[cisco-bba] Multiple Radius Accounting
Dennis Peng
dpeng at cisco.com
Wed Sep 17 19:11:13 EDT 2003
The first 4 RADIUS packets are quite normal:
1. Access-Request for user's domain name (occurs if VPDN is configured
and "vpdn authen-before-forward" is not configured)
2. Access-Reject indicating domain does not exist in RADIUS server
3. Access-Request for user's full name
4. Access-Accept indicating user passed authentication
At that point you see 4 straight Accounting-Requests from the router
with incrementing id's. There is not Accounting-Response. The same
holds true later when the session goes down.
So it doesn't seem like the Accounting-Response from the RADIUS server
is making it back to the router.
Dennis
Tay Chee Yong [tcy at pacific.net.sg] wrote:
> Hi Dennis,
>
> >From the tcpdump output, it seems that the router (10.10.10.2) is receiving
> the acknowledgement after the second attempt. The first one, seems to only
> send out the domain without the userid.
>
> Accounting Start
>
> 14:36:19.403440 10.10.10.2.21646 > 30.30.30.114.datametrics:
> rad-access-req 97 [id 102] Attr[ User{pacific.net.sg} Pass ] (ttl 253, id
> 11125, len 125)
> 14:36:19.413440 30.30.30.114.datametrics > 10.10.10.2.21646:
> rad-access-reject 77 [id 102] Attr[ Reply{adsl} [|radius] (DF) (ttl 64, id
> 0, len 105)
> 14:36:19.433441 10.10.10.2.21646 > 30.30.30.114.datametrics:
> rad-access-req 110 [id 103] Attr[ Framed_proto{#257}
> User{adsl at pacific.net.sg} [|radius] (ttl 253, id 11126, len 138)
> 14:36:19.443441 30.30.30.114.datametrics > 10.10.10.2.21646:
> rad-access-accept 219 [id 103] Attr[ Service_type{#519} Framed_proto{#282}
> [|radius] (DF) (ttl 64, id 0, len 247)
> 14:36:19.473442 10.10.10.2.21646 > 30.30.30.114.sa-msg-port:
> rad-account-req 193 [id 104] Attr[ Acct_session_id{00000370} [|radius]
> (ttl 253, id 11127, len 221)
> 14:36:24.473600 10.10.10.2.21646 > 30.30.30.114.sa-msg-port:
> rad-account-req 193 [id 105] Attr[ Acct_session_id{00000370} [|radius]
> (ttl 253, id 11156, len 221)
> 14:36:29.473757 10.10.10.2.21646 > 30.30.30.114.sa-msg-port:
> rad-account-req 193 [id 106] Attr[ Acct_session_id{00000370} [|radius]
> (ttl 253, id 11170, len 221)
> 14:36:34.473915 10.10.10.2.21646 > 30.30.30.114.sa-msg-port:
> rad-account-req 193 [id 107] Attr[ Acct_session_id{00000370} [|radius]
> (ttl 253, id 11179, len 221)
>
>
> The following is displayed when i attempt to close the session.
>
> 14:37:07.864968 10.10.10.2.21646 > 30.30.30.114.sa-msg-port:
> rad-account-req 277 [id 108] Attr[ Acct_session_id{00000370} [|radius]
> (ttl 253, id 11277, len 305)
> 14:37:12.865126 10.10.10.2.21646 > 30.30.30.114.sa-msg-port:
> rad-account-req 277 [id 109] Attr[ Acct_session_id{00000370} [|radius]
> (ttl 253, id 11302, len 305)
> 14:37:17.865284 10.10.10.2.21646 > 30.30.30.114.sa-msg-port:
> rad-account-req 277 [id 110] Attr[ Acct_session_id{00000370} [|radius]
> (ttl 253, id 11313, len 305)
> 14:37:22.865441 10.10.10.2.21646 > 30.30.30.114.sa-msg-port:
> rad-account-req 277 [id 111] Attr[ Acct_session_id{00000370} [|radius]
> (ttl 253, id 11323, len 305)
>
>
> Following is the debugging of radius and aaa accounting.
>
> Sep 17 14:36:19: AAA/ACCT/CLIENT(0000003C): recv 153354240bps xmit
> 153354240bps
> Sep 17 14:36:19: AAA/ACCT/HC(0000003C): Register PPoE/638019F8 153Mbit/s,
> poll every 30.3000s
> Sep 17 14:36:19: AAA/ACCT/HC(0000003C): Update PPoE/638019F8
> Sep 17 14:36:19: AAA/ACCT/HC(0000003C): PPoE/638019F8 [init-sess] (rx/tx)
> base 0/0 pre 0/0 call 0/0
> Sep 17 14:36:19: AAA/ACCT/HC(0000003C): PPoE/638019F8 [init-sess] (rx/tx)
> adjusted, pre 0/0 call 0/0
> Sep 17 14:36:19: AAA/ACCT/EVENT/(0000003C): CALL START
> Sep 17 14:36:19: Getting session id for NET(0000003C) : db=64591AF4
> Sep 17 14:36:19: AAA/ACCT(00000000): add node, session 880
> Sep 17 14:36:19: AAA/ACCT/NET(0000003C): add, count 1
> Sep 17 14:36:19: AAA/ACCT/NET(0000003C): Pick method list 'default'
> Sep 17 14:36:19: AAA/ACCT/SETMLIST(0000003C): Handle 0, mlist 63CDD44C,
> Name default
> Sep 17 14:36:19: AAA/ACCT/EVENT/(0000003C): ATTR REPLACE
> Sep 17 14:36:19: RADIUS(0000003C): Storing nasport 0 in rad_db
> Sep 17 14:36:19: RADIUS(0000003C): Config NAS IP: 10.10.10.2
> Sep 17 14:36:19: Getting session id for NET(0000003C) : db=64591AF4
> Sep 17 14:36:19: RADIUS/DECODE: Reply-Message fragments, 4, total 4 bytes
> Sep 17 14:36:19: RADIUS(0000003C): Using existing nas_port 0
> Sep 17 14:36:19: RADIUS(0000003C): Config NAS IP: 10.10.10.2
> Sep 17 14:36:19: Getting session id for NET(0000003C) : db=64591AF4
> Sep 17 14:36:19: %LINK-3-UPDOWN: Interface Virtual-Access4, changed state
> to up
> Sep 17 14:36:19: AAA/ACCT/NET(0000003C): Pick method list 'default'
> Sep 17 14:36:19: AAA/ACCT/SETMLIST(0000003C): Handle 0, mlist 63CDD44C,
> Name default
> Sep 17 14:36:19: AAA/ACCT/EVENT/(0000003C): NET UP
> Sep 17 14:36:19: AAA/ACCT/CLIENT(0000003C): recv 153354240bps xmit
> 153354240bps
> Sep 17 14:36:19: AAA/ACCT/HC(0000003C): Update PPoE/638019F8
> Sep 17 14:36:19: AAA/ACCT/HC(0000003C): PPoE/638019F8 [pre-sess] (rx/tx)
> base 0/0 pre 166/72 call 166/72
> Sep 17 14:36:19: AAA/ACCT/HC(0000003C): PPoE/638019F8 [pre-sess] (rx/tx)
> adjusted, pre 166/72 call 0/0
> Sep 17 14:36:19: AAA/ACCT/NET(0000003C): Queueing record is START
> Sep 17 14:36:19: AAA/ACCT(0000003C): Accouting method=radius (radius)
> Sep 17 14:36:19: RADIUS(0000003C): Using existing nas_port 0
> Sep 17 14:36:19: RADIUS(0000003C): Config NAS IP: 10.10.10.2
> Sep 17 14:36:19: RADIUS(0000003C): sending
> Sep 17 14:36:19: RADIUS(0000003C): Send Accounting-Request to
> 30.30.30.114:1646 id 21646/104, len 193
> Sep 17 14:36:19: RADIUS: authenticator EB FE D4 54 EB 35 AE 67 - DB C3 B3
> F6 F3 2B 22 24
> Sep 17 14:36:19: RADIUS: Acct-Session-Id [44] 10 "00000370"
> Sep 17 14:36:19: RADIUS: Vendor, Cisco [26] 41
> Sep 17 14:36:19: RADIUS: Cisco AVpair [1] 35
> "client-mac-address=00d0.597f.ad73"
> Sep 17 14:36:19: RADIUS: Framed-Protocol [7] 6 PPP
> [1]
> Sep 17 14:36:19: RADIUS: Vendor, Cisco [26] 32
> Sep 17 14:36:19: RADIUS: Cisco AVpair [1] 26
> "connect-progress=Call Up"
> Sep 17 14:36:19: RADIUS: Acct-Authentic [45] 6 RADIUS
> [1]
> Sep 17 14:36:19: RADIUS: User-Name [1] 23
> "piadsl at pacific.net.sg"
> Sep 17 14:36:19: RADIUS: Acct-Status-Type [40] 6 Start
> [1]
> Sep 17 14:36:19: RADIUS: NAS-Port-Type [61] 6 Virtual
> [5]
> Sep 17 14:36:19: RADIUS: Vendor, Cisco [26] 19
> Sep 17 14:36:19: RADIUS: cisco-nas-port [2] 13 "4/0/0/1.105"
> Sep 17 14:36:19: RADIUS: NAS-Port [5] 6 0
>
> Sep 17 14:36:19: RADIUS: Service-Type [6] 6 Framed
> [2]
> Sep 17 14:36:19: RADIUS: NAS-IP-Address [4] 6 10.10.10.2
>
> Sep 17 14:36:19: RADIUS: Acct-Delay-Time [41] 6 0
>
> Sep 17 14:36:19: AAA/ACCT/EVENT/(0000003C): IPCP_PASS
> Sep 17 14:36:20: %LINEPROTO-5-UPDOWN: Line protocol on Interface
> Virtual-Access4, changed state to up
> Sep 17 14:36:24: RADIUS: Retransmit to (30.30.30.114:1645,1646) for id
> 21646/104
> Sep 17 14:36:24: RADIUS: acct-delay-time for 514D014 (at 514D0CF) now 5
> Sep 17 14:36:29: RADIUS: Retransmit to (30.30.30.114:1645,1646) for id
> 21646/105
> Sep 17 14:36:29: RADIUS: acct-delay-time for 514D014 (at 514D0CF) now 10
> Sep 17 14:36:34: RADIUS: Retransmit to (30.30.30.114:1645,1646) for id
> 21646/106
> Sep 17 14:36:34: RADIUS: acct-delay-time for 514D014 (at 514D0CF) now 15
> Sep 17 14:36:39: RADIUS: No response from (30.30.30.114:1645,1646) for id
> 21646/107
> Sep 17 14:36:39: RADIUS/DECODE: parse response no app start; FAIL
> Sep 17 14:36:39: RADIUS/DECODE: parse response; FAIL
> Sep 17 14:36:39: AAA/ACCT/NET(0000003C): START protocol reply FAIL
> Sep 17 14:36:39: AAA/ACCT(0000003C): Accouting method=NOT_SET
>
>
>
>
> Sep 17 14:37:07: AAA/ACCT/NET(0000003C): Pick method list 'default'
> Sep 17 14:37:07: AAA/ACCT/SETMLIST(0000003C): Handle 0, mlist 63CDD44C,
> Name default
> Sep 17 14:37:07: AAA/ACCT/EVENT/(0000003C): NET DOWN
> Sep 17 14:37:07: AAA/ACCT/CLIENT(0000003C): recv 153354240bps xmit
> 153354240bps
> Sep 17 14:37:07: AAA/ACCT/HC(0000003C): Update PPoE/638019F8
> Sep 17 14:37:07: AAA/ACCT/HC(0000003C): PPoE/638019F8 [sess] (rx/tx) base
> 0/0 pre 166/72 call 4812/11339
> Sep 17 14:37:07: AAA/ACCT/HC(0000003C): PPoE/638019F8 [sess] (rx/tx)
> adjusted, pre 166/72 call 4646/11267
> Sep 17 14:37:07: AAA/ACCT/NET(0000003C): Queueing record is STOP osr 1
> Sep 17 14:37:07: AAA/ACCT(0000003C): del node, session 880
> Sep 17 14:37:07: AAA/ACCT/NET(0000003C): free_rec, count 0
> Sep 17 14:37:07: AAA/ACCT/NET(0000003C): Setting session id 890 :
> db=64591AF4
> Sep 17 14:37:07: AAA/ACCT(0000003C): Accouting method=radius (radius)
> Sep 17 14:37:07: RADIUS(0000003C): Using existing nas_port 0
> Sep 17 14:37:07: RADIUS(0000003C): Config NAS IP: 10.10.10.2
> Sep 17 14:37:07: RADIUS(0000003C): sending
> Sep 17 14:37:07: AAA/ACCT/EVENT/(0000003C): NET DOWN
> Sep 17 14:37:07: AAA/ACCT(0000003C): Duplicate action NET DOWN
> Sep 17 14:37:07: AAA/ACCT/CLIENT(0000003C): recv 153354240bps xmit
> 153354240bps
> Sep 17 14:37:07: AAA/ACCT/HC(0000003C): Update PPoE/638019F8
> Sep 17 14:37:07: AAA/ACCT/HC(0000003C): PPoE/638019F8 [sess] (rx/tx) base
> 0/0 pre 166/72 call 4812/11339
> Sep 17 14:37:07: AAA/ACCT/HC(0000003C): PPoE/638019F8 [sess] (rx/tx)
> adjusted, pre 166/72 call 4646/11267
> Sep 17 14:37:07: AAA/ACCT/HC(0000003C): Deregister PPoE/638019F8
> Sep 17 14:37:07: RADIUS(0000003C): Send Accounting-Request to
> 30.30.30.114:1646 id 21646/108, len 277
> Sep 17 14:37:07: RADIUS: authenticator 74 25 E9 45 06 06 94 8A - E5 A6 40
> 23 D7 CB A3 4B
> Sep 17 14:37:07: RADIUS: Acct-Session-Id [44] 10 "00000370"
> Sep 17 14:37:07: RADIUS: Vendor, Cisco [26] 41
> Sep 17 14:37:07: RADIUS: Cisco AVpair [1] 35
> "client-mac-address=00d0.597f.ad73"
> Sep 17 14:37:07: RADIUS: Framed-Protocol [7] 6 PPP
> [1]
> Sep 17 14:37:07: RADIUS: Framed-IP-Address [8] 6 20.20.113.84
>
> Sep 17 14:37:07: RADIUS: Acct-Authentic [45] 6 RADIUS
> [1]
> Sep 17 14:37:07: RADIUS: Vendor, Cisco [26] 35
> Sep 17 14:37:07: RADIUS: Cisco AVpair [1] 29
> "connect-progress=LAN Ses Up"
> Sep 17 14:37:07: RADIUS: Acct-Session-Time [46] 6 48
>
> Sep 17 14:37:07: RADIUS: Acct-Input-Octets [42] 6 4646
>
> Sep 17 14:37:07: RADIUS: Acct-Output-Octets [43] 6 11267
>
> Sep 17 14:37:07: RADIUS: Acct-Input-Packets [47] 6 50
>
> Sep 17 14:37:07: RADIUS: Acct-Output-Packets [48] 6 24
>
> Sep 17 14:37:07: RADIUS: Acct-Terminate-Cause[49] 6 user-request
> [1]
> Sep 17 14:37:07: RADIUS: Vendor, Cisco [26] 39
> Sep 17 14:37:07: RADIUS: Cisco AVpair [1] 33 "disc-cause-ext=PPP
> Receive Term"
> Sep 17 14:37:07: RADIUS: User-Name [1] 23
> "piadsl at pacific.net.sg"
> Sep 17 14:37:07: RADIUS: Acct-Status-Type [40] 6 Stop
> [2]
> Sep 17 14:37:07: RADIUS: NAS-Port-Type [61] 6 Virtual
> [5]
> Sep 17 14:37:07: RADIUS: Vendor, Cisco [26] 19
> Sep 17 14:37:07: RADIUS: cisco-nas-port [2] 13 "4/0/0/1.105"
> Sep 17 14:37:07: RADIUS: NAS-Port [5] 6 0
>
> Sep 17 14:37:07: RADIUS: Service-Type [6] 6 Framed
> [2]
> Sep 17 14:37:07: RADIUS: NAS-IP-Address [4] 6 10.10.10.2
>
> Sep 17 14:37:07: RADIUS: Acct-Delay-Time [41] 6 0
>
> Sep 17 14:37:07: AAA/ACCT/EVENT/(0000003C): CALL STOP
> Sep 17 14:37:07: AAA/ACCT(0000003C) reccnt 0, osr 1
> Sep 17 14:37:07: %LINK-3-UPDOWN: Interface Virtual-Access4, changed state
> to down
> Sep 17 14:37:08: %LINEPROTO-5-UPDOWN: Line protocol on Interface
> Virtual-Access4, changed state to down
> Sep 17 14:37:12: RADIUS: Retransmit to (30.30.30.114:1645,1646) for id
> 21646/108
> Sep 17 14:37:12: RADIUS: acct-delay-time for 5003D74 (at 5003E83) now 5
> Sep 17 14:37:17: RADIUS: Retransmit to (30.30.30.114:1645,1646) for id
> 21646/109
> Sep 17 14:37:17: RADIUS: acct-delay-time for 5003D74 (at 5003E83) now 10
> Sep 17 14:37:22: RADIUS: Retransmit to (30.30.30.114:1645,1646) for id
> 21646/110
> Sep 17 14:37:22: RADIUS: acct-delay-time for 5003D74 (at 5003E83) now 15
> Sep 17 14:37:27: RADIUS: No response from (30.30.30.114:1645,1646) for id
> 21646/111
> Sep 17 14:37:27: RADIUS/DECODE: parse response no app start; FAIL
> Sep 17 14:37:27: RADIUS/DECODE: parse response; FAIL
> Sep 17 14:37:27: AAA/ACCT/NET(0000003C): STOP protocol reply FAIL
> Sep 17 14:37:27: AAA/ACCT(0000003C): Accouting method=NOT_SET
> Sep 17 14:37:27: AAA/ACCT/NET(0000003C): Tried all the methods, osr 0
> Sep 17 14:37:27: AAA/ACCT/NET(0000003C) Record not present
> Sep 17 14:37:27: AAA/ACCT/NET(0000003C) reccnt 0, csr TRUE, osr 0
> Sep 17 14:37:27: AAA/ACCT/NET(0000003C): Last rec in db, intf not enqueued
>
>
> Thanks very much.
>
> Regards,
> Cheeyong
>
> On Tue, 16 Sep 2003, Dennis Peng wrote:
>
> : Please turn on "Debug radius accounting" to see if the router is
> : receiving the acknowledgements.
> :
> : Dennis
> :
> : Tay Chee Yong [tcy at pacific.net.sg] wrote:
> : > Hi all,
> : >
> : > I am using a Cisco 7206 router as BB aggregator. I seems to be getting
> : > multiple accounting start/stop packets on the radius server.
> : >
> : > I noticed from the tcpdump output that despite acknowledgement from the
> : > radius server, the 7206 is still sending the start packet to the radius
> : > server. (Observe the time of the debug and tcpdump output)
> : >
> : > A "debug aaa accounting" shows the following in the Cisco 7206:
> : >
> : > Start Accounting:
> : >
> : > Sep 15 19:08:08: AAA/ACCT/CLIENT(0000000B): recv 153354240bps xmit
> : > 153354240bps
> : > Sep 15 19:08:08: AAA/ACCT/HC(0000000B): Register PPoE/63801ACC 153Mbit/s,
> : > poll every 30.3000s
> : > Sep 15 19:08:08: AAA/ACCT/HC(0000000B): Update PPoE/63801ACC
> : > Sep 15 19:08:08: AAA/ACCT/HC(0000000B): PPoE/63801ACC [init-sess] (rx/tx)
> : > base 0/0 pre 0/0 call 0/0
> : > Sep 15 19:08:08: AAA/ACCT/HC(0000000B): PPoE/63801ACC [init-sess] (rx/tx)
> : > adjusted, pre 0/0 call 0/0
> : > Sep 15 19:08:08: AAA/ACCT/EVENT/(0000000B): CALL START
> : > Sep 15 19:08:08: Getting session id for NET(0000000B) : db=64589038
> : > Sep 15 19:08:08: AAA/ACCT(00000000): add node, session 155
> : > Sep 15 19:08:08: AAA/ACCT/NET(0000000B): add, count 1
> : > Sep 15 19:08:08: AAA/ACCT/NET(0000000B): Pick method list 'default'
> : > Sep 15 19:08:08: AAA/ACCT/SETMLIST(0000000B): Handle 0, mlist 63CDD44C,
> : > Name default
> : > Sep 15 19:08:08: AAA/ACCT/EVENT/(0000000B): ATTR REPLACE
> : > Sep 15 19:08:18: Getting session id for NET(0000000B) : db=64589038
> : > Sep 15 19:08:18: AAA/ACCT/NET(0000000B): Pick method list 'default'
> : > Sep 15 19:08:18: AAA/ACCT/SETMLIST(0000000B): Handle 0, mlist 63CDD44C,
> : > Name default
> : > Sep 15 19:08:18: AAA/ACCT/EVENT/(0000000B): NET UP
> : > Sep 15 19:08:18: AAA/ACCT/CLIENT(0000000B): recv 153354240bps xmit
> : > 153354240bps
> : > Sep 15 19:08:18: AAA/ACCT/HC(0000000B): Update PPoE/63801ACC
> : > Sep 15 19:08:18: AAA/ACCT/HC(0000000B): PPoE/63801ACC [pre-sess] (rx/tx)
> : > base 0/0 pre 101/95 call 101/95
> : > Sep 15 19:08:18: AAA/ACCT/HC(0000000B): PPoE/63801ACC [pre-sess] (rx/tx)
> : > adjusted, pre 101/95 call 0/0
> : > Sep 15 19:08:18: AAA/ACCT/NET(0000000B): Queueing record is START
> : > Sep 15 19:08:18: AAA/ACCT(0000000B): Accouting method=radius (radius)
> : > Sep 15 19:08:19: AAA/ACCT/EVENT/(0000000B): IPCP_PASS
> : > Sep 15 19:08:38: AAA/ACCT/NET(0000000B): START protocol reply FAIL
> : > Sep 15 19:08:38: AAA/ACCT(0000000B): Accouting method=NOT_SET
> : >
> : > Stop accounting
> : >
> : > Sep 15 19:09:03: AAA/ACCT/NET(0000000B): Pick method list 'default'
> : > Sep 15 19:09:03: AAA/ACCT/SETMLIST(0000000B): Handle 0, mlist 63CDD44C,
> : > Name default
> : > Sep 15 19:09:03: AAA/ACCT/EVENT/(0000000B): NET DOWN
> : > Sep 15 19:09:03: AAA/ACCT/CLIENT(0000000B): recv 153354240bps xmit
> : > 153354240bps
> : > Sep 15 19:09:03: AAA/ACCT/HC(0000000B): Update PPoE/63801ACC
> : > Sep 15 19:09:03: AAA/ACCT/HC(0000000B): PPoE/63801ACC [sess] (rx/tx) base
> : > 0/0 pre 101/95 call 2891/1811
> : > Sep 15 19:09:03: AAA/ACCT/HC(0000000B): PPoE/63801ACC [sess] (rx/tx)
> : > adjusted, pre 101/95 call 2790/1716
> : > Sep 15 19:09:03: AAA/ACCT/NET(0000000B): Queueing record is STOP osr 1
> : > Sep 15 19:09:03: AAA/ACCT(0000000B): del node, session 155
> : > Sep 15 19:09:03: AAA/ACCT/NET(0000000B): free_rec, count 0
> : > Sep 15 19:09:03: AAA/ACCT/NET(0000000B): Setting session id 165 :
> : > db=64589038
> : > Sep 15 19:09:03: AAA/ACCT(0000000B): Accouting method=radius (radius)
> : > Sep 15 19:09:03: AAA/ACCT/EVENT/(0000000B): NET DOWN
> : > Sep 15 19:09:03: AAA/ACCT(0000000B): Duplicate action NET DOWN
> : > Sep 15 19:09:03: AAA/ACCT/CLIENT(0000000B): recv 153354240bps xmit
> : > 153354240bps
> : > Sep 15 19:09:03: AAA/ACCT/HC(0000000B): Update PPoE/63801ACC
> : > Sep 15 19:09:03: AAA/ACCT/HC(0000000B): PPoE/63801ACC [sess] (rx/tx) base
> : > 0/0 pre 101/95 call 2891/1811
> : > Sep 15 19:09:03: AAA/ACCT/HC(0000000B): PPoE/63801ACC [sess] (rx/tx)
> : > adjusted, pre 101/95 call 2790/1716
> : > Sep 15 19:09:03: AAA/ACCT/HC(0000000B): Deregister PPoE/63801ACC
> : > Sep 15 19:09:03: AAA/ACCT/EVENT/(0000000B): CALL STOP
> : > Sep 15 19:09:03: AAA/ACCT(0000000B) reccnt 0, osr 1
> : > Sep 15 19:09:23: AAA/ACCT/NET(0000000B): STOP protocol reply FAIL
> : > Sep 15 19:09:23: AAA/ACCT(0000000B): Accouting method=NOT_SET
> : > Sep 15 19:09:23: AAA/ACCT/NET(0000000B): Tried all the methods, osr 0
> : > Sep 15 19:09:23: AAA/ACCT/NET(0000000B) Record not present
> : > Sep 15 19:09:23: AAA/ACCT/NET(0000000B) reccnt 0, csr TRUE, osr 0
> : > Sep 15 19:09:23: AAA/ACCT/NET(0000000B): Last rec in db, intf not enqueued
> : >
> : >
> : > A tcpdump from my radius server:
> : >
> : > 19:08:18.945248 10.10.10.2.21645 > 20.20.20.114.datametrics:
> : > rad-access-req 91 [id 49] Attr[ Framed_proto{#257} User{test at domain.net}
> : > [|radius] (ttl 253, id 6670, len 119)
> : > 19:08:18.955248 20.20.20.114.datametrics > 10.10.10.2.21645:
> : > rad-access-accept 55 [id 49] Attr[ Service_type{#538} [|radius] (DF) (ttl
> : > 64, id 0, len 83)
> : > 19:08:18.965249 10.10.10.2.21645 > 20.20.20.114.sa-msg-port:
> : > rad-account-req 101 [id 50] Attr[ Acct_session_id{0000009B}
> : > Framed_proto{#301} Acct_authentic{#257} [|radius] (ttl 253, id 6671, len
> : > 129)
> : > 19:08:23.965408 10.10.10.2.21645 > 20.20.20.114.sa-msg-port:
> : > rad-account-req 101 [id 51] Attr[ Acct_session_id{0000009B}
> : > Framed_proto{#301} Acct_authentic{#257} [|radius] (ttl 253, id 6703, len
> : > 129)
> : > 19:08:28.975567 10.10.10.2.21645 > 20.20.20.114.sa-msg-port:
> : > rad-account-req 101 [id 52] Attr[ Acct_session_id{0000009B}
> : > Framed_proto{#301} Acct_authentic{#257} [|radius] (ttl 253, id 6723, len
> : > 129)
> : > 19:08:33.965726 10.10.10.2.21645 > 20.20.20.114.sa-msg-port:
> : > rad-account-req 101 [id 53] Attr[ Acct_session_id{0000009B}
> : > Framed_proto{#301} Acct_authentic{#257} [|radius] (ttl 253, id 6733, len
> : > 129)
> : >
> : >
> : >
> : >
> : >
> : >
> : > 19:09:03.076652 10.10.10.2.21645 > 20.20.20.114.sa-msg-port:
> : > rad-account-req 143 [id 54] Attr[ Acct_session_id{0000009B}
> : > Framed_proto{#264} Framed_ipaddr{3.3.3.82} Acct_authentic{#302}
> : > Acct_session_time{44 secs} ] (ttl 253, id 6845, len 171)
> : > 19:09:08.076811 10.10.10.2.21645 > 20.20.20.114.sa-msg-port:
> : > rad-account-req 143 [id 55] Attr[ Acct_session_id{0000009B}
> : > Framed_proto{#264} Framed_ipaddr{3.3.3.82} Acct_authentic{#302}
> : > Acct_session_time{44 secs} ] (ttl 253, id 6863, len 171)
> : > 19:09:13.076970 10.10.10.2.21645 > 20.20.20.114.sa-msg-port:
> : > rad-account-req 143 [id 56] Attr[ Acct_session_id{0000009B}
> : > Framed_proto{#264} Framed_ipaddr{3.3.3.82} Acct_authentic{#302}
> : > Acct_session_time{44 secs} ] (ttl 253, id 6878, len 171)
> : > 19:09:18.077129 10.10.10.2.21645 > 20.20.20.114.sa-msg-port:
> : > rad-account-req 143 [id 57] Attr[ Acct_session_id{0000009B}
> : > Framed_proto{#264} Framed_ipaddr{3.3.3.82} Acct_authentic{#302}
> : > Acct_session_time{44 secs} ] (ttl 253, id 6903, len 171)
> : >
> : >
> : > Could anyone explain to me why is this happening?
> : >
> : > Thanks.
> : >
> : > Regards,
> : > Cheeyong
> : > _______________________________________________
> : > cisco-bba mailing list
> : > cisco-bba at puck.nether.net
> : > https://puck.nether.net/mailman/listinfo/cisco-bba
> :
More information about the cisco-bba
mailing list