[nsp] Weird PPP problem with NM-8AM in 2610

From: Hailstone, Simon (SHailstone@ndsuk.com)
Date: Tue Jun 11 2002 - 11:56:18 EDT


Hi All

I am having a strange problem with a 2610 running 12.0(2a)T1 with
a NM-8AM, MCOM firmware(s) boot 1.1.5 MIMIC 1.3.3 Modem 2.3.11 DSP 0.0.2

I am doing PPP dialup with CHAP for a variety of different devices,
including several embedded devices.

This is working pretty much fine except for a problem that only occurs
at v22bis. With LAPM and V42bis, I can connect at 2400 perfectly, and
LCP negotiation occurs correctly, IPCP etc. Absolutely fine.

However, if I disable LAPM I can still "CONNECT" but LCP doesn't
complete correctly...

Anyone ever seen a similar problem?
A somewhat verbose bebug log follows below.

Thanks in advance,
Simon Hailstone

PS I do have a good reason for wanting to do v22bis
   without LAPM and v42bis!

======================================================================

19:29:06: Modem 1/7 Mcom: in modem state 'Dialing/Answering'
19:29:06: Modem 1/7 Mcom: in modem state 'Incoming ring'
19:29:09: Modem 1/7 Mcom: in modem state 'Waiting for Carrier'
19:29:14: Modem 1/7 Mcom: in modem state 'Connected'
19:29:15: Modem 1/7 Mcom: CONNECT at 2400/2400(Tx/Rx), V22bis, Normal, None,
Answer
19:29:16: TTY40: DSR came up
19:29:16: tty40: Modem: IDLE->READY
19:29:16: TTY40: EXEC creation
19:29:16: TTY40: set timer type 10, 30 seconds
19:29:20: TTY40: Autoselect(2) sample 2
19:29:20: TTY40: Autoselect(2) sample 201
19:29:20: TTY40: Autoselect(2) sample 20103
19:29:20: TTY40: set timer type 10, 30 seconds
19:29:22: TTY40: Autoselect(2) sample 201037E
19:29:22: TTY40: Autoselect(2) sample 1037EFF
19:29:22: TTY40: Autoselect(2) sample 37EFF7D
19:29:22: TTY40: Autoselect(2) sample 7EFF7D23
19:29:22: TTY40 Autoselect cmd: ppp negotiate
19:29:22: TTY40: EXEC creation
19:29:22: TTY40: create timer type 1, 600 seconds
19:29:22: As40 PPP: Consuming data in TTY40 receive queue
19:29:22: Async40: Setup PPP framing on TTY40
19:29:22: TTY40: destroy timer type 1 (OK)
19:29:22: TTY40: destroy timer type 0
19:29:22: As40 PPP: Async Protocol Mode started for 172.20.240.23
19:29:22: As40 AAA/ACCT: Using PPP accounting list ""
19:29:22: As40 PPP: Processed packet cached during autoselect
19:29:24: %LINK-3-UPDOWN: Interface Async40, changed state to up
19:29:24: As40 PPP: Treating connection as a dedicated line
19:29:24: As40 PPP: Phase is ESTABLISHING, Active Open
19:29:24: Modem 1/7 Mcom: PPP escape map: Tx map = FFFFFFFF, Rx map = 0
19:29:24: As40 LCP: O CONFREQ [Closed] id 163 len 25
19:29:24: As40 LCP: ACCM 0x000A0000 (0x0206000A0000)
19:29:24: As40 LCP: AuthProto CHAP (0x0305C22305)
19:29:24: As40 LCP: MagicNumber 0x54A1DD19 (0x050654A1DD19)
19:29:24: As40 LCP: PFC (0x0702)
19:29:24: As40 LCP: ACFC (0x0802)
19:29:24: APPP40: Output packet, len = 29, header = FF 3 C0 21
19:29:24: APPP40: CRC error
19:29:24: APPP40: Input packet, len = 29, header = FF 3 C0 21
19:29:24: As40 PPP: I pkt type 0xC021, datagramsize 29
19:29:24: As40 PPP: I pkt type 0xC021, datagramsize 29
19:29:24: As40 LCP: I CONFACK [REQsent] id 163 len 25
19:29:24: As40 LCP: ACCM 0x000A0000 (0x0206000A0000)
19:29:24: As40 LCP: AuthProto CHAP (0x0305C22305)
19:29:24: As40 LCP: MagicNumber 0x54A1DD19 (0x050654A1DD19)
19:29:24: As40 LCP: PFC (0x0702)
19:29:24: As40 LCP: ACFC (0x0802)
19:29:26: As40 LCP: TIMEout: State ACKrcvd
19:29:26: As40 LCP: O CONFREQ [ACKrcvd] id 164 len 25
19:29:26: As40 LCP: ACCM 0x000A0000 (0x0206000A0000)
19:29:26: As40 LCP: AuthProto CHAP (0x0305C22305)
19:29:26: As40 LCP: MagicNumber 0x54A1DD19 (0x050654A1DD19)
19:29:26: As40 LCP: PFC (0x0702)
19:29:26: As40 LCP: ACFC (0x0802)
19:29:26: APPP40: Output packet, len = 29, header = FF 3 C0 21
19:29:26: APPP40: Input packet, len = 29, header = FF 3 C0 21
19:29:26: As40 PPP: I pkt type 0xC021, datagramsize 29
19:29:26: As40 PPP: I pkt type 0xC021, datagramsize 29
19:29:26: As40 LCP: I CONFACK [REQsent] id 164 len 25
19:29:26: As40 LCP: ACCM 0x000A0000 (0x0206000A0000)
19:29:26: As40 LCP: AuthProto CHAP (0x0305C22305)
19:29:26: As40 LCP: MagicNumber 0x54A1DD19 (0x050654A1DD19)
19:29:26: As40 LCP: PFC (0x0702)
19:29:26: As40 LCP: ACFC (0x0802)
19:29:28: APPP40: Input packet, len = 27, header = FF 3 C0 21
19:29:28: As40 PPP: I pkt type 0xC021, datagramsize 27
19:29:28: As40 PPP: I pkt type 0xC021, datagramsize 27
19:29:28: As40 LCP: I CONFREQ [ACKrcvd] id 0 len 23
19:29:28: As40 LCP: ACCM 0x00000000 (0x020600000000)
19:29:28: As40 LCP: MagicNumber 0x00002DE2 (0x050600002DE2)
19:29:28: As40 LCP: PFC (0x0702)
19:29:28: As40 LCP: ACFC (0x0802)
19:29:28: As40 LCP: Callback 6 (0x0D0306)
19:29:28: Async40: Enabling PPP framing in UART's Microcode on line TTY40
19:29:28: Modem 1/7 Mcom: switching to PPP mode succeeded
19:29:28: As40 LCP: O CONFREJ [ACKrcvd] id 0 len 7
19:29:28: As40 LCP: Callback 6 (0x0D0306)
19:29:28: As40 LCP: TIMEout: State ACKrcvd
19:29:28: As40 LCP: O CONFREQ [ACKrcvd] id 165 len 25
19:29:28: As40 LCP: ACCM 0x000A0000 (0x0206000A0000)
19:29:28: As40 LCP: AuthProto CHAP (0x0305C22305)
19:29:28: As40 LCP: MagicNumber 0x54A1DD19 (0x050654A1DD19)
19:29:28: As40 LCP: PFC (0x0702)
19:29:28: As40 LCP: ACFC (0x0802)
19:29:30: As40 LCP: TIMEout: State REQsent
19:29:30: As40 LCP: O CONFREQ [REQsent] id 166 len 25
19:29:30: As40 LCP: ACCM 0x000A0000 (0x0206000A0000)
19:29:30: As40 LCP: AuthProto CHAP (0x0305C22305)
19:29:30: As40 LCP: MagicNumber 0x54A1DD19 (0x050654A1DD19)
19:29:30: As40 LCP: PFC (0x0702)
19:29:30: As40 LCP: ACFC (0x0802)
19:29:32: As40 LCP: TIMEout: State REQsent
19:29:32: As40 LCP: O CONFREQ [REQsent] id 167 len 25
19:29:32: As40 LCP: ACCM 0x000A0000 (0x0206000A0000)
19:29:32: As40 LCP: AuthProto CHAP (0x0305C22305)
19:29:32: As40 LCP: MagicNumber 0x54A1DD19 (0x050654A1DD19)
19:29:32: As40 LCP: PFC (0x0702)
19:29:32: As40 LCP: ACFC (0x0802)
19:29:34: As40 PPP: I pkt type 0xC021, datagramsize 27
19:29:34: As40 PPP: I pkt type 0xC021, datagramsize 27
19:29:34: As40 LCP: I CONFREQ [REQsent] id 0 len 23
19:29:34: As40 LCP: ACCM 0x00000000 (0x020600000000)
19:29:34: As40 LCP: MagicNumber 0x00002DE2 (0x050600002DE2)
19:29:34: As40 LCP: PFC (0x0702)
19:29:34: As40 LCP: ACFC (0x0802)
19:29:34: As40 LCP: Callback 6 (0x0D0306)
19:29:34: As40 LCP: O CONFREJ [REQsent] id 0 len 7
19:29:34: As40 LCP: Callback 6 (0x0D0306)
19:29:34: As40 LCP: TIMEout: State REQsent
19:29:34: As40 LCP: O CONFREQ [REQsent] id 168 len 25
19:29:34: As40 LCP: ACCM 0x000A0000 (0x0206000A0000)
19:29:34: As40 LCP: AuthProto CHAP (0x0305C22305)
19:29:34: As40 LCP: MagicNumber 0x54A1DD19 (0x050654A1DD19)
19:29:34: As40 LCP: PFC (0x0702)
19:29:34: As40 LCP: ACFC (0x0802)
19:29:36: As40 LCP: TIMEout: State REQsent
19:29:36: As40 LCP: O CONFREQ [REQsent] id 169 len 25
19:29:36: As40 LCP: ACCM 0x000A0000 (0x0206000A0000)
19:29:36: As40 LCP: AuthProto CHAP (0x0305C22305)
19:29:36: As40 LCP: MagicNumber 0x54A1DD19 (0x050654A1DD19)
19:29:36: As40 LCP: PFC (0x0702)
19:29:36: As40 LCP: ACFC (0x0802)
19:29:38: As40 LCP: TIMEout: State REQsent
19:29:38: As40 LCP: O CONFREQ [REQsent] id 170 len 25
19:29:38: As40 LCP: ACCM 0x000A0000 (0x0206000A0000)
19:29:38: As40 LCP: AuthProto CHAP (0x0305C22305)
19:29:38: As40 LCP: MagicNumber 0x54A1DD19 (0x050654A1DD19)
19:29:38: As40 LCP: PFC (0x0702)
19:29:38: As40 LCP: ACFC (0x0802)
19:29:40: As40 PPP: I pkt type 0xC021, datagramsize 27
19:29:40: As40 PPP: I pkt type 0xC021, datagramsize 27
19:29:40: As40 LCP: I CONFREQ [REQsent] id 0 len 23
19:29:40: As40 LCP: ACCM 0x00000000 (0x020600000000)
19:29:40: As40 LCP: MagicNumber 0x00002DE2 (0x050600002DE2)
19:29:40: As40 LCP: PFC (0x0702)
19:29:40: As40 LCP: ACFC (0x0802)
19:29:40: As40 LCP: Callback 6 (0x0D0306)
19:29:40: As40 LCP: O CONFREJ [REQsent] id 0 len 7
19:29:40: As40 LCP: Callback 6 (0x0D0306)
19:29:40: As40 LCP: TIMEout: State REQsent
19:29:40: As40 LCP: O CONFREQ [REQsent] id 171 len 25
19:29:40: As40 LCP: ACCM 0x000A0000 (0x0206000A0000)
19:29:40: As40 LCP: AuthProto CHAP (0x0305C22305)
19:29:40: As40 LCP: MagicNumber 0x54A1DD19 (0x050654A1DD19)
19:29:40: As40 LCP: PFC (0x0702)
19:29:40: As40 LCP: ACFC (0x0802)
19:29:42: As40 LCP: TIMEout: State REQsent
19:29:42: As40 LCP: O CONFREQ [REQsent] id 172 len 25
19:29:42: As40 LCP: ACCM 0x000A0000 (0x0206000A0000)
19:29:42: As40 LCP: AuthProto CHAP (0x0305C22305)
19:29:42: As40 LCP: MagicNumber 0x54A1DD19 (0x050654A1DD19)
19:29:42: As40 LCP: PFC (0x0702)
19:29:42: As40 LCP: ACFC (0x0802)
19:29:44: As40 LCP: TIMEout: State REQsent
19:29:44: As40 LCP: O CONFREQ [REQsent] id 173 len 25
19:29:44: As40 LCP: ACCM 0x000A0000 (0x0206000A0000)
19:29:44: As40 LCP: AuthProto CHAP (0x0305C22305)
19:29:44: As40 LCP: MagicNumber 0x54A1DD19 (0x050654A1DD19)
19:29:44: As40 LCP: PFC (0x0702)
19:29:44: As40 LCP: ACFC (0x0802)
19:29:46: As40 PPP: I pkt type 0xC021, datagramsize 27
19:29:46: As40 PPP: I pkt type 0xC021, datagramsize 27
19:29:46: As40 LCP: I CONFREQ [REQsent] id 0 len 23
19:29:46: As40 LCP: ACCM 0x00000000 (0x020600000000)
19:29:46: As40 LCP: MagicNumber 0x00002DE2 (0x050600002DE2)
19:29:46: As40 LCP: PFC (0x0702)
19:29:46: As40 LCP: ACFC (0x0802)
19:29:46: As40 LCP: Callback 6 (0x0D0306)
19:29:46: As40 LCP: O CONFREJ [REQsent] id 0 len 7
19:29:46: As40 LCP: Callback 6 (0x0D0306)
19:29:46: As40 LCP: TIMEout: State REQsent
19:29:46: TTY40: Async Int reset: Dropping DTR
19:29:46: As40 LCP: State is Listen
19:29:46: Modem 1/7 Mcom: in modem state 'Disconnecting'
19:29:46: Modem 1/7 Mcom: DISCONNECT, duration = 00:00:32, reason (0x9) DTR
Drop
19:29:47: TTY40: DSR was dropped
19:29:47: tty40: Modem: READY->HANGUP
19:29:47: Modem 1/7 Mcom: in modem state 'Idle'
19:29:48: TTY40: dropping DTR, hanging up
19:29:48: tty40: Modem: HANGUP->IDLE
19:29:48: %LINK-5-CHANGED: Interface Async40, changed state to reset
19:29:48: As40 LCP: State is Closed
19:29:48: As40 PPP: Phase is DOWN
19:29:48: As40 IPCP: Remove route to 172.20.240.23
19:29:49: TTY40: cleanup pending. Delaying DTR
19:29:50: TTY40: cleanup pending. Delaying DTR
19:29:51: TTY40: cleanup pending. Delaying DTR
19:29:51: Async40: Async protocol mode stopped for 0.0.0.0
19:29:51: Modem 1/7 Mcom: switching to character mode
19:29:51: Async40: Reset PPP framing on TTY40
19:29:51: TTY40: destroy timer type 0
19:29:51: TTY40: destroy timer type 1
19:29:51: TTY40: destroy timer type 3
19:29:51: TTY40: destroy timer type 4
19:29:51: TTY40: destroy timer type 2
19:29:51: Async40: allowing modem_process to continue hangup
19:29:52: TTY40: restoring DTR
19:29:53: TTY40: autoconfigure probe started
19:29:53: %LINK-3-UPDOWN: Interface Async40, changed state to down
19:29:53: As40 LCP: State is Closed
19:29:53: As40 PPP: Phase is DOWN



This archive was generated by hypermail 2b29 : Sun Aug 04 2002 - 04:13:46 EDT