[cisco-nas] strange double AUTH'ing for same PPP sessions with AS5300/12.2(15)T9

Gerald Krause gk at pop-interactive.de
Thu Jan 22 18:25:21 EST 2004


Hi,

after an IOS update we have some trouble with AUTH'ing normal
PPP sessions. When users connecting to the NAS without MultiLink
PPP, the AUTH'ing against the RADIUS servers will be made two times! 

Even this is not weird enough the main significant difference between
the two is AUTH'ings is, that during the second AUTH'ing no CLID's are
included within the AUTH-REQ packets (we have sniffed this) but we
rely on this :(.

Have someone out there an idea why this can happen?

normal AUTH'ing with 12.1(17):
------------------------------

00:18:01.866: Se3:29 PPP: Treating connection as a callin
00:18:01.866: Se3:29 PPP: Phase is ESTABLISHING, Passive Open
00:18:01.866: Se3:29 LCP: State is Listen
00:18:01.906: ISDN Se3:15: received CALL_PROGRESSing call_id 0x42DF
00:18:02.494: Se3:29 LCP: I CONFREQ [Listen] id 1 len 26
00:18:02.494: Se3:29 LCP:    MRU 1524 (0x010405F4)
00:18:02.494: Se3:29 LCP:    QualityType 0xC025 period 1000 (0x0408C025000003E8)
00:18:02.494: Se3:29 LCP:    MagicNumber 0x44D4DA36 (0x050644D4DA36)
00:18:02.494: Se3:29 LCP:    PFC (0x0702)
00:18:02.494: Se3:29 LCP:    ACFC (0x0802)
00:18:02.494: Se3:29 LCP: O CONFREQ [Listen] id 182 len 28
00:18:02.494: Se3:29 LCP:    AuthProto PAP (0x0304C023)
00:18:02.494: Se3:29 LCP:    MagicNumber 0xB4FF1EBE (0x0506B4FF1EBE)
00:18:02.494: Se3:29 LCP:    MRRU 1524 (0x110405F4)
00:18:02.494: Se3:29 LCP:    EndpointDisc 1 Local (0x130A0161732D706F7069)
00:18:02.494: Se3:29 LCP: O CONFACK [Listen] id 1 len 26
00:18:02.494: Se3:29 LCP:    MRU 1524 (0x010405F4)
00:18:02.498: Se3:29 LCP:    QualityType 0xC025 period 1000 (0x0408C025000003E8)
00:18:02.498: Se3:29 LCP:    MagicNumber 0x44D4DA36 (0x050644D4DA36)
00:18:02.498: Se3:29 LCP:    PFC (0x0702)
00:18:02.498: Se3:29 LCP:    ACFC (0x0802)
00:18:02.558: Se3:29 LCP: I CONFREJ [ACKsent] id 182 len 18
00:18:02.558: Se3:29 LCP:    MRRU 1524 (0x110405F4)
00:18:02.558: Se3:29 LCP:    EndpointDisc 1 Local (0x130A0161732D706F7069)
00:18:02.558: Se3:29 LCP: O CONFREQ [ACKsent] id 183 len 14
00:18:02.558: Se3:29 LCP:    AuthProto PAP (0x0304C023)
00:18:02.558: Se3:29 LCP:    MagicNumber 0xB4FF1EBE (0x0506B4FF1EBE)
00:18:02.594: Se3:29 LCP: I CONFACK [ACKsent] id 183 len 14
00:18:02.594: Se3:29 LCP:    AuthProto PAP (0x0304C023)
00:18:02.594: Se3:29 LCP:    MagicNumber 0xB4FF1EBE (0x0506B4FF1EBE)
00:18:02.594: Se3:29 LCP: State is Open
00:18:02.598: Se3:29 PPP: Phase is AUTHENTICATING, by this end
00:18:02.602: Se3:29 PAP: I AUTH-REQ id 1 len 19 from "henne"
00:18:02.602: Se3:29 PPP: Phase is FORWARDING
00:18:02.602: Se3:29 PPP: Phase is AUTHENTICATING
00:18:02.602: Se3:29 PAP: Authenticating peer henne
00:18:02.718: Se3:29 PAP: O AUTH-ACK id 1 len 5
00:18:02.718: Se3:29 DDR: Authenticated host henne with no matching dialer map

00:18:02.762: Vi104 PPP: Using set call direction
00:18:02.762: Vi104 PPP: Treating connection as a callin
00:18:02.762: Vi104 PPP: Phase is ESTABLISHING, Passive Open
00:18:02.762: Vi104 LCP: State is Listen
00:18:02.762: Se3:29 PPP: Phase is FORWARDED
00:18:02.762: Vi104 LCP: I FORCED CONFREQ len 10
00:18:02.762: Vi104 LCP:    AuthProto PAP (0x0304C023)
00:18:02.762: Vi104 LCP:    MagicNumber 0xB4FF1EBE (0x0506B4FF1EBE)
00:18:02.762: Vi104 PPP: Phase is UP
00:18:02.766: Vi104 IPCP: O CONFREQ [Closed] id 219 len 10
00:18:02.766: Vi104 IPCP:    Address 212.79.63.223 (0x0306D44F3FDF)
00:18:02.806: Vi104 IPCP: I CONFREQ [REQsent] id 1 len 10
00:18:02.806: Vi104 IPCP:    Address 0.0.0.0 (0x030600000000)
00:18:02.806: Vi104 AAA/AUTHOR/IPCP: Start.  Her address 0.0.0.0, we want 0.0.0.0
...


double AUTH'ing with 12.2(15)T9:
--------------------------------


23:47:40.405: Se3:3 PPP: Using dialer call direction
23:47:40.405: Se3:3 PPP: Treating connection as a callin
23:47:40.405: Se3:3 PPP: Phase is ESTABLISHING, Passive Open
23:47:40.405: Se3:3 LCP: State is Listen
23:47:41.001: Se3:3 LCP: I CONFREQ [Listen] id 1 len 26
23:47:41.001: Se3:3 LCP:    MRU 1524 (0x010405F4)
23:47:41.001: Se3:3 LCP:    QualityType 0xC025 period 1000 (0x0408C025000003E8)
23:47:41.001: Se3:3 LCP:    MagicNumber 0xB91CEA37 (0x0506B91CEA37)
23:47:41.005: Se3:3 LCP:    PFC (0x0702)
23:47:41.005: Se3:3 LCP:    ACFC (0x0802)
23:47:41.005: Se3:3 PPP: Authorization required
23:47:41.005: Se3:3 LCP: O CONFREQ [Listen] id 254 len 28
23:47:41.005: Se3:3 LCP:    AuthProto PAP (0x0304C023)
23:47:41.005: Se3:3 LCP:    MagicNumber 0x378525F8 (0x0506378525F8)
23:47:41.005: Se3:3 LCP:    MRRU 1524 (0x110405F4)
23:47:41.005: Se3:3 LCP:    EndpointDisc 1 as-popi (0x130A0161732D706F7069)
23:47:41.005: Se3:3 LCP: O CONFACK [Listen] id 1 len 26
23:47:41.005: Se3:3 LCP:    MRU 1524 (0x010405F4)
23:47:41.005: Se3:3 LCP:    QualityType 0xC025 period 1000 (0x0408C025000003E8)
23:47:41.005: Se3:3 LCP:    MagicNumber 0xB91CEA37 (0x0506B91CEA37)
23:47:41.005: Se3:3 LCP:    PFC (0x0702)
23:47:41.005: Se3:3 LCP:    ACFC (0x0802)
23:47:41.045: Se3:3 LCP: I CONFREJ [ACKsent] id 254 len 18
23:47:41.045: Se3:3 LCP:    MRRU 1524 (0x110405F4)
23:47:41.045: Se3:3 LCP:    EndpointDisc 1 as-popi (0x130A0161732D706F7069)
23:47:41.045: Se3:3 LCP: O CONFREQ [ACKsent] id 255 len 14
23:47:41.045: Se3:3 LCP:    AuthProto PAP (0x0304C023)
23:47:41.045: Se3:3 LCP:    MagicNumber 0x378525F8 (0x0506378525F8)
23:47:41.081: Se3:3 LCP: I CONFACK [ACKsent] id 255 len 14
23:47:41.081: Se3:3 LCP:    AuthProto PAP (0x0304C023)
23:47:41.085: Se3:3 LCP:    MagicNumber 0x378525F8 (0x0506378525F8)
23:47:41.085: Se3:3 LCP: State is Open
23:47:41.085: Se3:3 PPP: Phase is AUTHENTICATING, by this end
23:47:41.085: Se3:3 PAP: I AUTH-REQ id 1 len 19 from "henne"
23:47:41.085: Se3:3 PAP: Authenticating peer henne
23:47:41.089: Se3:3 PPP: Phase is FORWARDING, Attempting Forward
23:47:41.089: Se3:3 PPP: Phase is AUTHENTICATING, Unauthenticated User
23:47:41.089: Se3:3 PPP: Sent PAP LOGIN Request
23:47:41.137: Se3:3 PPP: Received LOGIN Response PASS
23:47:41.137: Se3:3 PPP: Phase is FORWARDING, Attempting Forward
23:47:41.137: Se3:3 PPP: Phase is AUTHENTICATING, Authenticated User
23:47:41.137: Se3:3 DDR: Remote name for henne
23:47:41.137: Se3:3 DDR: Authenticated host henne with no matching dialer map
23:47:41.137: Se3:3 PAP: O AUTH-ACK id 1 len 5
23:47:41.141: Se3:3 PPP: Phase is FORWARDING
23:47:41.153: Se3:3 PPP: Phase is FORWARDED
23:47:41.153: Se3:3 PPP: Process pending packets

23:47:41.157: Vi24 PPP: Using vpn set call direction
23:47:41.157: Vi24 PPP: Treating connection as a callin
23:47:41.157: Vi24 PPP: Phase is ESTABLISHING, Passive Open
23:47:41.157: Vi24 LCP: State is Listen
23:47:41.225: Vi24 IPCP: LCP not open, discarding packet
23:47:42.081: Vi24 LQR: LCP not open, discarding packet
23:47:43.077: Vi24 LQR: LCP not open, discarding packet
23:47:43.169: Vi24 LCP: TIMEout: State Listen
23:47:43.169: Vi24 PPP: Authorization required
23:47:43.169: Vi24 LCP: O CONFREQ [Listen] id 62 len 14
23:47:43.169: Vi24 LCP:    AuthProto PAP (0x0304C023)
23:47:43.169: Vi24 LCP:    MagicNumber 0x37852E6E (0x050637852E6E)
23:47:43.241: Vi24 LCP: I CONFREQ [REQsent] id 2 len 26
23:47:43.241: Vi24 LCP:    MRU 1524 (0x010405F4)
23:47:43.241: Vi24 LCP:    QualityType 0xC025 period 1000 (0x0408C025000003E8)
23:47:43.241: Vi24 LCP:    MagicNumber 0x99469280 (0x050699469280)
23:47:43.241: Vi24 LCP:    PFC (0x0702)
23:47:43.241: Vi24 LCP:    ACFC (0x0802)
23:47:43.241: Vi24 LCP: O CONFACK [REQsent] id 2 len 26
23:47:43.241: Vi24 LCP:    MRU 1524 (0x010405F4)
23:47:43.241: Vi24 LCP:    QualityType 0xC025 period 1000 (0x0408C025000003E8)
23:47:43.241: Vi24 LCP:    MagicNumber 0x99469280 (0x050699469280)
23:47:43.241: Vi24 LCP:    PFC (0x0702)
23:47:43.241: Vi24 LCP:    ACFC (0x0802)
23:47:43.245: Vi24 LCP: I CONFACK [ACKsent] id 62 len 14
23:47:43.245: Vi24 LCP:    AuthProto PAP (0x0304C023)
23:47:43.245: Vi24 LCP:    MagicNumber 0x37852E6E (0x050637852E6E)
23:47:43.245: Vi24 LCP: State is Open
23:47:43.245: Vi24 PPP: Phase is AUTHENTICATING, by this end
23:47:43.281: Vi24 PAP: I AUTH-REQ id 1 len 19 from "henne"
23:47:43.281: Vi24 PAP: Authenticating peer henne
23:47:43.281: Vi24 PPP: Sent PAP LOGIN Request
23:47:43.329: Vi24 PPP: Received LOGIN Response PASS
23:47:43.329: Vi24 PAP: O AUTH-ACK id 1 len 5
23:47:43.329: Vi24 PPP: Phase is UP
23:47:43.329: Vi24 IPCP: O CONFREQ [Closed] id 1 len 10
23:47:43.329: Vi24 IPCP:    Address 212.79.63.223 (0x0306D44F3FDF)
23:47:43.329: Vi24 PPP: Process pending packets
23:47:43.413: Vi24 IPCP: I CONFREQ [REQsent] id 1 len 10
23:47:43.413: Vi24 IPCP:    Address 0.0.0.0 (0x030600000000)
23:47:43.413: Vi24 AAA/AUTHOR/IPCP: Start.  Her address 0.0.0.0, we want 0.0.0.0
...



thx
Gerald


More information about the cisco-nas mailing list