Accommodating miss behaving NAS?
David Herselman
dhe at syrex.co
Wed Jul 28 09:39:58 CEST 2021
Hi,
We have a legacy ADSL system whereby the Telco handles PPPoE termination of the circuits, proxying authentication and accounting records through to us. We have several instances where the NASs appear to be miss-behaving and looking for recommendations around this.
Authorization and authentication appears to be working as intended, accounting is also initially as expected in that we receive accounting start, interim updates and then an accounting stop. We however then continue to receive interim update accounting records where the utilisation is not added to the radacct table.
We do have a request logged with the Telco regarding this behaviour, but our legacy FR v1 system would continue to associate accounting data and my understanding of the mods-config/sql/main/mysql/queries.conf file is that the following query should still continue to update the closed session as well (pretty sure the following is unmodified):
#
# Update an existing session and calculate the interval
# between the last data we received for the session and this
# update. This can be used to find stale sessions.
#
query = "\
UPDATE ${....acct_table1} \
SET \
acctupdatetime = (@acctupdatetime_old:=acctupdatetime), \
acctupdatetime = FROM_UNIXTIME(\
%{integer:Event-Timestamp}), \
acctinterval = %{integer:Event-Timestamp} - \
UNIX_TIMESTAMP(@acctupdatetime_old), \
framedipaddress = '%{Framed-IP-Address}', \
acctsessiontime = %{%{Acct-Session-Time}:-NULL}, \
acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' \
<< 32 | '%{%{Acct-Input-Octets}:-0}', \
acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' \
<< 32 | '%{%{Acct-Output-Octets}:-0}' \
WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}'"
FR 3.0.17+dfsg-1.1 appears to only update accounting up until the stop being received, ignoring subsequent updates:
[admin at unix-01 ~]# mysql -u root -p**************** radius -e 'SELECT username,acctstarttime,acctstoptime,framedipaddress,callingstationid,acctinputoctets,acctoutputoctets FROM radacct WHERE acctuniqueid="50decbeb537ebe5860a8fdf11221017f"';
+------------------------------+---------------------+---------------------+-----------------+------------------+-----------------+------------------+
| username | acctstarttime | acctstoptime | framedipaddress | callingstationid | acctinputoctets | acctoutputoctets |
+------------------------------+---------------------+---------------------+-----------------+------------------+-----------------+------------------+
| user60d1 at realm.company.co.za<mailto:user60d1 at realm.company.co.za> | 2021-07-24 11:11:08 | 2021-07-25 18:50:23 | 41.247.86.6 | 0112223333 | 199564666 | 321290299 |
+------------------------------+---------------------+---------------------+-----------------+------------------+-----------------+------------------+
[admin at unix-01 ~]# grep '50decbeb537ebe5860a8fdf11221017f' /var/log/freeradius/radacct/*/*;
/var/log/freeradius/radacct/196.43.3.76/detail-20210724: Acct-Unique-Session-Id = "50decbeb537ebe5860a8fdf11221017f" # start
/var/log/freeradius/radacct/196.43.3.76/detail-20210724: Acct-Unique-Session-Id = "50decbeb537ebe5860a8fdf11221017f" # interim-update
/var/log/freeradius/radacct/196.43.3.76/detail-20210724: Acct-Unique-Session-Id = "50decbeb537ebe5860a8fdf11221017f" # interim-update
/var/log/freeradius/radacct/196.43.3.76/detail-20210725: Acct-Unique-Session-Id = "50decbeb537ebe5860a8fdf11221017f" # interim-update
/var/log/freeradius/radacct/196.43.3.76/detail-20210725: Acct-Unique-Session-Id = "50decbeb537ebe5860a8fdf11221017f" # stop
/var/log/freeradius/radacct/196.43.3.77/detail-20210725: Acct-Unique-Session-Id = "50decbeb537ebe5860a8fdf11221017f" # interim-update
/var/log/freeradius/radacct/196.43.3.77/detail-20210725: Acct-Unique-Session-Id = "50decbeb537ebe5860a8fdf11221017f" # interim-update
Herewith the relevant accounting packets for Acct-Unique-Session-Id = "50decbeb537ebe5860a8fdf11221017f". Green entries above are the 'start', 'interim-updates' and then a 'stop'. The red entries above are interim-updates we receive after the stop and the purple is the in/out counters as per the stop packet having been received:
Sat Jul 24 11:11:13 2021
X-Ascend-Xmit-Rate = 20480000
Acct-Authentic = RADIUS
NAS-IP-Address = 196.43.47.51
Attr-26.1431.7 = 0x4144534c
Framed-Protocol = PPP
Attr-26.1431.3 = 0x494e5445524e4554
NAS-Port-Type = PPPoEoQinQ
Acct-Status-Type = Start
Calling-Station-Id = "0112223333"
NAS-Port = 2686963842
User-Name = "user60d1 at realm.company.co.za"
Class = 0x4e31
X-Ascend-Data-Rate = 20480000
Acct-Delay-Time = 0
Framed-IP-Address = 41.247.86.6
NAS-Port-Id = "10/2/1:125.130"
Acct-Session-Time = 5
Attr-26.1431.4 = 0x00005000
Acct-Session-Id = "B74D8B03E91BB460FBD922"
Service-Type = Framed-User
Telkom-Access-Type = "DSL"
Proxy-State = 0x3739
Event-Timestamp = "Jul 24 2021 11:11:13 SAST"
Tmp-String-9 = "ai:"
Acct-Unique-Session-Id = "50decbeb537ebe5860a8fdf11221017f"
Timestamp = 1627117873
Sat Jul 24 17:10:26 2021
NAS-Port = 2686963842
Attr-26.1431.7 = 0x4144534c
X-Ascend-Xmit-Rate = 20480000
Calling-Station-Id = "0112223333"
Class = 0x4e31
NAS-Port-Type = PPPoEoQinQ
Framed-IP-Address = 41.247.86.6
Service-Type = Framed-User
Framed-Protocol = PPP
NAS-Port-Id = "10/2/1:125.130"
Acct-Input-Gigawords = 0
NAS-IP-Address = 196.43.47.51
Acct-Output-Octets = 65339784
Acct-Output-Packets = 138132
Acct-Input-Packets = 145488
User-Name = "user60d1 at realm.company.co.za"
Acct-Authentic = RADIUS
Acct-Session-Time = 21558
Attr-26.1431.3 = 0x494e5445524e4554
Acct-Status-Type = Interim-Update
Acct-Input-Octets = 33612675
Acct-Session-Id = "B74D8B03E91BB460FBD922"
Acct-Delay-Time = 0
Acct-Output-Gigawords = 0
Attr-26.1431.4 = 0x00005000
X-Ascend-Data-Rate = 20480000
Telkom-Access-Type = "DSL"
Proxy-State = 0x313936
Event-Timestamp = "Jul 24 2021 17:10:26 SAST"
Tmp-String-9 = "ai:"
Acct-Unique-Session-Id = "50decbeb537ebe5860a8fdf11221017f"
Timestamp = 1627139426
Sat Jul 24 23:13:24 2021
Acct-Input-Gigawords = 0
NAS-Port-Id = "10/2/1:125.130"
Acct-Output-Octets = 124192829
Attr-26.1431.7 = 0x4144534c
Acct-Delay-Time = 0
X-Ascend-Xmit-Rate = 20480000
X-Ascend-Data-Rate = 20480000
Attr-26.1431.4 = 0x00005000
Acct-Input-Packets = 295296
NAS-Port = 2686963842
Acct-Input-Octets = 86715171
User-Name = "user60d1 at realm.company.co.za"
Acct-Status-Type = Interim-Update
NAS-IP-Address = 196.43.47.51
Acct-Output-Packets = 271352
Attr-26.1431.3 = 0x494e5445524e4554
Framed-Protocol = PPP
Class = 0x4e31
Framed-IP-Address = 41.247.86.6
Service-Type = Framed-User
Acct-Output-Gigawords = 0
Calling-Station-Id = "0112223333"
Acct-Authentic = RADIUS
NAS-Port-Type = PPPoEoQinQ
Acct-Session-Time = 43336
Acct-Session-Id = "B74D8B03E91BB460FBD922"
Telkom-Access-Type = "DSL"
Proxy-State = 0x3634
Event-Timestamp = "Jul 24 2021 23:13:24 SAST"
Tmp-String-9 = "ai:"
Acct-Unique-Session-Id = "50decbeb537ebe5860a8fdf11221017f"
Timestamp = 1627161204
Sun Jul 25 05:15:19 2021
Acct-Input-Octets = 118004756
Attr-26.1431.4 = 0x00005000
Acct-Status-Type = Interim-Update
Acct-Input-Packets = 425898
X-Ascend-Xmit-Rate = 20480000
User-Name = "user60d1 at realm.company.co.za"
Framed-Protocol = PPP
NAS-Port = 2686963842
Attr-26.1431.7 = 0x4144534c
Class = 0x4e31
NAS-Port-Type = PPPoEoQinQ
Acct-Output-Octets = 179007110
Framed-IP-Address = 41.247.86.6
Acct-Output-Packets = 390444
Service-Type = Framed-User
X-Ascend-Data-Rate = 20480000
Acct-Session-Id = "B74D8B03E91BB460FBD922"
Acct-Session-Time = 65052
Acct-Output-Gigawords = 0
NAS-IP-Address = 196.43.47.51
Calling-Station-Id = "0112223333"
Acct-Delay-Time = 0
Attr-26.1431.3 = 0x494e5445524e4554
Acct-Input-Gigawords = 0
Acct-Authentic = RADIUS
NAS-Port-Id = "10/2/1:125.130"
Telkom-Access-Type = "DSL"
Proxy-State = 0x323432
Event-Timestamp = "Jul 25 2021 05:15:19 SAST"
Tmp-String-9 = "ai:"
Acct-Unique-Session-Id = "50decbeb537ebe5860a8fdf11221017f"
Timestamp = 1627182919
Sun Jul 25 18:50:23 2021
Calling-Station-Id = "0112223333"
Acct-Terminate-Cause = Lost-Carrier
Acct-Output-Octets = 321290299
NAS-Port-Type = PPPoEoQinQ
Acct-Authentic = RADIUS
Acct-Input-Packets = 798410
Attr-26.1431.3 = 0x494e5445524e4554
Acct-Status-Type = Stop
Acct-Input-Gigawords = 0
Framed-Protocol = PPP
NAS-Port = 2686963842
X-Ascend-Data-Rate = 20480000
Attr-26.1431.7 = 0x4144534c
Acct-Delay-Time = 0
User-Name = "user60d1 at realm.company.co.za"
Attr-26.1431.4 = 0x00005000
Class = 0x4e31
NAS-Port-Id = "10/2/1:125.130"
Service-Type = Framed-User
Acct-Session-Id = "B74D8B03E91BB460FBD922"
NAS-IP-Address = 196.43.47.51
Acct-Input-Octets = 199564666
Acct-Session-Time = 113955
Acct-Output-Gigawords = 0
Framed-IP-Address = 41.247.86.6
X-Ascend-Xmit-Rate = 20480000
Acct-Output-Packets = 742386
Telkom-Access-Type = "DSL"
Proxy-State = 0x323235
Event-Timestamp = "Jul 25 2021 18:50:23 SAST"
Tmp-String-9 = "ai:"
Acct-Unique-Session-Id = "50decbeb537ebe5860a8fdf11221017f"
Timestamp = 1627231823
Sun Jul 25 11:16:58 2021
NAS-Port-Id = "10/2/1:125.130"
Acct-Status-Type = Interim-Update
NAS-IP-Address = 196.43.47.51
Class = 0x4e31
X-Ascend-Data-Rate = 20480000
Acct-Input-Packets = 600825
Attr-26.1431.4 = 0x00005000
X-Ascend-Xmit-Rate = 20480000
Framed-IP-Address = 41.247.86.6
Acct-Session-Id = "B74D8B03E91BB460FBD922"
Acct-Input-Gigawords = 0
Acct-Output-Gigawords = 0
Acct-Delay-Time = 0
User-Name = "user60d1 at realm.company.co.za"
Framed-Protocol = PPP
Acct-Session-Time = 86751
Attr-26.1431.7 = 0x4144534c
Service-Type = Framed-User
Calling-Station-Id = "0112223333"
Attr-26.1431.3 = 0x494e5445524e4554
Acct-Input-Octets = 155655292
Acct-Output-Octets = 243066595
NAS-Port-Type = PPPoEoQinQ
NAS-Port = 2686963842
Acct-Output-Packets = 557229
Acct-Authentic = RADIUS
Telkom-Access-Type = "DSL"
Proxy-State = 0x3439
Event-Timestamp = "Jul 25 2021 11:16:58 SAST"
Tmp-String-9 = "ai:"
Acct-Unique-Session-Id = "50decbeb537ebe5860a8fdf11221017f"
Timestamp = 1627204618
Sun Jul 25 17:14:09 2021
Acct-Delay-Time = 0
NAS-Port-Id = "10/2/1:125.130"
Acct-Output-Packets = 708535
Service-Type = Framed-User
Calling-Station-Id = "0112223333"
Acct-Session-Id = "B74D8B03E91BB460FBD922"
X-Ascend-Data-Rate = 20480000
Class = 0x4e31
Acct-Authentic = RADIUS
Framed-IP-Address = 41.247.86.6
NAS-Port = 2686963842
User-Name = "user60d1 at realm.company.co.za"
Acct-Output-Octets = 305092740
Acct-Session-Time = 108182
Acct-Input-Gigawords = 0
Acct-Output-Gigawords = 0
Attr-26.1431.4 = 0x00005000
Framed-Protocol = PPP
Acct-Status-Type = Interim-Update
Acct-Input-Packets = 761669
Attr-26.1431.7 = 0x4144534c
Attr-26.1431.3 = 0x494e5445524e4554
NAS-Port-Type = PPPoEoQinQ
Acct-Input-Octets = 190814584
NAS-IP-Address = 196.43.47.51
X-Ascend-Xmit-Rate = 20480000
Telkom-Access-Type = "DSL"
Proxy-State = 0x3133
Event-Timestamp = "Jul 25 2021 17:14:09 SAST"
Tmp-String-9 = "ai:"
Acct-Unique-Session-Id = "50decbeb537ebe5860a8fdf11221017f"
Timestamp = 1627226049
Regards
David Herselman
More information about the Freeradius-Users
mailing list