[c-nsp] PPP fails with IOS upgrade

[Joseph Mays]

I sent a message yesterday about a problem we are having on an AS5400. PPP works fine with version 12.2.16, but fails with version 12.3.13. The config is not changing between the two versions. Here's information on the problem that is a bit more specific. With the old version of IOS everything proceeds as normally, as shown by the following debug output (debug ppp events, errors, and negotiation). With the new version, the debug output is identical through pap authentication (with the exception of a session ID line that doesn't show up with the old version, but I don't think it has anything to do with the problem). Immediately after authentication, the new version begins sending an IPCP packet (with a "ccp code"?). It sends it over and over. On the client side, windows dial-up times out during "Registering your computer on the network" saying it timed out awaiting a response from the server.

This is a confusing and disturbing problem, though I have a suspicion that when we arrive at the answer it will turn out to be something quite simple and easy to fix. Any help that can be offered would be appreciated.




With IOS c5400-js-mz.122-16.T17.bin

005248: Aug 23 12:00:14.918: As2/42 LCP: Lower layer not up, Fast Starting
005249: Aug 23 12:00:14.918: As2/42 PPP: Using dialer call direction
005250: Aug 23 12:00:14.918: As2/42 PPP: Treating connection as a callin
005251: Aug 23 12:00:14.918: As2/42 PPP: Phase is ESTABLISHING, Passive Open
005252: Aug 23 12:00:14.918: As2/42 LCP: State is Listen
[...]
005299: Aug 23 12:00:15.174: As2/42 PAP: Authenticating peer launchpad at win.net
005300: Aug 23 12:00:15.174: As2/42 PPP: Phase is FORWARDING, Attempting Forward
005301: Aug 23 12:00:15.174: As2/42 EVT: Hook 1 0x00000000
005302: Aug 23 12:00:15.174: As2/42 EVT: Hook 1 0x00000000
005303: Aug 23 12:00:15.174: As2/42 EVT: Forwarded 0 0x00000000
005304: Aug 23 12:00:15.174: As2/42 PPP: Phase is AUTHENTICATING, Unauthenticated User
005305: Aug 23 12:00:15.230: As2/42 EVT: AAA Response 0 0x6387270C
005306: Aug 23 12:00:15.230: As2/42 PPP: Phase is FORWARDING, Attempting Forward
005307: Aug 23 12:00:15.230: As2/42 EVT: Hook 1 0x00000000
005308: Aug 23 12:00:15.230: As2/42 EVT: Forwarded 0 0x00000000
005309: Aug 23 12:00:15.230: As2/42 PPP: Phase is AUTHENTICATING, Authenticated User
005310: Aug 23 12:00:15.230: As2/42 EVT: AAA Response 0 0x64BBD314
005311: Aug 23 12:00:15.230: As2/42 PAP: O AUTH-ACK id 27 len 5
005312: Aug 23 12:00:15.234: As2/42 PPP: Phase is UP
[...]
005361: Aug 23 12:00:15.550: As2/42 IPCP: Add link info for cef entry 216.24.0.207


With IOS c5400-js-mz.123-13b.bin

000835: Aug 23 12:15:59.328: As2/46 LCP: Lower layer not up, Fast Starting
000836: Aug 23 12:15:59.328: As2/46 PPP: Using dialer call direction
000837: Aug 23 12:15:59.328: As2/46 PPP: Treating connection as a callin
000838: Aug 23 12:15:59.328: As2/46 PPP: Session handle[D0000062] Session id[0]
000839: Aug 23 12:15:59.328: As2/46 PPP: Phase is ESTABLISHING, Passive Open
000840: Aug 23 12:15:59.328: As2/46 LCP: State is Listen
[...]
000887: Aug 23 12:15:59.576: As2/46 PAP: Authenticating peer launchpad at win.net
000888: Aug 23 12:15:59.576: As2/46 PPP: Phase is FORWARDING, Attempting Forward
000889: Aug 23 12:15:59.576: As2/46 EVT: Hook 1 0x00000000
000890: Aug 23 12:15:59.580: As2/46 EVT: Forwarded 0 0x00000000
000891: Aug 23 12:15:59.580: As2/46 PPP: Phase is AUTHENTICATING, Unauthenticated User
000892: Aug 23 12:15:59.584: As2/46 EVT: AAA Response 0 0x64DFF388
000893: Aug 23 12:15:59.584: As2/46 PPP: Phase is FORWARDING, Attempting Forward
000894: Aug 23 12:15:59.584: As2/46 EVT: Hook 1 0x00000000
000895: Aug 23 12:15:59.584: As2/46 EVT: Forwarded 0 0x00000000
000896: Aug 23 12:15:59.584: As2/46 PPP: Phase is AUTHENTICATING, Authenticated User
000897: Aug 23 12:15:59.584: As2/46 EVT: AAA Response 0 0x64E0A3EC
000898: Aug 23 12:15:59.584: As2/46 EVT: AAA Response 0 0x64DDA8F8
000899: Aug 23 12:15:59.588: As2/46 PAP: O AUTH-ACK id 30 len 5
000900: Aug 23 12:15:59.700: As2/46 EVT: Packet 0 0x62AC4B40
000901: Aug 23 12:15:59.700: As2/46 PPP: Queue CCP code[1] id[4]
000902: Aug 23 12:15:59.700: As2/46 EVT: IPCP Packet 0 0x62AC7508
000903: Aug 23 12:15:59.700: As2/46 PPP: Queue IPCP code[1] id[5]
000904: Aug 23 12:16:01.328: As2/46 EVT: IPCP Packet 0 0x62AC98D8
000905: Aug 23 12:16:01.328: As2/46 PPP: Update queued IPCP code[1] id[6]
000906: Aug 23 12:16:01.328: As2/46 EVT: Packet 0 0x62AC9BD4
000907: Aug 23 12:16:01.328: As2/46 PPP: Update queued CCP code[1] id[7]
000908: Aug 23 12:16:04.328: As2/46 EVT: IPCP Packet 0 0x62AD4EE4
000909: Aug 23 12:16:04.328: As2/46 PPP: Update queued IPCP code[1] id[8]
[...]