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

From: Aaron Leonard (Aaron@Cisco.COM)
Date: Tue Jun 11 2002 - 14:58:11 EDT


Hm, interesting.

I don't think that CSCdi75794 is applicable, since it
(supposedly) is specific to the 2400 bps V.34 / nonLAPM
case, while Simon's problem is with 2400 bps V.22bis / nonLAPM.

I'd probably first try upgrading from 12.0(2a)T1. I'd start with
12.2(10a) (if feasible) in order to pick up the latest NM-AM
firmware. (If that isn't an option, I'd go to 12.1(latest) [which
should require no more memory than 12.0T] then manually upgrade to
1.2.2 firmware from http://www.cisco.com/pcgi-bin/tablebuild.pl/x600-analog .)

If that doesn't provide relief, then one would want to open a
TAC case and do some serious troubleshooting. This would involve
varying the client modem, the circuit, and the server modem, and
examining the octets sent and received on each end of each call,
in order to assess the scope of the problem.

Aaron

---

> [adding in cisco-nas]

> Looks like: CSCdi75794 - V.34 without Error Correction fails at 2400 bps

> Not sure what to do about it though...

> Josh

> ----- Original Message ----- > From: "Hailstone, Simon" <SHailstone@ndsuk.com> > To: <cisco-nsp@puck.nether.net> > Sent: Tuesday, June 11, 2002 10:56 AM > Subject: [nsp] Weird PPP problem with NM-8AM in 2610

> > 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