[cisco-bba] Multiple Radius Accounting
Tay Chee Yong
tcy at pacific.net.sg
Fri Sep 19 18:14:03 EDT 2003
Hi Dennis,
Thanks for your advise. Had managed to rectify the problem.
Regards,
Cheeyong
On Wed, 17 Sep 2003, Dennis Peng wrote:
: 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