incorrect radacct AcctSessionTime
Just one observation ...
From time to time I see entries in the radacct AcctSessionTime column with over 1 billion seconds, despite that the StopTime minus StartTime is less than 5 seconds. With FR 1.0.5 it was a few times 2147483647:
AcctStartTime AcctStopTime AcctSessionTime inOctets outOctets 2005-10-06 03:34:30 2005-10-06 03:34:34 2147483647 1069 4541 2005-11-09 00:13:39 2005-11-09 00:13:40 2147483647 128 124 2005-12-01 03:13:55 2005-12-01 03:13:58 2147483647 0 40 Now with 1.1.0 it is around 1142280970: 2006-03-14 00:16:29 2006-03-14 00:16:32 1142280970 100 152 2006-03-14 00:16:29 2006-03-14 00:16:32 1142280970 0 0 2006-03-14 00:16:29 2006-03-14 00:16:32 1142280969 0 0 2006-03-14 00:16:30 2006-03-14 00:16:32 1142280969 0 0 2006-03-14 03:26:54 2006-03-14 03:26:56 1142292393 0 0 While the number of transferred octes is usually less than 200 bytes. There are less than 15 users at the same time (GMT time) using the server. There is some heavy download activity before ... I presume that the NAS (wrt54g with Chillispot) is sending the incorrect information ... Is this correct? Gunther
"Gunther" <freeradius@caribsms.com> wrote:
From time to time I see entries in the radacct AcctSessionTime column with over 1 billion seconds, despite that the StopTime minus StartTime is less than 5 seconds. With FR 1.0.5 it was a few times 2147483647:
2147483647 is 2^31-1. It looks like a signed/unsigned problem to me.
Now with 1.1.0 it is around 1142280970:
Which is a weird number.
I presume that the NAS (wrt54g with Chillispot) is sending the incorrect information ... Is this correct?
Maybe. See the SQL queries. If the NAS is sending Acct-Session-Time, that goes into the column. If it doesn't send Acct-Session-Time, then the session time is calculated based on the local system time, and other info. It looks to me like the clocks on your NAS and the RADIUS server may be quite a ways off from each other. Alan DeKok.
On Tue, 2006-14-03 at 15:16 -0500, Alan DeKok wrote:
"Gunther" <freeradius@caribsms.com> wrote:
From time to time I see entries in the radacct AcctSessionTime column with over 1 billion seconds, despite that the StopTime minus StartTime is less than 5 seconds. With FR 1.0.5 it was a few times 2147483647:
2147483647 is 2^31-1. It looks like a signed/unsigned problem to me.
I used to see Acct-Session-Time responses from USR Hyper Cards like that every so often, the NAS was at fault and required a reboot. We would then calculate the time : Example, Acct-Session-Time = (Acct-Stop-Time - Acct-Stop-Delay) - (Acct-Start-Time + Acct-Start-Delay) We did it that way to give the customer the benefit of any error possibly incurred by delays. How you do this in real life will depend on what kind of DB you use to store the accounting data.
Now with 1.1.0 it is around 1142280970:
Which is a weird number.
I presume that the NAS (wrt54g with Chillispot) is sending the incorrect information ... Is this correct?
Maybe. See the SQL queries. If the NAS is sending Acct-Session-Time, that goes into the column. If it doesn't send Acct-Session-Time, then the session time is calculated based on the local system time, and other info.
It looks to me like the clocks on your NAS and the RADIUS server may be quite a ways off from each other.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Guy Fraser wrote Sent: Wednesday, March 15, 2006 11:24 AM
On Tue, 2006-14-03 at 15:16 -0500, Alan DeKok wrote:
"Gunther" <freeradius@caribsms.com> wrote:
From time to time I see entries in the radacct AcctSessionTime column with over 1 billion seconds, despite that the StopTime minus StartTime is less than 5 seconds. With FR 1.0.5 it was a few times 2147483647:
2147483647 is 2^31-1. It looks like a signed/unsigned problem to me.
I used to see Acct-Session-Time responses from USR Hyper Cards like that every so often, the NAS was at fault and required a reboot.
We would then calculate the time : Example, Acct-Session-Time = (Acct-Stop-Time - Acct-Stop-Delay) - (Acct-Start-Time + Acct-Start-Delay)
We did it that way to give the customer the benefit of any error possibly incurred by delays. How you do this in real life will depend on what kind of DB you use to store the accounting data.
I am using MySQL and I simply exclude these entries as the amount of data is usually below 200 bytes. The problem seem to come from Chillispot in connection with mac authentication (macallowed). We put the number of macallowed users down, using UAM instead and it seems to work. Had no entries of that kind for over 24 hours.
-----Original Message----- Alan DeKok wrote: Sent: Tuesday, March 14, 2006 4:17 PM To: FreeRadius users mailing list Subject: Re: incorrect radacct AcctSessionTime
From time to time I see entries in the radacct AcctSessionTime column with over 1 billion seconds, despite that the StopTime minus StartTime is less than 5 seconds.
I presume that the NAS (wrt54g with Chillispot) is sending the incorrect information ... Is this correct?
Maybe. See the SQL queries. If the NAS is sending Acct-Session-Time, that goes into the column. If it doesn't send Acct-Session-Time, then the session time is calculated based on the local system time, and other info.
Yes, it is in the SQL queries and as far as I understand Chillispot is sending the Acct-Session-Time. It only seems to happen with MAC authenticated addresses (macallowed). Looks still like a Chillispot problem. But it could help to actually subtract AcctStopTime - AcctStartTime to get the AcctSessionTime.
It looks to me like the clocks on your NAS and the RADIUS server may be quite a ways off from each other.
Not sure if I can change that at all. The wrt54G & Chillispot box does not always set the time correct. If there is no Internet connection at boottime to synchronize with a time server, it is using some very old time. But that is not the case here as the unit was on the 'right local time', while the server runs on GMT. Gunther
On Tue 14 Mar 2006 08:51, Gunther wrote:
I presume that the NAS (wrt54g with Chillispot) is sending the incorrect information ... Is this correct?
Please check your detail files (If you have them enabled) to confirm if the NAS is sending you this data or not. -- Peter Nixon http://www.peternixon.net/ PGP Key: http://www.peternixon.net/public.asc
Thanks for the hint ... !! The details file shows: Thu Mar 16 02:41:46 2006 Acct-Status-Type = Stop User-Name = "00-0D-88-10-61-C9@mystuff" Calling-Station-Id = "00-0D-88-00-aa-aa" Called-Station-Id = "00-14-BF-20-ff-dd" NAS-Port-Type = Wireless-802.11 NAS-Port = 2 NAS-Port-Id = "00000002" NAS-IP-Address = 0.0.0.0 ... (how come it is always 0.0.0.0?) NAS-Identifier = "myIdent" Framed-IP-Address = 192.168.182.251 Acct-Session-Id = "0000001500000002" Acct-Input-Octets = 130 Acct-Output-Octets = 48 Acct-Input-Gigawords = 0 Acct-Output-Gigawords = 0 Acct-Input-Packets = 1 Acct-Output-Packets = 1 Acct-Session-Time = 1142462484 ... that looks like a timestamp !!! Acct-Terminate-Cause = Session-Timeout Client-IP-Address = My-IP Acct-Unique-Session-Id = "dd506e4d4bda70aa" Timestamp = 1142476906 !!!! Means it is from the Chillispot wrt54g nas! Not a FR problem at all! Gunther
-----Original Message----- Peter Nixon wrote: Sent: Thursday, March 16, 2006 3:11 AM
On Tue 14 Mar 2006 08:51, Gunther wrote:
I presume that the NAS (wrt54g with Chillispot) is sending the incorrect information ... Is this correct?
Please check your detail files (If you have them enabled) to confirm if the NAS is sending you this data or not.
participants (4)
-
Alan DeKok -
Gunther -
Guy Fraser -
Peter Nixon