Event-Timestamp issue when reading a detail file
Hello, I would like to kinldy ask for an help with following issue. I am running Freeradius 3.2.3+dfsg-2+b4 (Debian package) and have following problem. I receive Radius Accounting and put it into a a detail files. Then I have a detail file reader which stores Accounting records to DB. I have noticed a weird thing related to timestamp of the records. All records are inserted to DB with +1 hour offset. The attribute Event-Timestamp is logged correctly - when grepping detail files for the Event-Timestamp , it is fine, no offset. When I start Freeradius in debug mode, I can see that the packet is received as follows: (3848) Received Accounting-Request Id 254 from 10.49.17.160:38050 to 10.49.17.164:1813 length 637 (3848) User-Name = "xxx" (3848) NAS-IP-Address = 10.49.32.254 (3848) NAS-Port = 793003 (3848) Service-Type = Framed-User (3848) Framed-Protocol = GPRS-PDP-Context (3848) Framed-IP-Address = 100.81.87.87 (3848) Framed-MTU = 1500 (3848) Called-Station-Id = "internet" (3848) Calling-Station-Id = "xxx" (3848) NAS-Identifier = "rzt-gw2" (3848) Acct-Status-Type = Start (3848) Acct-Session-Id = "591800FA15580ABD" (3848) Acct-Authentic = RADIUS (3848) Acct-Multi-Session-Id = "591800FA15580ABB" (3848) Event-Timestamp = "May 16 2024 21:32:59 CEST" . The same req. taken from the detail file in debug mode has the Event-Timestamp shifted by 1h! detail (/srv/radius/freeradius_01/radacct/detail.mobile_v3/queue-30/detail-*): Read packet from /srv/radius/freeradius_01/radacct/detail.mobile_v3/queue-30/detail.work User-Name = "xxx" NAS-IP-Address = 10.49.32.254 NAS-Port = 793003 Service-Type = Framed-User Framed-Protocol = GPRS-PDP-Context Framed-IP-Address = 100.81.87.87 Framed-MTU = 1500 Called-Station-Id = "internet" Calling-Station-Id = "xxx" NAS-Identifier = "rzt-gw2" Acct-Status-Type = Start Acct-Session-Id = "591800FA15580ABD" Acct-Authentic = RADIUS Acct-Multi-Session-Id = "591800FA15580ABB" Event-Timestamp = "May 16 2024 22:32:59 CEST" . Event-Timestamp with 1 hour offset is also inserted to DB. Here I use FROM_UNIXTIME(%{integer:Event-Timestamp}). I am running this setup on another machine for more than 3 years with Freeradius 3.0.13+git and there is nothing like that. I can see it with 3.2.3+dfsg-2+b4 and also 3.2.1+dfsg-4+deb12u1 (Bookworm default). NAS and Freeradius are both in Europe/Prague (CEST, +0200), timezone is set correctly, time in sync. Thanks Ales
On May 18, 2024, at 3:23 PM, Aleš Rygl <ales@rygl.net> wrote:
I would like to kinldy ask for an help with following issue. I am running Freeradius 3.2.3+dfsg-2+b4 (Debian package) and have following problem. I receive Radius Accounting and put it into a a detail files. Then I have a detail file reader which stores Accounting records to DB. I have noticed a weird thing related to timestamp of the records. All records are inserted to DB with +1 hour offset. The attribute Event-Timestamp is logged correctly - when grepping detail files for the Event-Timestamp , it is fine, no offset.
When I start Freeradius in debug mode, I can see that the packet is received as follows:
That's odd. We have all kinds of tests for dates, and they all pass. Plus, the time parsing code in src/lib/misc.c hasn't change between 3.0. and 3.2. The underlying issue is that the OS functions which create times from structs (mktime() etc.) don't take time zones. So they either (a) use the local time zone, or (b) use GMT / UTC. This means that the time zone in the string is ignored, and the OS / C library functions treat the time as being from the local time zone. So the two systems are either in different time zones, or one of them has the wrong time zone set. i.e. the date was printed in CEST, but when it was parsed, the local time zone was CEDT. We're working on fixing this in v4 by just removing the old-style time strings, and going to the RFC 3339 format. The nice thing there is that the times / dates are now numerical, so there are no internationalization issues, either. Alan DeKok.
On 20. 05. 24 14:54, Alan DeKok wrote:
On May 18, 2024, at 3:23 PM, Aleš Rygl <ales@rygl.net> wrote:
I would like to kinldy ask for an help with following issue. I am running Freeradius 3.2.3+dfsg-2+b4 (Debian package) and have following problem. I receive Radius Accounting and put it into a a detail files. Then I have a detail file reader which stores Accounting records to DB. I have noticed a weird thing related to timestamp of the records. All records are inserted to DB with +1 hour offset. The attribute Event-Timestamp is logged correctly - when grepping detail files for the Event-Timestamp , it is fine, no offset.
When I start Freeradius in debug mode, I can see that the packet is received as follows:
That's odd. We have all kinds of tests for dates, and they all pass. Plus, the time parsing code in src/lib/misc.c hasn't change between 3.0. and 3.2.
The underlying issue is that the OS functions which create times from structs (mktime() etc.) don't take time zones. So they either (a) use the local time zone, or (b) use GMT / UTC.
This means that the time zone in the string is ignored, and the OS / C library functions treat the time as being from the local time zone.
So the two systems are either in different time zones, or one of them has the wrong time zone set. i.e. the date was printed in CEST, but when it was parsed, the local time zone was CEDT.
We're working on fixing this in v4 by just removing the old-style time strings, and going to the RFC 3339 format. The nice thing there is that the times / dates are now numerical, so there are no internationalization issues, either.
Thanks Alan. Is there any way around this? I could use $S instead of Event-Timestamp, but that's no good. Would it be possible to manipulate the Event-Timestamp value with the expr module when reading the details file? Or when inserting into a DB where FROM_UNIXTIME(%{integer:Event-Timestamp}) is used. But it would have to respect DST change. Ales
On May 20, 2024, at 9:57 AM, Aleš Rygl <ales@rygl.net> wrote:
Is there any way around this? I could use $S instead of Event-Timestamp, but that's no good. Would it be possible to manipulate the Event-Timestamp value with the expr module when reading the details file? Or when inserting into a DB where FROM_UNIXTIME(%{integer:Event-Timestamp}) is used. But it would have to respect DST change.
The correct solution is to port the fixed code from the "master" branch: https://github.com/FreeRADIUS/freeradius-server/issues/5323 It's really just an "#ifdef __APPLE_" block, and a call to strptime(). Alan DeKok.
participants (2)
-
Alan DeKok -
Aleš Rygl