Problem with datetime and mysql
ANGEL LUIS MATEO MARTINEZ
amateo at um.es
Fri Sep 15 10:19:20 UTC 2023
With more debugging I have found that this the detail saved for the Start record:
Fri Sep 15 12:15:57 2023
Service-Type = Framed-User
Framed-Protocol = PPP
NAS-Port = 15728735
NAS-Port-Type = Virtual
User-Name = "angel.luis at um.es"
Calling-Station-Id = "155.54.67.5"
Called-Station-Id = "155.54.213.7"
MS-CHAP-Domain = "um.es"
Acct-Session-Id = "81a0005b"
Framed-IP-Address = 155.54.194.54
Acct-Authentic = RADIUS
Event-Timestamp = "Sep 15 2023 12:15:57 CEST"
Acct-Status-Type = Start
NAS-Identifier = "MikroTik-Pruebas"
Acct-Delay-Time = 0
Mikrotik-Realm = "um.es"
NAS-IP-Address = 155.54.213.7
Huntgroup-Name = "vpn"
X-Atica-Service = "vpn"
X-Atica-Service-Filter = "vpn"
Stripped-User-Name = "angel.luis"
Realm = "um.es"
Timestamp = 1694772957
But this is the content passed to buffered-sql site:
detail (/datapool/radacct/acct_sql_log): Read packet from /datapool/radacct/acct_sql_log.work
Service-Type = Framed-User
Framed-Protocol = PPP
NAS-Port = 15728735
NAS-Port-Type = Virtual
User-Name = "angel.luis at um.es"
Calling-Station-Id = "155.54.67.5"
Called-Station-Id = "155.54.213.7"
MS-CHAP-Domain = "um.es"
Acct-Session-Id = "81a0005b"
Framed-IP-Address = 155.54.194.54
Acct-Authentic = RADIUS
Event-Timestamp = "Sep 15 2023 13:15:57 CEST"
Acct-Status-Type = Start
NAS-Identifier = "MikroTik-Pruebas"
Acct-Delay-Time = 4294963696
Mikrotik-Realm = "um.es"
NAS-IP-Address = 155.54.213.7
Huntgroup-Name = "vpn"
X-Atica-Service = "vpn"
X-Atica-Service-Filter = "vpn"
Stripped-User-Name = "angel.luis"
Realm = "um.es"
SQL-User-Name = "angel.luis at um.es"
Packet-Original-Timestamp = "Sep 15 2023 12:15:57 CEST"
Packet-Transmit-Counter = 1
Any why the Event-Timestamp is changed in the buffered-sql?
--
Angel L. Mateo Martínez
Sección de Telemática
Área de Tecnologías de la Información y las Comunicaciones Aplicadas (ATICA)
http://www.um.es/atica
Tfo: 868889150
Fax: 868888337
________________________________________
De: Freeradius-Users <freeradius-users-bounces+amateo=um.es at lists.freeradius.org> en nombre de ANGEL LUIS MATEO MARTINEZ <amateo at um.es>
Enviado: viernes, 15 de septiembre de 2023 9:56
Para: FreeRadius users mailing list
Asunto: Problem with datetime and mysql
Hello,
I have a running freeradius with Ubuntu 18.04 and freeradius 3.0.19. In this system I'm using mysql to store accounting records in a MySQL database (radacct). To achieve this, I'm using the buffered-sql site. This is working fine.
Now I'm developing a new updated system with Ubuntu 22.04 and freeradius 3.0.26. I'm trying to configure this same MySQL database. I'm using the same database. Although the store in the database is working, I have a problem with datetime stored in acctstarttime, aactupdatetime and acctstoptime columns. The problem is that the datetime stored is 1 hour ahead of my current time.
I have both SO configured with the same timezone. In my case, it's Europe/Madrid (CEST, GMT+2 now).
I have also the same queries.conf file in both systems. I'm using the queries.conf distributed with the freeradius 3.0.26 22.04 package. In this file:
...
event_timestamp_epoch = "%{%{integer:Event-Timestamp}:-%l}"
# event_timestamp is the SQL snippet for converting an epoch timestamp
# to an SQL date.
event_timestamp = "FROM_UNIXTIME(${event_timestamp_epoch})"
...
start {
#
# Insert a new record into the sessions table
#
query = "\
INSERT INTO ${....acct_table1} \
(${...column_list}) \
VALUES \
('%{Acct-Session-Id}', \
'%{Acct-Unique-Session-Id}', \
'%{SQL-User-Name}', \
'%{Realm}', \
'%{NAS-IP-Address}', \
'%{%{NAS-Port-ID}:-%{NAS-Port}}', \
'%{NAS-Port-Type}', \
${....event_timestamp}, \
${....event_timestamp}, \
NULL, \
'0', \
'%{Acct-Authentic}', \
'%{Connect-Info}', \
'', \
'0', \
'0', \
'%{Called-Station-Id}', \
'%{Calling-Station-Id}', \
'', \
'%{Service-Type}', \
'%{Framed-Protocol}', \
'%{Framed-IP-Address}', \
'%{Framed-IPv6-Address}', \
'%{Framed-IPv6-Prefix}', \
'%{Framed-Interface-Id}', \
'%{Delegated-IPv6-Prefix}' \
${....class.packet_xlat})"
...
With this configuration, I have this Start record in my old system:
Fri Sep 15 09:33:10 2023
Service-Type = Framed-User
Framed-Protocol = PPP
NAS-Port = 15728730
NAS-Port-Type = Virtual
User-Name = "XXXXX at um.es"
Calling-Station-Id = "155.54.67.5"
Called-Station-Id = "155.54.213.7"
MS-CHAP-Domain = "um.es"
Acct-Session-Id = "81a00056"
Framed-IP-Address = 155.54.192.37
Acct-Authentic = RADIUS
Event-Timestamp = "Sep 15 2023 09:33:10 CEST"
Acct-Status-Type = Start
NAS-Identifier = "MikroTik-Pruebas"
Acct-Delay-Time = 0
Mikrotik-Realm = "um.es"
NAS-IP-Address = 155.54.213.7
Huntgroup-Name = "vpn"
X-Atica-Service = "vpn"
X-Atica-Service-Filter = "vpn"
Stripped-User-Name = "XXXXX"
Realm = "um.es"
Timestamp = 1694763190
and the corresponding insert query in the database is:
use dbradiuslog;
SET timestamp=1694763191;
INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctupdatetime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, framedipv6address, framedipv6prefix, framedinterfaceid, delegatedipv6prefix ) VALUES ('81a00056', 'eb9b9fe238b5a46ac0e6be64acd6ec58', 'XXXXX at um.es', 'um.es', '155.54.213.7', '15728730', 'Virtual', FROM_UNIXTIME(1694763190), FROM_UNIXTIME(1694763190), NULL, '0', 'RADIUS', '', '', '0', '0', '155.54.213.7', '155.54.67.5', '', 'Framed-User', 'PPP', '155.54.192.37', '', '', '', '' );
where the 1694763191 timestamp is "Fri Sep 15 2023 09:33:11 GMT+0200" and 1694763190 is "Fri Sep 15 2023 09:33:10 GMT+0200"
and datetimes are correct.
But in the updated system I have this detail entry:
Fri Sep 15 09:35:47 2023
Service-Type = Framed-User
Framed-Protocol = PPP
NAS-Port = 15728731
NAS-Port-Type = Virtual
User-Name = "XXXXX at um.es"
Calling-Station-Id = "155.54.67.5"
Called-Station-Id = "155.54.213.7"
MS-CHAP-Domain = "um.es"
Acct-Session-Id = "81a00057"
Framed-IP-Address = 155.54.194.50
Acct-Authentic = RADIUS
Event-Timestamp = "Sep 15 2023 09:35:47 CEST"
Acct-Status-Type = Start
NAS-Identifier = "MikroTik-Pruebas"
Acct-Delay-Time = 0
Mikrotik-Realm = "um.es"
NAS-IP-Address = 155.54.213.7
Huntgroup-Name = "vpn"
X-Atica-Service = "vpn"
X-Atica-Service-Filter = "vpn"
Stripped-User-Name = "XXXXX"
Realm = "um.es"
Timestamp = 1694763347
and the insert query is:
use dbradiuslog;
SET timestamp=1694763348;
INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctupdatetime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, framedipv6address, framedipv6prefix, framedinterfaceid, delegatedipv6prefix ) VALUES ('81a00057', '186c6d4ebe375d3178097fe46f3bdaae', 'XXXXX at um.es', 'um.es', '155.54.213.7', '15728731', 'Virtual', FROM_UNIXTIME(1694766947), FROM_UNIXTIME(1694766947), NULL, '0', 'RADIUS', '', '', '0', '0', '155.54.213.7', '155.54.67.5', '', 'Framed-User', 'PPP', '155.54.194.50', '', '', '', '' );
in this case, the first 1694763348 datetime (the used in SET) corresponds to "Fri Sep 15 2023 09:35:48 GMT+0200" (it's fine), but the 1694766947 used in FROM_UNIX(1694766947) corresponds to "Fri Sep 15 2023 10:35:47 GMT+0200" which is wrong. The date stored in the database is wrong too.
It seems that there is a problem somewhere in the transformation from the Event-Timestamp entry in the detail to the epoch used in the SQL query.
Any help with this? Thank you.
-
List info/subscribe/unsubscribe? See https://urldefense.com/v3/__http://www.freeradius.org/list/users.html__;!!D9dNQwwGXtA!XBymHp2XgmNkyFvGSwSNEuDhIGTdbh1KDVfGB8kMSsHR4FwJfOz8SeiaEo66zvMP3yrDhEPHkg$
More information about the Freeradius-Users
mailing list