C3640 ISDN PRI dial-in problem

Discussion in 'Cisco' started by Ada, Sep 22, 2004.

  1. Ada

    Ada Guest

    Hi!

    I've got a CISCO 3640 with an ISDN card and 30 MICA modems. Everything
    was doing well, but now clients cannot dial-in.

    Could it be the HW problem?

    Ada.

    I'll really appreciate any help. Here are some debugs:

    Sep 21 13:17:49: CSM: Next free modem = 2/12; statbits = 10020
    Sep 21 13:17:49: Modem 2/12 CSM: modem is allocated, modems free=27
    Sep 21 13:17:49: Modem 2/12 CSM: Incoming call from xxxxxxxxxx to 9,
    id 0x1CB
    Sep 21 13:17:49: Modem 2/12 CSM: (CSM_PROC_IDLE)<--ISDN_CALL
    Sep 21 13:17:49: Modem 2/12 CSM: MODEM_REPORT rcvd DEV_CONNECTED for
    call_id 0x1CB
    Sep 21 13:17:49: Modem 2/12 CSM:
    (CSM_PROC_MODEM_RESERVED)<--ISDN_CONNECTED
    Sep 21 13:17:49: Modem 2/12 Mica: configured for Answer mode, with
    Null signaling, 0x0 tone detection.
    Sep 21 13:17:50: Modem 2/12 Mica: in modem state CALL_SETUP
    Sep 21 13:17:51: Modem 2/12 Mica: in modem state CONNECT
    Sep 21 13:17:56: Modem 2/12 Mica: in modem state LINK
    Sep 21 13:18:07: Modem 2/12 Mica: in modem state TRAINUP
    Sep 21 13:18:15: Modem 2/12 CSM:
    (CSM_PROC_WAIT_FOR_CARRIER)<--MODEM_CONNECTED
    Sep 21 13:18:15: Modem 2/12 Mica: in modem state STEADY
    Sep 21 13:18:15: Modem 2/12 Mica: CONNECT at 41333/28800 (Tx/Rx), V90,
    LAPM, V42bis
    Sep 21 13:18:15: TTY77: DSR came up
    Sep 21 13:18:15: tty77: Modem: IDLE->(unknown)
    Sep 21 13:18:15: TTY77: EXEC creation
    Sep 21 13:18:15: TTY77: create timer type 10, 0 seconds
    Sep 21 13:18:15: TTY77: resume timer type 10 (OK)
    Sep 21 13:18:15: TTY77: Autoselect(2) sample 7E
    Sep 21 13:18:15: TTY77: Autoselect(2) sample 7EFF
    Sep 21 13:18:15: TTY77: Autoselect(2) sample 7EFF7D
    Sep 21 13:18:15: TTY77: Autoselect(2) sample 7EFF7D23
    Sep 21 13:18:15: TTY77 Autoselect cmd: ppp negotiate
    Sep 21 13:18:15: TTY77: pause timer type 10 (OK)
    Sep 21 13:18:15: TTY77: EXEC creation
    Sep 21 13:18:16: TTY77: no timer type 1 to destroy
    Sep 21 13:18:16: TTY77: no timer type 0 to destroy
    Sep 21 13:18:16: TTY77: no timer type 2 to destroy
    Sep 21 13:18:18: As77 PPP: Using dialer call direction
    Sep 21 13:18:18: As77 PPP: Treating connection as a callin
    Sep 21 13:18:18: As77 PPP: Phase is ESTABLISHING, Passive Open [0
    sess, 0 load]
    Sep 21 13:18:18: As77 LCP: State is Listen
    Sep 21 13:18:18: As77 LCP: I CONFREQ [Listen] id 2 len 23
    Sep 21 13:18:18: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    Sep 21 13:18:18: As77 LCP: MagicNumber 0x013011E0 (0x0506013011E0)
    Sep 21 13:18:18: As77 LCP: PFC (0x0702)
    Sep 21 13:18:18: As77 LCP: ACFC (0x0802)
    Sep 21 13:18:18: As77 LCP: Callback 6 (0x0D0306)
    Sep 21 13:18:18: Modem 2/12 Mica: PPP escape_map: Tx map = FFFFFFFF,
    Rx map = 0
    Sep 21 13:18:18: As77 LCP: O CONFREQ [Listen] id 21 len 25
    Sep 21 13:18:18: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    Sep 21 13:18:18: As77 LCP: AuthProto CHAP (0x0305C22305)
    Sep 21 13:18:18: As77 LCP: MagicNumber 0xD0D43E4C (0x0506D0D43E4C)
    Sep 21 13:18:18: As77 LCP: PFC (0x0702)
    Sep 21 13:18:18: As77 LCP: ACFC (0x0802)
    Sep 21 13:18:18: As77 LCP: O CONFACK [Listen] id 2 len 23
    Sep 21 13:18:18: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    Sep 21 13:18:18: As77 LCP: MagicNumber 0x013011E0 (0x0506013011E0)
    Sep 21 13:18:18: As77 LCP: PFC (0x0702)
    Sep 21 13:18:18: As77 LCP: ACFC (0x0802)
    Sep 21 13:18:18: As77 LCP: Callback 6 (0x0D0306)
    Sep 21 13:18:20: As77 LCP: TIMEout: State ACKsent
    Sep 21 13:18:20: As77 LCP: O CONFREQ [ACKsent] id 22 len 25
    Sep 21 13:18:20: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    Sep 21 13:18:20: As77 LCP: AuthProto CHAP (0x0305C22305)
    Sep 21 13:18:20: As77 LCP: MagicNumber 0xD0D43E4C (0x0506D0D43E4C)
    Sep 21 13:18:20: As77 LCP: PFC (0x0702)
    Sep 21 13:18:20: As77 LCP: ACFC (0x0802)
    Sep 21 13:18:21: As77 LCP: I CONFACK [ACKsent] id 22 len 25
    Sep 21 13:18:21: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    Sep 21 13:18:21: As77 LCP: AuthProto CHAP (0x0305C22305)
    Sep 21 13:18:21: As77 LCP: MagicNumber 0xD0D43E4C (0x0506D0D43E4C)
    Sep 21 13:18:21: As77 LCP: PFC (0x0702)
    Sep 21 13:18:21: As77 LCP: ACFC (0x0802)
    Sep 21 13:18:21: As77 LCP: State is Open
    Sep 21 13:18:21: Modem 2/12 Mica: PPP escape_map: Tx map = A0000, Rx
    map = 0
    Sep 21 13:18:21: As77 PPP: Phase is AUTHENTICATING, by this end [0
    sess, 0 load]
    Sep 21 13:18:21: As77 CHAP: O CHALLENGE id 8 len 27 from "STYXSK"
    Sep 21 13:18:21: As77 LCP: I CONFREQ [Open] id 3 len 23
    Sep 21 13:18:21: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    Sep 21 13:18:21: As77 LCP: MagicNumber 0x013011E0 (0x0506013011E0)
    Sep 21 13:18:21: As77 LCP: PFC (0x0702)
    Sep 21 13:18:21: As77 LCP: ACFC (0x0802)
    Sep 21 13:18:21: As77 LCP: Callback 6 (0x0D0306)
    Sep 21 13:18:21: As77 PPP: Phase is TERMINATING [0 sess, 0 load]
    Sep 21 13:18:21: Modem 2/12 Mica: PPP escape_map: Tx map = FFFFFFFF,
    Rx map = 0
    Sep 21 13:18:21: As77 PPP: Phase is ESTABLISHING [0 sess, 0 load]
    Sep 21 13:18:21: As77 LCP: O CONFREQ [Open] id 23 len 25
    Sep 21 13:18:21: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    Sep 21 13:18:21: As77 LCP: AuthProto CHAP (0x0305C22305)
    Sep 21 13:18:21: As77 LCP: MagicNumber 0xD0D44A0B (0x0506D0D44A0B)
    Sep 21 13:18:21: As77 LCP: PFC (0x0702)
    Sep 21 13:18:21: As77 LCP: ACFC (0x0802)
    Sep 21 13:18:21: As77 LCP: O CONFACK [Open] id 3 len 23
    Sep 21 13:18:21: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    Sep 21 13:18:21: As77 LCP: MagicNumber 0x013011E0 (0x0506013011E0)
    Sep 21 13:18:21: As77 LCP: PFC (0x0702)
    Sep 21 13:18:21: As77 LCP: ACFC (0x0802)
    Sep 21 13:18:21: As77 LCP: Callback 6 (0x0D0306)
    Sep 21 13:18:22: As77 LCP: I CONFACK [ACKsent] id 23 len 25
    Sep 21 13:18:22: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    Sep 21 13:18:22: As77 LCP: AuthProto CHAP (0x0305C22305)
    Sep 21 13:18:22: As77 LCP: MagicNumber 0xD0D44A0B (0x0506D0D44A0B)
    Sep 21 13:18:22: As77 LCP: PFC (0x0702)
    Sep 21 13:18:22: As77 LCP: ACFC (0x0802)
    Sep 21 13:18:22: As77 LCP: State is Open
    Sep 21 13:18:22: Modem 2/12 Mica: PPP escape_map: Tx map = A0000, Rx
    map = 0
    Sep 21 13:18:22: As77 PPP: Phase is AUTHENTICATING, by this end [0
    sess, 0 load]
    Sep 21 13:18:22: As77 CHAP: O CHALLENGE id 9 len 27 from "XXXX"
    Sep 21 13:18:22: As77 CHAP: I RESPONSE id 9 len 29 from "W1315238"
    Sep 21 13:18:22: As77 CHAP: O SUCCESS id 9 len 4
    Sep 21 13:18:22: As77 MCB: Callback not authorized for this user
    W1315238
    Sep 21 13:18:22: Async77 PPP: O MCB Request(1) id 3 len 6
    Sep 21 13:18:22: Async77 MCB: O 1 3 0 6 1 2
    Sep 21 13:18:22: As77 MCB: O Request Id 3 Callback Type None
    Sep 21 13:18:22: As77 PPP: Phase is CBCP [0 sess, 0 load]
    Sep 21 13:18:22: Async77 PPP: I MCB Response(2) id 3 len 6
    Sep 21 13:18:22: Async77 MCB: I 2 3 0 6 1 2
    Sep 21 13:18:22: As77 MCB: Received response
    Sep 21 13:18:22: As77 MCB: Response CBK-None 1 2
    Sep 21 13:18:22: Async77 PPP: O MCB Ack(3) id 3 len 6
    Sep 21 13:18:22: Async77 MCB: O 3 3 0 6 1 2
    Sep 21 13:18:22: As77 MCB: O Ack Id 3 Callback Type None
    Sep 21 13:18:22: As77 MCB: No Callback negotiated; Exit
    Sep 21 13:18:22: As77 PPP: Phase is UP [0 sess, 0 load]
    Sep 21 13:18:22: As77 IPCP: O CONFREQ [Closed] id 5 len 16
    Sep 21 13:18:22: As77 IPCP: CompressType VJ 15 slots
    (0x0206002D0F00)
    Sep 21 13:18:22: As77 IPCP: Address XXX.XXX.XXX.XXX
    (0x0306C0A88801)
    Sep 21 13:18:23: As77 IPXCP: I CONFREQ [Not negotiated] id 1 len 30
    Sep 21 13:18:23: As77 IPXCP: Network 0x00000000 (0x010600000000)
    Sep 21 13:18:23: As77 IPXCP: Node 0061.6e30.2e2f
    (0x020800616E302E2F)
    Sep 21 13:18:23: As77 IPXCP: Compression Telebit Compressed IPX
    (0x030600020F01)
    Sep 21 13:18:23: As77 IPXCP: Routing 0 (0x04040000)
    Sep 21 13:18:23: As77 IPXCP: ConfigComplete (0x0602)
    Sep 21 13:18:23: As77 LCP: O PROTREJ [Open] id 24 len 36 protocol
    IPXCP
    Sep 21 13:18:23: As77 LCP: (0x802B0101001E01060000000002080061)
    Sep 21 13:18:23: As77 LCP: (0x6E302E2F030600020F01040400000602)
    Sep 21 13:18:23: As77 IPCP: I CONFREQ [REQsent] id 1 len 40
    Sep 21 13:18:23: As77 IPCP: CompressType VJ 15 slots CompressSlotID
    (0x0206002D0F01)
    Sep 21 13:18:23: As77 IPCP: Address 0.0.0.0 (0x030600000000)
    Sep 21 13:18:23: As77 IPCP: PrimaryDNS 0.0.0.0 (0x810600000000)
    Sep 21 13:18:23: As77 IPCP: PrimaryWINS 0.0.0.0 (0x820600000000)
    Sep 21 13:18:23: As77 IPCP: SecondaryDNS 0.0.0.0 (0x830600000000)
    Sep 21 13:18:23: As77 IPCP: SecondaryWINS 0.0.0.0 (0x840600000000)
    Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we
    want 192.168.200.134
    Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Says use pool MC
    Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Pool returned 192.168. 200.134
    Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we
    want 192.168. 200.134
    Sep 21 13:18:23: As77 IPCP: O CONFREJ [REQsent] id 1 len 16
    Sep 21 13:18:23: As77 IPCP: PrimaryWINS 0.0.0.0 (0x820600000000)
    Sep 21 13:18:23: As77 IPCP: SecondaryWINS 0.0.0.0 (0x840600000000)
    Sep 21 13:18:23: As77 CCP: I CONFREQ [Not negotiated] id 1 len 15
    Sep 21 13:18:23: As77 CCP: MS-PPC supported bits 0x00000001
    (0x120600000001)
    Sep 21 13:18:23: As77 CCP: Stacker history 1 check mode EXTENDED
    (0x1105000104)
    Sep 21 13:18:23: As77 LCP: O PROTREJ [Open] id 25 len 21 protocol CCP
    Sep 21 13:18:23: As77 LCP: (0x80FD0101000F12060000000111050001)
    Sep 21 13:18:23: As77 LCP: (0x04)
    Sep 21 13:18:23: As77 IPCP: I CONFACK [REQsent] id 5 len 16
    Sep 21 13:18:23: As77 IPCP: CompressType VJ 15 slots
    (0x0206002D0F00)
    Sep 21 13:18:23: As77 IPCP: Address XXX.XXX.XXX.XXX
    (0x0306C0A88801)
    Sep 21 13:18:23: As77 IPCP: I CONFREQ [ACKrcvd] id 2 len 28
    Sep 21 13:18:23: As77 IPCP: CompressType VJ 15 slots CompressSlotID
    (0x0206002D0F01)
    Sep 21 13:18:23: As77 IPCP: Address 0.0.0.0 (0x030600000000)
    Sep 21 13:18:23: As77 IPCP: PrimaryDNS 0.0.0.0 (0x810600000000)
    Sep 21 13:18:23: As77 IPCP: SecondaryDNS 0.0.0.0 (0x830600000000)
    Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we
    want 192.168.200.134
    Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we
    want 192.168.200.134
    Sep 21 13:18:23: As77 IPCP: O CONFNAK [ACKrcvd] id 2 len 22
    Sep 21 13:18:23: As77 IPCP: Address 192.168. 200.134
    (0x0306C0A888B1)
    Sep 21 13:18:23: As77 IPCP: PrimaryDNS XXX.XXX.XXX.XXX
    (0x8106C0A886CA)
    Sep 21 13:18:23: As77 IPCP: SecondaryDNS XXX.XXX.XXX.XXX
    (0x8306D97660CD)
    Sep 21 13:18:23: As77 IPCP: I CONFREQ [ACKrcvd] id 3 len 28
    Sep 21 13:18:23: As77 IPCP: CompressType VJ 15 slots CompressSlotID
    (0x0206002D0F01)
    Sep 21 13:18:23: As77 IPCP: Address 192.168.200.134
    (0x0306C0A888B1)
    Sep 21 13:18:23: As77 IPCP: PrimaryDNS XXX.XXX.XXX.XXX
    (0x8106C0A886CA)
    Sep 21 13:18:23: As77 IPCP: SecondaryDNS XXX.XXX.XXX.XXX
    (0x8306D97660CD)
    Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Start. Her address
    192.168.200.134, we want 192.168. 200.134
    Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Request 192.168.200.134 from
    pool MC
    Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Pool grants 192.168.200.134
    Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Done. Her address
    192.168.200.134, we want 192.168. 200.134
    Sep 21 13:18:23: As77 IPCP: O CONFACK [ACKrcvd] id 3 len 28
    Sep 21 13:18:23: As77 IPCP: CompressType VJ 15 slots CompressSlotID
    (0x0206002D0F01)
    Sep 21 13:18:23: As77 IPCP: Address 192.168.200.134
    (0x0306C0A888B1)
    Sep 21 13:18:23: As77 IPCP: PrimaryDNS XXX.XXX.XXX.XXX
    (0x8106C0A886CA)
    Sep 21 13:18:23: As77 IPCP: SecondaryDNS XXX.XXX.XXX.XXX
    (0x8306D97660CD)
    Sep 21 13:18:23: As77 IPCP: State is Open
    Sep 21 13:18:23: As77 IPCP: Install route to 192.168. 200.134
    Sep 21 13:18:36: As77 LCP: I TERMREQ [Open] id 4 len 4
    Sep 21 13:18:36: As77 LCP: O TERMACK [Open] id 4 len 4
    Sep 21 13:18:36: As77 IPCP: State is Closed
    Sep 21 13:18:36: As77 PPP: Phase is TERMINATING [0 sess, 0 load]
    Sep 21 13:18:36: As77 IPCP: Remove route to 192.168. 200.134
    Sep 21 13:18:36: Modem 2/12 Mica: in modem state TERMINATING
    Sep 21 13:18:36: Modem 2/12 CSM:
    (CSM_PROC_CONNECTED)<--MODEM_DISCONNECTED
    Sep 21 13:18:36: Modem 2/12 Mica: in modem state IDLE
    Sep 21 13:18:36: Modem 2/12 CSM:
    (CSM_PROC_CONNECTED)<--QUEUED_DISCONNECT
    Sep 21 13:18:36: Modem 2/12 CSM: CSM_MODEM_DEALLOCATE: modem is
    deallocated
    Sep 21 13:18:36: Modem 2/12 Mica: DISCONNECT after 00:00:45, due to
    reason (0x8220) EC rcvd DISC frame.
    Sep 21 13:18:36: CSM: MODEM_REPORT from 1/0:0, call_id=0x1CB,
    event=0x0, cause=0x10, dchan_idb=0x61519990
    Sep 21 13:18:36: CSM: MODEM_REPORT rcvd DEV_IDLE for call_id 0x1CB,
    modem not found due to wrong b channel num
    ber or b channel is deallocated
     
    Ada, Sep 22, 2004
    #1
    1. Advertising

  2. Looks to me like the client dialed in,
    trained in V.90, negotiated PPP and IPCP just
    fine. Then 13 seconds later, the peer
    sent us an LCP TERMREQ - i.e. a deliberate
    request to close the PPP connection.

    Why did the peer do this? You'd have to
    get inside its head and find out. Maybe
    it was expecting some kind of callback?

    Aaron

    ---

    ~ Hi!
    ~
    ~ I've got a CISCO 3640 with an ISDN card and 30 MICA modems. Everything
    ~ was doing well, but now clients cannot dial-in.
    ~
    ~ Could it be the HW problem?
    ~
    ~ Ada.
    ~
    ~ I'll really appreciate any help. Here are some debugs:
    ~
    ~ Sep 21 13:17:49: CSM: Next free modem = 2/12; statbits = 10020
    ~ Sep 21 13:17:49: Modem 2/12 CSM: modem is allocated, modems free=27
    ~ Sep 21 13:17:49: Modem 2/12 CSM: Incoming call from xxxxxxxxxx to 9,
    ~ id 0x1CB
    ~ Sep 21 13:17:49: Modem 2/12 CSM: (CSM_PROC_IDLE)<--ISDN_CALL
    ~ Sep 21 13:17:49: Modem 2/12 CSM: MODEM_REPORT rcvd DEV_CONNECTED for
    ~ call_id 0x1CB
    ~ Sep 21 13:17:49: Modem 2/12 CSM:
    ~ (CSM_PROC_MODEM_RESERVED)<--ISDN_CONNECTED
    ~ Sep 21 13:17:49: Modem 2/12 Mica: configured for Answer mode, with
    ~ Null signaling, 0x0 tone detection.
    ~ Sep 21 13:17:50: Modem 2/12 Mica: in modem state CALL_SETUP
    ~ Sep 21 13:17:51: Modem 2/12 Mica: in modem state CONNECT
    ~ Sep 21 13:17:56: Modem 2/12 Mica: in modem state LINK
    ~ Sep 21 13:18:07: Modem 2/12 Mica: in modem state TRAINUP
    ~ Sep 21 13:18:15: Modem 2/12 CSM:
    ~ (CSM_PROC_WAIT_FOR_CARRIER)<--MODEM_CONNECTED
    ~ Sep 21 13:18:15: Modem 2/12 Mica: in modem state STEADY
    ~ Sep 21 13:18:15: Modem 2/12 Mica: CONNECT at 41333/28800 (Tx/Rx), V90,
    ~ LAPM, V42bis
    ~ Sep 21 13:18:15: TTY77: DSR came up
    ~ Sep 21 13:18:15: tty77: Modem: IDLE->(unknown)
    ~ Sep 21 13:18:15: TTY77: EXEC creation
    ~ Sep 21 13:18:15: TTY77: create timer type 10, 0 seconds
    ~ Sep 21 13:18:15: TTY77: resume timer type 10 (OK)
    ~ Sep 21 13:18:15: TTY77: Autoselect(2) sample 7E
    ~ Sep 21 13:18:15: TTY77: Autoselect(2) sample 7EFF
    ~ Sep 21 13:18:15: TTY77: Autoselect(2) sample 7EFF7D
    ~ Sep 21 13:18:15: TTY77: Autoselect(2) sample 7EFF7D23
    ~ Sep 21 13:18:15: TTY77 Autoselect cmd: ppp negotiate
    ~ Sep 21 13:18:15: TTY77: pause timer type 10 (OK)
    ~ Sep 21 13:18:15: TTY77: EXEC creation
    ~ Sep 21 13:18:16: TTY77: no timer type 1 to destroy
    ~ Sep 21 13:18:16: TTY77: no timer type 0 to destroy
    ~ Sep 21 13:18:16: TTY77: no timer type 2 to destroy
    ~ Sep 21 13:18:18: As77 PPP: Using dialer call direction
    ~ Sep 21 13:18:18: As77 PPP: Treating connection as a callin
    ~ Sep 21 13:18:18: As77 PPP: Phase is ESTABLISHING, Passive Open [0
    ~ sess, 0 load]
    ~ Sep 21 13:18:18: As77 LCP: State is Listen
    ~ Sep 21 13:18:18: As77 LCP: I CONFREQ [Listen] id 2 len 23
    ~ Sep 21 13:18:18: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    ~ Sep 21 13:18:18: As77 LCP: MagicNumber 0x013011E0 (0x0506013011E0)
    ~ Sep 21 13:18:18: As77 LCP: PFC (0x0702)
    ~ Sep 21 13:18:18: As77 LCP: ACFC (0x0802)
    ~ Sep 21 13:18:18: As77 LCP: Callback 6 (0x0D0306)
    ~ Sep 21 13:18:18: Modem 2/12 Mica: PPP escape_map: Tx map = FFFFFFFF,
    ~ Rx map = 0
    ~ Sep 21 13:18:18: As77 LCP: O CONFREQ [Listen] id 21 len 25
    ~ Sep 21 13:18:18: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    ~ Sep 21 13:18:18: As77 LCP: AuthProto CHAP (0x0305C22305)
    ~ Sep 21 13:18:18: As77 LCP: MagicNumber 0xD0D43E4C (0x0506D0D43E4C)
    ~ Sep 21 13:18:18: As77 LCP: PFC (0x0702)
    ~ Sep 21 13:18:18: As77 LCP: ACFC (0x0802)
    ~ Sep 21 13:18:18: As77 LCP: O CONFACK [Listen] id 2 len 23
    ~ Sep 21 13:18:18: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    ~ Sep 21 13:18:18: As77 LCP: MagicNumber 0x013011E0 (0x0506013011E0)
    ~ Sep 21 13:18:18: As77 LCP: PFC (0x0702)
    ~ Sep 21 13:18:18: As77 LCP: ACFC (0x0802)
    ~ Sep 21 13:18:18: As77 LCP: Callback 6 (0x0D0306)
    ~ Sep 21 13:18:20: As77 LCP: TIMEout: State ACKsent
    ~ Sep 21 13:18:20: As77 LCP: O CONFREQ [ACKsent] id 22 len 25
    ~ Sep 21 13:18:20: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    ~ Sep 21 13:18:20: As77 LCP: AuthProto CHAP (0x0305C22305)
    ~ Sep 21 13:18:20: As77 LCP: MagicNumber 0xD0D43E4C (0x0506D0D43E4C)
    ~ Sep 21 13:18:20: As77 LCP: PFC (0x0702)
    ~ Sep 21 13:18:20: As77 LCP: ACFC (0x0802)
    ~ Sep 21 13:18:21: As77 LCP: I CONFACK [ACKsent] id 22 len 25
    ~ Sep 21 13:18:21: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    ~ Sep 21 13:18:21: As77 LCP: AuthProto CHAP (0x0305C22305)
    ~ Sep 21 13:18:21: As77 LCP: MagicNumber 0xD0D43E4C (0x0506D0D43E4C)
    ~ Sep 21 13:18:21: As77 LCP: PFC (0x0702)
    ~ Sep 21 13:18:21: As77 LCP: ACFC (0x0802)
    ~ Sep 21 13:18:21: As77 LCP: State is Open
    ~ Sep 21 13:18:21: Modem 2/12 Mica: PPP escape_map: Tx map = A0000, Rx
    ~ map = 0
    ~ Sep 21 13:18:21: As77 PPP: Phase is AUTHENTICATING, by this end [0
    ~ sess, 0 load]
    ~ Sep 21 13:18:21: As77 CHAP: O CHALLENGE id 8 len 27 from "STYXSK"
    ~ Sep 21 13:18:21: As77 LCP: I CONFREQ [Open] id 3 len 23
    ~ Sep 21 13:18:21: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    ~ Sep 21 13:18:21: As77 LCP: MagicNumber 0x013011E0 (0x0506013011E0)
    ~ Sep 21 13:18:21: As77 LCP: PFC (0x0702)
    ~ Sep 21 13:18:21: As77 LCP: ACFC (0x0802)
    ~ Sep 21 13:18:21: As77 LCP: Callback 6 (0x0D0306)
    ~ Sep 21 13:18:21: As77 PPP: Phase is TERMINATING [0 sess, 0 load]
    ~ Sep 21 13:18:21: Modem 2/12 Mica: PPP escape_map: Tx map = FFFFFFFF,
    ~ Rx map = 0
    ~ Sep 21 13:18:21: As77 PPP: Phase is ESTABLISHING [0 sess, 0 load]
    ~ Sep 21 13:18:21: As77 LCP: O CONFREQ [Open] id 23 len 25
    ~ Sep 21 13:18:21: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    ~ Sep 21 13:18:21: As77 LCP: AuthProto CHAP (0x0305C22305)
    ~ Sep 21 13:18:21: As77 LCP: MagicNumber 0xD0D44A0B (0x0506D0D44A0B)
    ~ Sep 21 13:18:21: As77 LCP: PFC (0x0702)
    ~ Sep 21 13:18:21: As77 LCP: ACFC (0x0802)
    ~ Sep 21 13:18:21: As77 LCP: O CONFACK [Open] id 3 len 23
    ~ Sep 21 13:18:21: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    ~ Sep 21 13:18:21: As77 LCP: MagicNumber 0x013011E0 (0x0506013011E0)
    ~ Sep 21 13:18:21: As77 LCP: PFC (0x0702)
    ~ Sep 21 13:18:21: As77 LCP: ACFC (0x0802)
    ~ Sep 21 13:18:21: As77 LCP: Callback 6 (0x0D0306)
    ~ Sep 21 13:18:22: As77 LCP: I CONFACK [ACKsent] id 23 len 25
    ~ Sep 21 13:18:22: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    ~ Sep 21 13:18:22: As77 LCP: AuthProto CHAP (0x0305C22305)
    ~ Sep 21 13:18:22: As77 LCP: MagicNumber 0xD0D44A0B (0x0506D0D44A0B)
    ~ Sep 21 13:18:22: As77 LCP: PFC (0x0702)
    ~ Sep 21 13:18:22: As77 LCP: ACFC (0x0802)
    ~ Sep 21 13:18:22: As77 LCP: State is Open
    ~ Sep 21 13:18:22: Modem 2/12 Mica: PPP escape_map: Tx map = A0000, Rx
    ~ map = 0
    ~ Sep 21 13:18:22: As77 PPP: Phase is AUTHENTICATING, by this end [0
    ~ sess, 0 load]
    ~ Sep 21 13:18:22: As77 CHAP: O CHALLENGE id 9 len 27 from "XXXX"
    ~ Sep 21 13:18:22: As77 CHAP: I RESPONSE id 9 len 29 from "W1315238"
    ~ Sep 21 13:18:22: As77 CHAP: O SUCCESS id 9 len 4
    ~ Sep 21 13:18:22: As77 MCB: Callback not authorized for this user
    ~ W1315238
    ~ Sep 21 13:18:22: Async77 PPP: O MCB Request(1) id 3 len 6
    ~ Sep 21 13:18:22: Async77 MCB: O 1 3 0 6 1 2
    ~ Sep 21 13:18:22: As77 MCB: O Request Id 3 Callback Type None
    ~ Sep 21 13:18:22: As77 PPP: Phase is CBCP [0 sess, 0 load]
    ~ Sep 21 13:18:22: Async77 PPP: I MCB Response(2) id 3 len 6
    ~ Sep 21 13:18:22: Async77 MCB: I 2 3 0 6 1 2
    ~ Sep 21 13:18:22: As77 MCB: Received response
    ~ Sep 21 13:18:22: As77 MCB: Response CBK-None 1 2
    ~ Sep 21 13:18:22: Async77 PPP: O MCB Ack(3) id 3 len 6
    ~ Sep 21 13:18:22: Async77 MCB: O 3 3 0 6 1 2
    ~ Sep 21 13:18:22: As77 MCB: O Ack Id 3 Callback Type None
    ~ Sep 21 13:18:22: As77 MCB: No Callback negotiated; Exit
    ~ Sep 21 13:18:22: As77 PPP: Phase is UP [0 sess, 0 load]
    ~ Sep 21 13:18:22: As77 IPCP: O CONFREQ [Closed] id 5 len 16
    ~ Sep 21 13:18:22: As77 IPCP: CompressType VJ 15 slots
    ~ (0x0206002D0F00)
    ~ Sep 21 13:18:22: As77 IPCP: Address XXX.XXX.XXX.XXX
    ~ (0x0306C0A88801)
    ~ Sep 21 13:18:23: As77 IPXCP: I CONFREQ [Not negotiated] id 1 len 30
    ~ Sep 21 13:18:23: As77 IPXCP: Network 0x00000000 (0x010600000000)
    ~ Sep 21 13:18:23: As77 IPXCP: Node 0061.6e30.2e2f
    ~ (0x020800616E302E2F)
    ~ Sep 21 13:18:23: As77 IPXCP: Compression Telebit Compressed IPX
    ~ (0x030600020F01)
    ~ Sep 21 13:18:23: As77 IPXCP: Routing 0 (0x04040000)
    ~ Sep 21 13:18:23: As77 IPXCP: ConfigComplete (0x0602)
    ~ Sep 21 13:18:23: As77 LCP: O PROTREJ [Open] id 24 len 36 protocol
    ~ IPXCP
    ~ Sep 21 13:18:23: As77 LCP: (0x802B0101001E01060000000002080061)
    ~ Sep 21 13:18:23: As77 LCP: (0x6E302E2F030600020F01040400000602)
    ~ Sep 21 13:18:23: As77 IPCP: I CONFREQ [REQsent] id 1 len 40
    ~ Sep 21 13:18:23: As77 IPCP: CompressType VJ 15 slots CompressSlotID
    ~ (0x0206002D0F01)
    ~ Sep 21 13:18:23: As77 IPCP: Address 0.0.0.0 (0x030600000000)
    ~ Sep 21 13:18:23: As77 IPCP: PrimaryDNS 0.0.0.0 (0x810600000000)
    ~ Sep 21 13:18:23: As77 IPCP: PrimaryWINS 0.0.0.0 (0x820600000000)
    ~ Sep 21 13:18:23: As77 IPCP: SecondaryDNS 0.0.0.0 (0x830600000000)
    ~ Sep 21 13:18:23: As77 IPCP: SecondaryWINS 0.0.0.0 (0x840600000000)
    ~ Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we
    ~ want 192.168.200.134
    ~ Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Says use pool MC
    ~ Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Pool returned 192.168. 200.134
    ~ Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we
    ~ want 192.168. 200.134
    ~ Sep 21 13:18:23: As77 IPCP: O CONFREJ [REQsent] id 1 len 16
    ~ Sep 21 13:18:23: As77 IPCP: PrimaryWINS 0.0.0.0 (0x820600000000)
    ~ Sep 21 13:18:23: As77 IPCP: SecondaryWINS 0.0.0.0 (0x840600000000)
    ~ Sep 21 13:18:23: As77 CCP: I CONFREQ [Not negotiated] id 1 len 15
    ~ Sep 21 13:18:23: As77 CCP: MS-PPC supported bits 0x00000001
    ~ (0x120600000001)
    ~ Sep 21 13:18:23: As77 CCP: Stacker history 1 check mode EXTENDED
    ~ (0x1105000104)
    ~ Sep 21 13:18:23: As77 LCP: O PROTREJ [Open] id 25 len 21 protocol CCP
    ~ Sep 21 13:18:23: As77 LCP: (0x80FD0101000F12060000000111050001)
    ~ Sep 21 13:18:23: As77 LCP: (0x04)
    ~ Sep 21 13:18:23: As77 IPCP: I CONFACK [REQsent] id 5 len 16
    ~ Sep 21 13:18:23: As77 IPCP: CompressType VJ 15 slots
    ~ (0x0206002D0F00)
    ~ Sep 21 13:18:23: As77 IPCP: Address XXX.XXX.XXX.XXX
    ~ (0x0306C0A88801)
    ~ Sep 21 13:18:23: As77 IPCP: I CONFREQ [ACKrcvd] id 2 len 28
    ~ Sep 21 13:18:23: As77 IPCP: CompressType VJ 15 slots CompressSlotID
    ~ (0x0206002D0F01)
    ~ Sep 21 13:18:23: As77 IPCP: Address 0.0.0.0 (0x030600000000)
    ~ Sep 21 13:18:23: As77 IPCP: PrimaryDNS 0.0.0.0 (0x810600000000)
    ~ Sep 21 13:18:23: As77 IPCP: SecondaryDNS 0.0.0.0 (0x830600000000)
    ~ Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we
    ~ want 192.168.200.134
    ~ Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we
    ~ want 192.168.200.134
    ~ Sep 21 13:18:23: As77 IPCP: O CONFNAK [ACKrcvd] id 2 len 22
    ~ Sep 21 13:18:23: As77 IPCP: Address 192.168. 200.134
    ~ (0x0306C0A888B1)
    ~ Sep 21 13:18:23: As77 IPCP: PrimaryDNS XXX.XXX.XXX.XXX
    ~ (0x8106C0A886CA)
    ~ Sep 21 13:18:23: As77 IPCP: SecondaryDNS XXX.XXX.XXX.XXX
    ~ (0x8306D97660CD)
    ~ Sep 21 13:18:23: As77 IPCP: I CONFREQ [ACKrcvd] id 3 len 28
    ~ Sep 21 13:18:23: As77 IPCP: CompressType VJ 15 slots CompressSlotID
    ~ (0x0206002D0F01)
    ~ Sep 21 13:18:23: As77 IPCP: Address 192.168.200.134
    ~ (0x0306C0A888B1)
    ~ Sep 21 13:18:23: As77 IPCP: PrimaryDNS XXX.XXX.XXX.XXX
    ~ (0x8106C0A886CA)
    ~ Sep 21 13:18:23: As77 IPCP: SecondaryDNS XXX.XXX.XXX.XXX
    ~ (0x8306D97660CD)
    ~ Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Start. Her address
    ~ 192.168.200.134, we want 192.168. 200.134
    ~ Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Request 192.168.200.134 from
    ~ pool MC
    ~ Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Pool grants 192.168.200.134
    ~ Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Done. Her address
    ~ 192.168.200.134, we want 192.168. 200.134
    ~ Sep 21 13:18:23: As77 IPCP: O CONFACK [ACKrcvd] id 3 len 28
    ~ Sep 21 13:18:23: As77 IPCP: CompressType VJ 15 slots CompressSlotID
    ~ (0x0206002D0F01)
    ~ Sep 21 13:18:23: As77 IPCP: Address 192.168.200.134
    ~ (0x0306C0A888B1)
    ~ Sep 21 13:18:23: As77 IPCP: PrimaryDNS XXX.XXX.XXX.XXX
    ~ (0x8106C0A886CA)
    ~ Sep 21 13:18:23: As77 IPCP: SecondaryDNS XXX.XXX.XXX.XXX
    ~ (0x8306D97660CD)
    ~ Sep 21 13:18:23: As77 IPCP: State is Open
    ~ Sep 21 13:18:23: As77 IPCP: Install route to 192.168. 200.134
    ~ Sep 21 13:18:36: As77 LCP: I TERMREQ [Open] id 4 len 4
    ~ Sep 21 13:18:36: As77 LCP: O TERMACK [Open] id 4 len 4
    ~ Sep 21 13:18:36: As77 IPCP: State is Closed
    ~ Sep 21 13:18:36: As77 PPP: Phase is TERMINATING [0 sess, 0 load]
    ~ Sep 21 13:18:36: As77 IPCP: Remove route to 192.168. 200.134
    ~ Sep 21 13:18:36: Modem 2/12 Mica: in modem state TERMINATING
    ~ Sep 21 13:18:36: Modem 2/12 CSM:
    ~ (CSM_PROC_CONNECTED)<--MODEM_DISCONNECTED
    ~ Sep 21 13:18:36: Modem 2/12 Mica: in modem state IDLE
    ~ Sep 21 13:18:36: Modem 2/12 CSM:
    ~ (CSM_PROC_CONNECTED)<--QUEUED_DISCONNECT
    ~ Sep 21 13:18:36: Modem 2/12 CSM: CSM_MODEM_DEALLOCATE: modem is
    ~ deallocated
    ~ Sep 21 13:18:36: Modem 2/12 Mica: DISCONNECT after 00:00:45, due to
    ~ reason (0x8220) EC rcvd DISC frame.
    ~ Sep 21 13:18:36: CSM: MODEM_REPORT from 1/0:0, call_id=0x1CB,
    ~ event=0x0, cause=0x10, dchan_idb=0x61519990
    ~ Sep 21 13:18:36: CSM: MODEM_REPORT rcvd DEV_IDLE for call_id 0x1CB,
    ~ modem not found due to wrong b channel num
    ~ ber or b channel is deallocated
     
    Aaron Leonard, Sep 23, 2004
    #2
    1. Advertising

  3. Ada

    Ada Guest

    Hi Aaron,

    it's a really strange for me, but I'm almost sure it was (or still is)
    the problem on our side. The client was not expecting of callback,
    although it looks like this.
    All the clients wasn't able to connect successfully. We didn't do any
    configurations changes and the connection problem had been existed for
    2 days.
    Now everything seems to be fine. All I have to resolve (or to explain)
    this case are some debugs (it's not our access router). Could it be
    the 'branch switching centers''(the part between routers' interface
    and TELCO) problem?
    Could you say why this could happened?

    Thank you.
    Ada

    Aaron Leonard <> wrote in message news:<>...
    > Looks to me like the client dialed in,
    > trained in V.90, negotiated PPP and IPCP just
    > fine. Then 13 seconds later, the peer
    > sent us an LCP TERMREQ - i.e. a deliberate
    > request to close the PPP connection.
    >
    > Why did the peer do this? You'd have to
    > get inside its head and find out. Maybe
    > it was expecting some kind of callback?
    >
    > Aaron
    >
    > ---
    >
    > ~ Hi!
    > ~
    > ~ I've got a CISCO 3640 with an ISDN card and 30 MICA modems. Everything
    > ~ was doing well, but now clients cannot dial-in.
    > ~
    > ~ Could it be the HW problem?
    > ~
    > ~ Ada.
    > ~
    > ~ I'll really appreciate any help. Here are some debugs:
    > ~
    > ~ Sep 21 13:17:49: CSM: Next free modem = 2/12; statbits = 10020
    > ~ Sep 21 13:17:49: Modem 2/12 CSM: modem is allocated, modems free=27
    > ~ Sep 21 13:17:49: Modem 2/12 CSM: Incoming call from xxxxxxxxxx to 9,
    > ~ id 0x1CB
    > ~ Sep 21 13:17:49: Modem 2/12 CSM: (CSM_PROC_IDLE)<--ISDN_CALL
    > ~ Sep 21 13:17:49: Modem 2/12 CSM: MODEM_REPORT rcvd DEV_CONNECTED for
    > ~ call_id 0x1CB
    > ~ Sep 21 13:17:49: Modem 2/12 CSM:
    > ~ (CSM_PROC_MODEM_RESERVED)<--ISDN_CONNECTED
    > ~ Sep 21 13:17:49: Modem 2/12 Mica: configured for Answer mode, with
    > ~ Null signaling, 0x0 tone detection.
    > ~ Sep 21 13:17:50: Modem 2/12 Mica: in modem state CALL_SETUP
    > ~ Sep 21 13:17:51: Modem 2/12 Mica: in modem state CONNECT
    > ~ Sep 21 13:17:56: Modem 2/12 Mica: in modem state LINK
    > ~ Sep 21 13:18:07: Modem 2/12 Mica: in modem state TRAINUP
    > ~ Sep 21 13:18:15: Modem 2/12 CSM:
    > ~ (CSM_PROC_WAIT_FOR_CARRIER)<--MODEM_CONNECTED
    > ~ Sep 21 13:18:15: Modem 2/12 Mica: in modem state STEADY
    > ~ Sep 21 13:18:15: Modem 2/12 Mica: CONNECT at 41333/28800 (Tx/Rx), V90,
    > ~ LAPM, V42bis
    > ~ Sep 21 13:18:15: TTY77: DSR came up
    > ~ Sep 21 13:18:15: tty77: Modem: IDLE->(unknown)
    > ~ Sep 21 13:18:15: TTY77: EXEC creation
    > ~ Sep 21 13:18:15: TTY77: create timer type 10, 0 seconds
    > ~ Sep 21 13:18:15: TTY77: resume timer type 10 (OK)
    > ~ Sep 21 13:18:15: TTY77: Autoselect(2) sample 7E
    > ~ Sep 21 13:18:15: TTY77: Autoselect(2) sample 7EFF
    > ~ Sep 21 13:18:15: TTY77: Autoselect(2) sample 7EFF7D
    > ~ Sep 21 13:18:15: TTY77: Autoselect(2) sample 7EFF7D23
    > ~ Sep 21 13:18:15: TTY77 Autoselect cmd: ppp negotiate
    > ~ Sep 21 13:18:15: TTY77: pause timer type 10 (OK)
    > ~ Sep 21 13:18:15: TTY77: EXEC creation
    > ~ Sep 21 13:18:16: TTY77: no timer type 1 to destroy
    > ~ Sep 21 13:18:16: TTY77: no timer type 0 to destroy
    > ~ Sep 21 13:18:16: TTY77: no timer type 2 to destroy
    > ~ Sep 21 13:18:18: As77 PPP: Using dialer call direction
    > ~ Sep 21 13:18:18: As77 PPP: Treating connection as a callin
    > ~ Sep 21 13:18:18: As77 PPP: Phase is ESTABLISHING, Passive Open [0
    > ~ sess, 0 load]
    > ~ Sep 21 13:18:18: As77 LCP: State is Listen
    > ~ Sep 21 13:18:18: As77 LCP: I CONFREQ [Listen] id 2 len 23
    > ~ Sep 21 13:18:18: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    > ~ Sep 21 13:18:18: As77 LCP: MagicNumber 0x013011E0 (0x0506013011E0)
    > ~ Sep 21 13:18:18: As77 LCP: PFC (0x0702)
    > ~ Sep 21 13:18:18: As77 LCP: ACFC (0x0802)
    > ~ Sep 21 13:18:18: As77 LCP: Callback 6 (0x0D0306)
    > ~ Sep 21 13:18:18: Modem 2/12 Mica: PPP escape_map: Tx map = FFFFFFFF,
    > ~ Rx map = 0
    > ~ Sep 21 13:18:18: As77 LCP: O CONFREQ [Listen] id 21 len 25
    > ~ Sep 21 13:18:18: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    > ~ Sep 21 13:18:18: As77 LCP: AuthProto CHAP (0x0305C22305)
    > ~ Sep 21 13:18:18: As77 LCP: MagicNumber 0xD0D43E4C (0x0506D0D43E4C)
    > ~ Sep 21 13:18:18: As77 LCP: PFC (0x0702)
    > ~ Sep 21 13:18:18: As77 LCP: ACFC (0x0802)
    > ~ Sep 21 13:18:18: As77 LCP: O CONFACK [Listen] id 2 len 23
    > ~ Sep 21 13:18:18: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    > ~ Sep 21 13:18:18: As77 LCP: MagicNumber 0x013011E0 (0x0506013011E0)
    > ~ Sep 21 13:18:18: As77 LCP: PFC (0x0702)
    > ~ Sep 21 13:18:18: As77 LCP: ACFC (0x0802)
    > ~ Sep 21 13:18:18: As77 LCP: Callback 6 (0x0D0306)
    > ~ Sep 21 13:18:20: As77 LCP: TIMEout: State ACKsent
    > ~ Sep 21 13:18:20: As77 LCP: O CONFREQ [ACKsent] id 22 len 25
    > ~ Sep 21 13:18:20: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    > ~ Sep 21 13:18:20: As77 LCP: AuthProto CHAP (0x0305C22305)
    > ~ Sep 21 13:18:20: As77 LCP: MagicNumber 0xD0D43E4C (0x0506D0D43E4C)
    > ~ Sep 21 13:18:20: As77 LCP: PFC (0x0702)
    > ~ Sep 21 13:18:20: As77 LCP: ACFC (0x0802)
    > ~ Sep 21 13:18:21: As77 LCP: I CONFACK [ACKsent] id 22 len 25
    > ~ Sep 21 13:18:21: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    > ~ Sep 21 13:18:21: As77 LCP: AuthProto CHAP (0x0305C22305)
    > ~ Sep 21 13:18:21: As77 LCP: MagicNumber 0xD0D43E4C (0x0506D0D43E4C)
    > ~ Sep 21 13:18:21: As77 LCP: PFC (0x0702)
    > ~ Sep 21 13:18:21: As77 LCP: ACFC (0x0802)
    > ~ Sep 21 13:18:21: As77 LCP: State is Open
    > ~ Sep 21 13:18:21: Modem 2/12 Mica: PPP escape_map: Tx map = A0000, Rx
    > ~ map = 0
    > ~ Sep 21 13:18:21: As77 PPP: Phase is AUTHENTICATING, by this end [0
    > ~ sess, 0 load]
    > ~ Sep 21 13:18:21: As77 CHAP: O CHALLENGE id 8 len 27 from "STYXSK"
    > ~ Sep 21 13:18:21: As77 LCP: I CONFREQ [Open] id 3 len 23
    > ~ Sep 21 13:18:21: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    > ~ Sep 21 13:18:21: As77 LCP: MagicNumber 0x013011E0 (0x0506013011E0)
    > ~ Sep 21 13:18:21: As77 LCP: PFC (0x0702)
    > ~ Sep 21 13:18:21: As77 LCP: ACFC (0x0802)
    > ~ Sep 21 13:18:21: As77 LCP: Callback 6 (0x0D0306)
    > ~ Sep 21 13:18:21: As77 PPP: Phase is TERMINATING [0 sess, 0 load]
    > ~ Sep 21 13:18:21: Modem 2/12 Mica: PPP escape_map: Tx map = FFFFFFFF,
    > ~ Rx map = 0
    > ~ Sep 21 13:18:21: As77 PPP: Phase is ESTABLISHING [0 sess, 0 load]
    > ~ Sep 21 13:18:21: As77 LCP: O CONFREQ [Open] id 23 len 25
    > ~ Sep 21 13:18:21: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    > ~ Sep 21 13:18:21: As77 LCP: AuthProto CHAP (0x0305C22305)
    > ~ Sep 21 13:18:21: As77 LCP: MagicNumber 0xD0D44A0B (0x0506D0D44A0B)
    > ~ Sep 21 13:18:21: As77 LCP: PFC (0x0702)
    > ~ Sep 21 13:18:21: As77 LCP: ACFC (0x0802)
    > ~ Sep 21 13:18:21: As77 LCP: O CONFACK [Open] id 3 len 23
    > ~ Sep 21 13:18:21: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    > ~ Sep 21 13:18:21: As77 LCP: MagicNumber 0x013011E0 (0x0506013011E0)
    > ~ Sep 21 13:18:21: As77 LCP: PFC (0x0702)
    > ~ Sep 21 13:18:21: As77 LCP: ACFC (0x0802)
    > ~ Sep 21 13:18:21: As77 LCP: Callback 6 (0x0D0306)
    > ~ Sep 21 13:18:22: As77 LCP: I CONFACK [ACKsent] id 23 len 25
    > ~ Sep 21 13:18:22: As77 LCP: ACCM 0x000A0000 (0x0206000A0000)
    > ~ Sep 21 13:18:22: As77 LCP: AuthProto CHAP (0x0305C22305)
    > ~ Sep 21 13:18:22: As77 LCP: MagicNumber 0xD0D44A0B (0x0506D0D44A0B)
    > ~ Sep 21 13:18:22: As77 LCP: PFC (0x0702)
    > ~ Sep 21 13:18:22: As77 LCP: ACFC (0x0802)
    > ~ Sep 21 13:18:22: As77 LCP: State is Open
    > ~ Sep 21 13:18:22: Modem 2/12 Mica: PPP escape_map: Tx map = A0000, Rx
    > ~ map = 0
    > ~ Sep 21 13:18:22: As77 PPP: Phase is AUTHENTICATING, by this end [0
    > ~ sess, 0 load]
    > ~ Sep 21 13:18:22: As77 CHAP: O CHALLENGE id 9 len 27 from "XXXX"
    > ~ Sep 21 13:18:22: As77 CHAP: I RESPONSE id 9 len 29 from "W1315238"
    > ~ Sep 21 13:18:22: As77 CHAP: O SUCCESS id 9 len 4
    > ~ Sep 21 13:18:22: As77 MCB: Callback not authorized for this user
    > ~ W1315238
    > ~ Sep 21 13:18:22: Async77 PPP: O MCB Request(1) id 3 len 6
    > ~ Sep 21 13:18:22: Async77 MCB: O 1 3 0 6 1 2
    > ~ Sep 21 13:18:22: As77 MCB: O Request Id 3 Callback Type None
    > ~ Sep 21 13:18:22: As77 PPP: Phase is CBCP [0 sess, 0 load]
    > ~ Sep 21 13:18:22: Async77 PPP: I MCB Response(2) id 3 len 6
    > ~ Sep 21 13:18:22: Async77 MCB: I 2 3 0 6 1 2
    > ~ Sep 21 13:18:22: As77 MCB: Received response
    > ~ Sep 21 13:18:22: As77 MCB: Response CBK-None 1 2
    > ~ Sep 21 13:18:22: Async77 PPP: O MCB Ack(3) id 3 len 6
    > ~ Sep 21 13:18:22: Async77 MCB: O 3 3 0 6 1 2
    > ~ Sep 21 13:18:22: As77 MCB: O Ack Id 3 Callback Type None
    > ~ Sep 21 13:18:22: As77 MCB: No Callback negotiated; Exit
    > ~ Sep 21 13:18:22: As77 PPP: Phase is UP [0 sess, 0 load]
    > ~ Sep 21 13:18:22: As77 IPCP: O CONFREQ [Closed] id 5 len 16
    > ~ Sep 21 13:18:22: As77 IPCP: CompressType VJ 15 slots
    > ~ (0x0206002D0F00)
    > ~ Sep 21 13:18:22: As77 IPCP: Address XXX.XXX.XXX.XXX
    > ~ (0x0306C0A88801)
    > ~ Sep 21 13:18:23: As77 IPXCP: I CONFREQ [Not negotiated] id 1 len 30
    > ~ Sep 21 13:18:23: As77 IPXCP: Network 0x00000000 (0x010600000000)
    > ~ Sep 21 13:18:23: As77 IPXCP: Node 0061.6e30.2e2f
    > ~ (0x020800616E302E2F)
    > ~ Sep 21 13:18:23: As77 IPXCP: Compression Telebit Compressed IPX
    > ~ (0x030600020F01)
    > ~ Sep 21 13:18:23: As77 IPXCP: Routing 0 (0x04040000)
    > ~ Sep 21 13:18:23: As77 IPXCP: ConfigComplete (0x0602)
    > ~ Sep 21 13:18:23: As77 LCP: O PROTREJ [Open] id 24 len 36 protocol
    > ~ IPXCP
    > ~ Sep 21 13:18:23: As77 LCP: (0x802B0101001E01060000000002080061)
    > ~ Sep 21 13:18:23: As77 LCP: (0x6E302E2F030600020F01040400000602)
    > ~ Sep 21 13:18:23: As77 IPCP: I CONFREQ [REQsent] id 1 len 40
    > ~ Sep 21 13:18:23: As77 IPCP: CompressType VJ 15 slots CompressSlotID
    > ~ (0x0206002D0F01)
    > ~ Sep 21 13:18:23: As77 IPCP: Address 0.0.0.0 (0x030600000000)
    > ~ Sep 21 13:18:23: As77 IPCP: PrimaryDNS 0.0.0.0 (0x810600000000)
    > ~ Sep 21 13:18:23: As77 IPCP: PrimaryWINS 0.0.0.0 (0x820600000000)
    > ~ Sep 21 13:18:23: As77 IPCP: SecondaryDNS 0.0.0.0 (0x830600000000)
    > ~ Sep 21 13:18:23: As77 IPCP: SecondaryWINS 0.0.0.0 (0x840600000000)
    > ~ Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we
    > ~ want 192.168.200.134
    > ~ Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Says use pool MC
    > ~ Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Pool returned 192.168. 200.134
    > ~ Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we
    > ~ want 192.168. 200.134
    > ~ Sep 21 13:18:23: As77 IPCP: O CONFREJ [REQsent] id 1 len 16
    > ~ Sep 21 13:18:23: As77 IPCP: PrimaryWINS 0.0.0.0 (0x820600000000)
    > ~ Sep 21 13:18:23: As77 IPCP: SecondaryWINS 0.0.0.0 (0x840600000000)
    > ~ Sep 21 13:18:23: As77 CCP: I CONFREQ [Not negotiated] id 1 len 15
    > ~ Sep 21 13:18:23: As77 CCP: MS-PPC supported bits 0x00000001
    > ~ (0x120600000001)
    > ~ Sep 21 13:18:23: As77 CCP: Stacker history 1 check mode EXTENDED
    > ~ (0x1105000104)
    > ~ Sep 21 13:18:23: As77 LCP: O PROTREJ [Open] id 25 len 21 protocol CCP
    > ~ Sep 21 13:18:23: As77 LCP: (0x80FD0101000F12060000000111050001)
    > ~ Sep 21 13:18:23: As77 LCP: (0x04)
    > ~ Sep 21 13:18:23: As77 IPCP: I CONFACK [REQsent] id 5 len 16
    > ~ Sep 21 13:18:23: As77 IPCP: CompressType VJ 15 slots
    > ~ (0x0206002D0F00)
    > ~ Sep 21 13:18:23: As77 IPCP: Address XXX.XXX.XXX.XXX
    > ~ (0x0306C0A88801)
    > ~ Sep 21 13:18:23: As77 IPCP: I CONFREQ [ACKrcvd] id 2 len 28
    > ~ Sep 21 13:18:23: As77 IPCP: CompressType VJ 15 slots CompressSlotID
    > ~ (0x0206002D0F01)
    > ~ Sep 21 13:18:23: As77 IPCP: Address 0.0.0.0 (0x030600000000)
    > ~ Sep 21 13:18:23: As77 IPCP: PrimaryDNS 0.0.0.0 (0x810600000000)
    > ~ Sep 21 13:18:23: As77 IPCP: SecondaryDNS 0.0.0.0 (0x830600000000)
    > ~ Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we
    > ~ want 192.168.200.134
    > ~ Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we
    > ~ want 192.168.200.134
    > ~ Sep 21 13:18:23: As77 IPCP: O CONFNAK [ACKrcvd] id 2 len 22
    > ~ Sep 21 13:18:23: As77 IPCP: Address 192.168. 200.134
    > ~ (0x0306C0A888B1)
    > ~ Sep 21 13:18:23: As77 IPCP: PrimaryDNS XXX.XXX.XXX.XXX
    > ~ (0x8106C0A886CA)
    > ~ Sep 21 13:18:23: As77 IPCP: SecondaryDNS XXX.XXX.XXX.XXX
    > ~ (0x8306D97660CD)
    > ~ Sep 21 13:18:23: As77 IPCP: I CONFREQ [ACKrcvd] id 3 len 28
    > ~ Sep 21 13:18:23: As77 IPCP: CompressType VJ 15 slots CompressSlotID
    > ~ (0x0206002D0F01)
    > ~ Sep 21 13:18:23: As77 IPCP: Address 192.168.200.134
    > ~ (0x0306C0A888B1)
    > ~ Sep 21 13:18:23: As77 IPCP: PrimaryDNS XXX.XXX.XXX.XXX
    > ~ (0x8106C0A886CA)
    > ~ Sep 21 13:18:23: As77 IPCP: SecondaryDNS XXX.XXX.XXX.XXX
    > ~ (0x8306D97660CD)
    > ~ Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Start. Her address
    > ~ 192.168.200.134, we want 192.168. 200.134
    > ~ Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Request 192.168.200.134 from
    > ~ pool MC
    > ~ Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Pool grants 192.168.200.134
    > ~ Sep 21 13:18:23: As77 AAA/AUTHOR/IPCP: Done. Her address
    > ~ 192.168.200.134, we want 192.168. 200.134
    > ~ Sep 21 13:18:23: As77 IPCP: O CONFACK [ACKrcvd] id 3 len 28
    > ~ Sep 21 13:18:23: As77 IPCP: CompressType VJ 15 slots CompressSlotID
    > ~ (0x0206002D0F01)
    > ~ Sep 21 13:18:23: As77 IPCP: Address 192.168.200.134
    > ~ (0x0306C0A888B1)
    > ~ Sep 21 13:18:23: As77 IPCP: PrimaryDNS XXX.XXX.XXX.XXX
    > ~ (0x8106C0A886CA)
    > ~ Sep 21 13:18:23: As77 IPCP: SecondaryDNS XXX.XXX.XXX.XXX
    > ~ (0x8306D97660CD)
    > ~ Sep 21 13:18:23: As77 IPCP: State is Open
    > ~ Sep 21 13:18:23: As77 IPCP: Install route to 192.168. 200.134
    > ~ Sep 21 13:18:36: As77 LCP: I TERMREQ [Open] id 4 len 4
    > ~ Sep 21 13:18:36: As77 LCP: O TERMACK [Open] id 4 len 4
    > ~ Sep 21 13:18:36: As77 IPCP: State is Closed
    > ~ Sep 21 13:18:36: As77 PPP: Phase is TERMINATING [0 sess, 0 load]
    > ~ Sep 21 13:18:36: As77 IPCP: Remove route to 192.168. 200.134
    > ~ Sep 21 13:18:36: Modem 2/12 Mica: in modem state TERMINATING
    > ~ Sep 21 13:18:36: Modem 2/12 CSM:
    > ~ (CSM_PROC_CONNECTED)<--MODEM_DISCONNECTED
    > ~ Sep 21 13:18:36: Modem 2/12 Mica: in modem state IDLE
    > ~ Sep 21 13:18:36: Modem 2/12 CSM:
    > ~ (CSM_PROC_CONNECTED)<--QUEUED_DISCONNECT
    > ~ Sep 21 13:18:36: Modem 2/12 CSM: CSM_MODEM_DEALLOCATE: modem is
    > ~ deallocated
    > ~ Sep 21 13:18:36: Modem 2/12 Mica: DISCONNECT after 00:00:45, due to
    > ~ reason (0x8220) EC rcvd DISC frame.
    > ~ Sep 21 13:18:36: CSM: MODEM_REPORT from 1/0:0, call_id=0x1CB,
    > ~ event=0x0, cause=0x10, dchan_idb=0x61519990
    > ~ Sep 21 13:18:36: CSM: MODEM_REPORT rcvd DEV_IDLE for call_id 0x1CB,
    > ~ modem not found due to wrong b channel num
    > ~ ber or b channel is deallocated
     
    Ada, Sep 23, 2004
    #3
    1. Advertising

Want to reply to this thread or ask your own question?

It takes just 2 minutes to sign up (and it's free!). Just click the sign up button to choose a username and then you can ask your own questions on the forum.
Similar Threads
  1. jamal
    Replies:
    1
    Views:
    888
  2. JanC
    Replies:
    5
    Views:
    2,475
    Aaron Leonard
    Oct 17, 2003
  3. Reza
    Replies:
    0
    Views:
    5,746
  4. Replies:
    2
    Views:
    5,147
    thrill5
    Jan 28, 2006
  5. Carlo
    Replies:
    0
    Views:
    529
    Carlo
    Feb 14, 2006
Loading...

Share This Page