[cisco-nas] AAA problem (C7204 and freeradius)
Thomas Koeppe
thomas at kgt.org
Wed Nov 14 06:40:02 EST 2007
Hi,
can anybody give me a hint what is going on here? Every 1-2 weeks all
ppp sessions (coming in via l2tp over fa1/0) going down. Interface fa1/0
goes down too. The only possibility to reach the c7204 is via console
port. After reloading the router all looks well for the next 1-2 weeks.
--- debug output ---
AAA/ID(00000148): Setting disconnect: abort = 41/TCP Foreign Host Close,
terminate = 8/port-error
AAA/ACCT/SETMLIST(00000148): Handle 0, mlist 6370F0C8, Name default
AAA/ACCT/EVENT/(00000148): NET DOWN
AAA/ACCT(00000148): within bundle 327
AAA/ACCT(00000148): within bundle 327
AAA/ACCT(00000148): bundle 0x00000147 removed link, now has 1 link
AAA/ID(00000148): remove hw:Vi2,0x645DF634 sw:Vi2,0x645E0880 other:nil
base:nil unit:2/0 slot:4294967295 shelf:0 tty:nil
AAA/ID(00000148): bytes tx/rx 2133883456/212073592, pkts tx/rx
2889476/1361134
AAA/ID(00000148): Enqueuing in aaa_stop_Q for CALL STOP
AAA/ID(00000148): action(CALL STOP) rcv(9731) xmit(8942) ip(413) op(419)
xmitrt(1280000) rcvrt(1280000)
AAA/ID(00000148): Call completed 06:32:03 GMT Nov 14 2007
Vi2 PPP: aaa-id := 0x0 reset
Vi2 PPP: mlp-aaa-id := 0x0 reset
AAA/ID(00000148): dealloc , no idb or tty
AAA/ID(00000148): Call completed 06:32:03 GMT Nov 14 2007
RADIUS/ENCODE(00000148): Unsupported AAA attribute start_time
RADIUS/ENCODE(00000148): Unsupported AAA attribute protocol
RADIUS/ENCODE(00000148): Unsupported AAA attribute start_time
RADIUS/ENCODE(00000148): Unsupported AAA attribute protocol
RADIUS(00000148): Using existing nas_port 307
RADIUS(00000148): Config NAS IP: $ip_primary_radius
RADIUS(00000148): sending
AAA/AAA_SEND_STOP_PROC: Queue Event
AAA/ID/STOP(00000148): action(CALL STOP) rcv(9731) xmit(8942) ip(413)
op(419) xmitrt(1280000) rcvrt(1280000)
AAA/ACCT/EVENT/(00000148): CALL STOP
AAA/ACCT(00000148): within bundle 327
AAA/ACCT(00000148): db not present within bundle 327
RADIUS(00000148): Send Accounting-Request to $ip_primary_radius:1813 id
1646/187, len 354
RADIUS: authenticator DA AD 87 49 2A 67 63 E2 - C5 1B FE 1C 66 C0 E5 77
RADIUS: Acct-Session-Id [44] 10 "00000229"
RADIUS: Tunnel-Type [64] 6 00:L2TP [3]
RADIUS: Tunnel-Medium-Type [65] 6 00:IPv4 [1]
RADIUS: Tunnel-Server-Endpoi[67] 14 "$ip_lns"
RADIUS: Tunnel-Client-Endpoi[66] 16 "$ip_lac"
RADIUS: Tunnel-Assignment-Id[82] 3 "1"
RADIUS: Tunnel-Client-Auth-I[90] 23 "xxxxx"
RADIUS: Tunnel-Server-Auth-I[91] 6 "lns1"
Acct-Tunnel-Connecti[68] 12 "3046186402"
RADIUS: Framed-Protocol [7] 6 PPP [1]
RADIUS: Acct-Authentic [45] 6 RADIUS [1]
RADIUS: Vendor, Cisco [26] 32
RADIUS: Cisco AVpair [1] 26 "connect-progress=Call Up"
RADIUS: Acct-Session-Time [46] 6 3493
RADIUS: Acct-Input-Octets [42] 6 9731
RADIUS: Acct-Output-Octets [43] 6 8869
RADIUS: Acct-Input-Packets [47] 6 413
RADIUS: Acct-Output-Packets [48] 6 416
RADIUS: Acct-Terminate-Cause[49] 6 port-error [8]
RADIUS: Vendor, Cisco [26] 45
RADIUS: Cisco AVpair [1] 39 "disc-cause-ext=TCP Foreign Host
Close"
RADIUS: Acct-Status-Type [40] 6 Stop [2]
RADIUS: User-Name [1] 23 "$username at realm.com"
RADIUS: Multilink-Session-ID[50] 10 "00000147"
RADIUS: Acct-Link-Count [51] 6 2
RADIUS: Framed-IP-Address [8] 6 $user_ip
RADIUS: NAS-Port-Type [61] 6 Virtual [5]
RADIUS: Vendor, Cisco [26] 23
RADIUS: cisco-nas-port [2] 17 "Uniq-Sess-ID307"
RADIUS: NAS-Port [5] 6 307
RADIUS: Connect-Info [77] 9 "1280000"
RADIUS: Service-Type [6] 6 Framed [2]
RADIUS: NAS-IP-Address [4] 6 $ip_lns
RADIUS: Acct-Delay-Time [41] 6 0
Vi2 PPP: aaa-id := 0x0 reset
Vi2 PPP: mlp-aaa-id := 0x0 reset
AAA/ID(00000143): Setting disconnect: abort = 41/TCP Foreign Host Close,
terminate = 8/port-error
AAA/ACCT/SETMLIST(00000143): Handle 0, mlist 6370F0C8, Name default
AAA/ACCT/EVENT/(00000143): NET DOWN
AAA/ACCT(00000143): within bundle 321
AAA/ACCT(00000143): within bundle 321
AAA/ACCT(00000143): bundle 0x00000141 removed link, now has 2 links
AAA/ID(00000143): remove hw:Vi26,0x646460D4 sw:Vi26,0x64647320 other:nil
base:nil unit:26/0 slot:4294967295 shelf:0 tty:nil
AAA/ID(00000143): bytes tx/rx 2053135061/273070081, pkts tx/rx
2325849/1381742
AAA/ID(00000143): Enqueuing in aaa_stop_Q for CALL STOP
AAA/ID(00000143): action(CALL STOP) rcv(139940) xmit(4586317) ip(2787)
op(8037) xmitrt(864000) rcvrt(160000)
AAA/ID(00000143): Call completed 06:32:03 GMT Nov 14 2007
Vi26 PPP: aaa-id := 0x0 reset
Vi26 PPP: mlp-aaa-id := 0x0 reset
AAA/ID(00000143): dealloc , no idb or tty
AAA/ID(00000143): Call completed 06:32:03 GMT Nov 14 2007
RADIUS/ENCODE(00000143): Unsupported AAA attribute start_time
RADIUS/ENCODE(00000143): Unsupported AAA attribute protocol
RADIUS/ENCODE(00000143): Unsupported AAA attribute start_time
RADIUS/ENCODE(00000143): Unsupported AAA attribute protocol
RADIUS(00000143): Using existing nas_port 302
RADIUS(00000143): Config NAS IP: $ip_lns
RADIUS(00000143): sending
AAA/AAA_SEND_STOP_PROC: Queue Event
AAA/ID/STOP(00000143): action(CALL STOP) rcv(139940) xmit(4586317)
ip(2787) op(8037) xmitrt(864000) rcvrt(160000)
AAA/ACCT/EVENT/(00000143): CALL STOP
AAA/ACCT(00000143): within bundle 321
AAA/ACCT(00000140): multisession identifers mismatch 00000142:00000141
AAA/ACCT(00000143): db not present within bundle 321
RADIUS(00000143): Send Accounting-Request to $ip_primary_radius:1813 id
1646/188, len 364
RADIUS: authenticator 65 4B 69 E9 05 52 DE A7 - CD D3 04 59 2A 1C 00 5C
RADIUS: Acct-Session-Id [44] 10 "00000220"
RADIUS: Tunnel-Type [64] 6 00:L2TP [3]
RADIUS: Tunnel-Medium-Type [65] 6 00:IPv4 [1]
RADIUS: Tunnel-Server-Endpoi[67] 14 "$ip_lns"
RADIUS: Tunnel-Client-Endpoi[66] 16 "$ip_lac"
RADIUS: Tunnel-Assignment-Id[82] 3 "1"
RADIUS: Tunnel-Client-Auth-I[90] 23 "xxxxx"
RADIUS: Tunnel-Server-Auth-I[91] 6 "lns1"
RADIUS: Acct-Tunnel-Connecti[68] 12 "3046186364"
RADIUS: Framed-Protocol [7] 6 PPP [1]
RADIUS: Acct-Authentic [45] 6 RADIUS [1]
RADIUS: Vendor, Cisco [26] 32
RADIUS: Cisco AVpair [1] 26 "connect-progress=Call Up"
RADIUS: Acct-Session-Time [46] 6 8777
RADIUS: Acct-Input-Octets [42] 6 139940
RADIUS: Acct-Output-Octets [43] 6 4586244
RADIUS: Acct-Input-Packets [47] 6 2787
RADIUS: Acct-Output-Packets [48] 6 8034
RADIUS: Acct-Terminate-Cause[49] 6 port-error [8]
RADIUS: Vendor, Cisco [26] 45
RADIUS: Cisco AVpair [1] 39 "disc-cause-ext=TCP Foreign Host
Close"
RADIUS: Acct-Status-Type [40] 6 Stop [2]
RADIUS: User-Name [1] 27 "$username2 at realm.com"
RADIUS: Multilink-Session-ID[50] 10 "00000141"
RADIUS: Acct-Link-Count [51] 6 3
RADIUS: Framed-IP-Address [8] 6 $user_ip
RADIUS: NAS-Port-Type [61] 6 Virtual [5]
RADIUS: Vendor, Cisco [26] 23
RADIUS: cisco-nas-port [2] 17 "Uniq-Sess-ID302"
RADIUS: NAS-Port [5] 6 302
RADIUS: Connect-Info [77] 15 "864000/160000"
RADIUS: Service-Type [6] 6 Framed [2]
RADIUS: NAS-IP-Address [4] 6 $ip_lns
RADIUS: Acct-Delay-Time [41] 6
Vi26 PPP: aaa-id := 0x0 reset
Vi26 PPP: mlp-aaa-id := 0x0 reset
AAA/ID(00000137): Setting disconnect: abort = 41/TCP Foreign Host Close,
terminate = 8/port-error
AAA/ACCT/SETMLIST(00000137): Handle 0, mlist 6370F0C8, Name default
AAA/ACCT/EVENT/(00000137): NET DOWN
AAA/ACCT(00000137): within bundle 309
AAA/ACCT(00000137): within bundle 309
AAA/ACCT(00000137): bundle 0x00000135 removed link, now has 2 links
AAA/ID(00000137): remove hw:Vi18,0x64617F38 sw:Vi18,0x64619184 other:nil
base:nil unit:18/0 slot:4294967295 shelf:0 tty:nil
AAA/ID(00000137): bytes tx/rx 248491679/52918718, pkts tx/rx 476865/262874
AAA/ID(00000137): Enqueuing in aaa_stop_Q for CALL STOP
AAA/ID(00000137): action(CALL STOP) rcv(144492) xmit(213605) ip(1668)
op(1611) xmitrt(1184000) rcvrt(160000)
AAA/ID(00000137): Call completed 06:32:04 GMT Nov 14 2007
Vi18 PPP: aaa-id := 0x0 reset
Vi18 PPP: mlp-aaa-id := 0x0 reset
AAA/ID(00000137): dealloc , no idb or tty
AAA/ID(00000137): Call completed 06:32:04 GMT Nov 14 2007
RADIUS/ENCODE(00000137): Unsupported AAA attribute start_time
RADIUS/ENCODE(00000137): Unsupported AAA attribute protocol
RADIUS/ENCODE(00000137): Unsupported AAA attribute start_time
RADIUS/ENCODE(00000137): Unsupported AAA attribute protocol
RADIUS(00000137): Using existing nas_port 290
RADIUS(00000137): Config NAS IP: $ip_lns
RADIUS(00000137): sending
AAA/AAA_SEND_STOP_PROC: Queue Event
AAA/ID/STOP(00000137): action(CALL STOP) rcv(144492) xmit(213605)
ip(1668) op(1611) xmitrt(1184000) rcvrt(160000)
AAA/ACCT/EVENT/(00000137): CALL STOP
AAA/ACCT(00000137): within bundle 309
AAA/ACCT(00000134): multisession identifers mismatch 00000136:00000135
AAA/ACCT(00000137): db not present within bundle 309
RADIUS(00000137): Send Accounting-Request to $ip_primary_radius:1813 id
1646/189, len 363
...
...
...
RADIUS: Retransmit to ($ip_primary_radius:1812,1813) for id 1646/193
RADIUS: acct-delay-time for E384834 (at E38499C) now 5
RADIUS: Retransmit to ($ip_primary_radius:1812,1813) for id 1646/194
RADIUS: acct-delay-time for E382534 (at E38268D) now 5
RADIUS: Retransmit to ($ip_primary_radius:1812,1813) for id 1646/195
RADIUS: acct-delay-time for E384E74 (at E384FDD) now 5
RADIUS: Retransmit to ($ip_primary_radius:1812,1813) for id 1646/199
RADIUS: acct-delay-time for E38BBD4 (at E38BD39) now 5
RADIUS: Retransmit to ($ip_primary_radius:1812,1813) for id 1646/196
RADIUS: acct-delay-time for E388074 (at E3881DA) now 5
...
...
...
RADIUS: Fail-over to ($ip_secondary_radius:1812,1813) for id 1646/234
RADIUS: acct-delay-time for E35BE34 (at E35BF90) now 20
RADIUS: authenticator EF E7 7C E9 93 05 CB 54 - 9C 63 60 1E 8B DC 8F 9F
RADIUS: Acct-Session-Id [44] 10 "00000229"
RADIUS: Tunnel-Type [64] 6 00:L2TP [3]
RADIUS: Tunnel-Medium-Type [65] 6 00:IPv4
...
...
...
RADIUS: No response from ($ip_secondary_radius:1812,1813) for id 1646/55
RADIUS/DECODE: parse response no app start; FAIL
RADIUS/DECODE: parse response; FAIL
AAA/AAA_SEND_STOP_PROC: Message Event
AAA/AAA_SEND_STOP_PROC(00000143): Initiated message callback
AAA/AAA_SEND_STOP_PROC: Empty message queue
RADIUS: Retransmit to ($ip_secondary_radius:1812,1813) for id 1646/54
RADIUS: acct-delay-time for E38BBD4 (at E38BD39) now 35
RADIUS: No response from ($ip_secondary_radius:1812,1813) for id 1646/56
RADIUS/DECODE: parse response no app start; FAIL
RADIUS/DECODE: parse response; FAIL
AAA/AAA_SEND_STOP_PROC: Message Event
AAA/AAA_SEND_STOP_PROC(00000148): Initiated message callback
AAA/AAA_SEND_STOP_PROC: Empty message queue
--- end debug ---
--- sh ver ---
Cisco Internetwork Operating System Software
IOS (tm) 7200 Software (C7200-JS-M), Version 12.3(5a)B5, RELEASE
SOFTWARE (fc1)
Technical Support: http://www.cisco.com/techsupport
Copyright (c) 1986-2005 by cisco Systems, Inc.
Compiled Wed 11-May-05 14:06 by leccese
Image text-base: 0x60008AF4, data-base: 0x61FF0000
ROM: System Bootstrap, Version 12.2(4r)B2, RELEASE SOFTWARE (fc2)
BOOTLDR: 7200 Software (C7200-KBOOT-M), Version 12.3(6f), RELEASE
SOFTWARE (fc1)
lns1 uptime is 5 hours, 30 minutes
System returned to ROM by reload at 06:34:24 GMT Wed Nov 14 2007
System restarted at 06:35:43 GMT Wed Nov 14 2007
System image file is "disk0:c7200-js-mz.123-5a.B5.bin"
Last reload reason: Reload command
cisco 7204VXR (NPE400) processor (revision A) with 491520K/32768K bytes
of memory.
Processor board ID 32560070
R7000 CPU at 350MHz, Implementation 39, Rev 3.3, 256KB L2, 4096KB L3 Cache
4 slot VXR midplane, Version 2.9
Last reset from power-on
Bridging software.
X.25 software, Version 3.0.0.
SuperLAT software (copyright 1990 by Meridian Technology Corp).
TN3270 Emulation software.
PCI bus mb0_mb1 has 600 bandwidth points
PCI bus mb2 has 0 bandwidth points
1 Ethernet/IEEE 802.3 interface(s)
1 FastEthernet/IEEE 802.3 interface(s)
1 Gigabit Ethernet/IEEE 802.3 interface(s)
125K bytes of non-volatile configuration memory.
62720K bytes of ATA PCMCIA card at slot 0 (Sector size 512 bytes).
8192K bytes of Flash internal SIMM (Sector size 256K).
Configuration register is 0x2102
--- end sh ver ---
--- radius.log ---
Error: rlm_radutmp: Logout for NAS lns1 port 307, but no Login record
Error: rlm_radutmp: Logout for NAS lns1 port 302, but no Login record
Error: rlm_radutmp: Logout for NAS lns1 port 299, but no Login record
...
... (always the same message with different port number)
...
--- end radius.log ---
--- sh run (only relevant) ---
aaa authentication login default local
aaa authentication login oob none
aaa authentication enable default enable
aaa authentication ppp default local group radius
aaa authorization network default local group radius none
aaa accounting network default start-stop group radius
aaa session-id common
radius-server dead-criteria tries 2
radius-server host $ip_primary_radius auth-port 1812 acct-port 1813
radius-server host $ip_secondary_radius auth-port 1812 acct-port 1813
radius-server vsa send accounting
radius-server key xxxxxxxx
--- end radius.log ---
Both machines , primary and secondary radius, are up and running without
problems at all times. On this router we terminate both single
ppp-sessions and some multilink-ppp sessions from our DSL-customer. I
found (google) only one possible bug machtes my problem: CSCee42617 ?!?!?!
May be an interface (hardware) problem ? (i cant't believe it) Should I
remove the FastEthernet Card and connect to ge0/0 on the I/O-Controller
? Or perhaps change to another (possible stable) ios image ?
Thomas
More information about the cisco-nas
mailing list