Velocity Reviews - Computer Hardware Reviews

Velocity Reviews > Newsgroups > Computing > Cisco > C3640 ISDN PRI dial-in problem

Reply
Thread Tools

C3640 ISDN PRI dial-in problem

 
 
Ada
Guest
Posts: n/a
 
      09-22-2004
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
 
Reply With Quote
 
 
 
 
Aaron Leonard
Guest
Posts: n/a
 
      09-23-2004
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

 
Reply With Quote
 
 
 
 
Ada
Guest
Posts: n/a
 
      09-23-2004
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 <(E-Mail Removed)> wrote in message news:<(E-Mail Removed)>. ..
> 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

 
Reply With Quote
 
 
 
Reply

Thread Tools

Posting Rules
You may not post new threads
You may not post replies
You may not post attachments
You may not edit your posts

BB code is On
Smilies are On
[IMG] code is On
HTML code is Off
Trackbacks are On
Pingbacks are On
Refbacks are Off


Similar Threads
Thread Thread Starter Forum Replies Last Post
pc with isdn modem not connecte isdn 1841 router with isdn module sync Cisco 0 06-05-2007 10:10 AM
PRI to PRI with bidirectional channel Carlo Cisco 0 02-14-2006 09:40 PM
Cisco 2600 E1 ISDN PRI Voice Problem . Dial tone does not stop after DTMF Reza Cisco 0 04-22-2004 07:16 AM
C3640 - Incoming ISDN fails - JanC Cisco 5 10-17-2003 07:45 PM
Atlas 550 PRI to Cisco 3620 Channelized PRI port problem jamal Cisco 1 07-25-2003 02:51 PM



Advertisments