Incorrect datetime issue
Somanath Mishra
somanath.mishra at planetsbrain.com
Thu Sep 13 13:52:34 CEST 2018
Hi,
here is all debug output queries. You can see incorrect datetime value
below :
rlm_sql (sql): Opening additional connection (10), 1 of 25 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX
socket, server version 5.7.23-0ubuntu0.16.04.1, protocol version 10
(5) [sql] = fail
(5) } # accounting = fail
(5) Not sending reply to client.
(5) Finished request
(5) Cleaning up request packet ID 19 with timestamp +63
Waking up in 2.9 seconds.
(6) Received Accounting-Request Id 19 from 192.168.0.4:57878 to
192.168.0.252:1813 length 207
(6) Acct-Status-Type = Start
(6) Acct-Session-Id = "3C00A8C0-00043495"
(6) Acct-Authentic = RADIUS
(6) User-Name = "bob"
(6) Calling-Station-Id = "18:f0:e4:b0:fe:fd"
(6) Called-Station-Id = "00:0c:29:67:6d:ec"
(6) Connect-Info = "CONNECT Unknown Radio"
(6) NAS-Identifier = "00:0c:29:67:6d:ec"
(6) Meru-Access-Point-Id = 10
(6) Meru-Access-Point-Name = "Bangalore"
(6) Attr-26.15983.3 = 0xc0a8003c
(6) Framed-IP-Address = 192.168.0.60
(6) NAS-IP-Address = 192.168.0.4
(6) NAS-Port-Type = Wireless-802.11
(6) NAS-Port = 0
(6) Acct-Delay-Time = 0
(6) # Executing section preacct from file
/etc/freeradius/sites-enabled/default
(6) preacct {
(6) [preprocess] = ok
(6) policy acct_unique {
(6) update request {
(6) &Tmp-String-9 := "ai:"
(6) } # update request = noop
(6) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) &&
("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) {
(6) EXPAND %{hex:&Class}
(6) -->
(6) EXPAND ^%{hex:&Tmp-String-9}
(6) --> ^61693a
(6) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) &&
("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) -> FALSE
(6) else {
(6) update request {
(6) EXPAND
%{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}
(6) --> deb7615a3734113b62c4db4bc605a4c4
(6) &Acct-Unique-Session-Id := deb7615a3734113b62c4db4bc605a4c4
(6) } # update request = noop
(6) } # else = noop
(6) } # policy acct_unique = noop
(6) suffix: Checking for suffix after "@"
(6) suffix: No '@' in User-Name = "bob", looking up realm NULL
(6) suffix: No such realm "NULL"
(6) [suffix] = noop
(6) [files] = noop
(6) } # preacct = ok
(6) # Executing section accounting from file
/etc/freeradius/sites-enabled/default
(6) accounting {
(6) detail: EXPAND
/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
(6) detail: --> /var/log/freeradius/radacct/192.168.0.4/detail-20180913
(6) detail:
/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
expands to /var/log/freeradius/radacct/192.168.0.4/detail-20180913
(6) detail: EXPAND %t
(6) detail: --> Thu Sep 13 12:49:29 2018
(6) [detail] = ok
(6) [unix] = ok
(6) sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query}
(6) sql: --> type.start.query
(6) sql: Using query template 'query'
rlm_sql (sql): Reserved connection (3)
(6) sql: EXPAND %{User-Name}
(6) sql: --> bob
(6) sql: SQL-User-Name set to 'bob'
(6) sql: EXPAND 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) VALUES ('%{Acct-Session-Id}',
'%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}',
'%{NAS-IP-Address}', '%{%{NAS-Port-ID}:-%{NAS-Port}}', '%{NAS-Port-Type}',
%{%{integer:Event-Timestamp}:-date('now')},
%{%{integer:Event-Timestamp}:-date('now')}, NULL, '0',
'%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0',
'%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}',
'%{Framed-Protocol}', '%{Framed-IP-Address}')
(6) sql: --> 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) VALUES ('3C00A8C0-00043495',
'deb7615a3734113b62c4db4bc605a4c4', 'bob', '', '192.168.0.4', '0',
'Wireless-802.11', 1536839369, 1536839369, NULL, '0', 'RADIUS', 'CONNECT
Unknown Radio', '', '0', '0', '00:0c:29:67:6d:ec', '18:f0:e4:b0:fe:fd',
'', '', '', '192.168.0.60')
(6) sql: Executing query: 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) VALUES ('3C00A8C0-00043495',
'deb7615a3734113b62c4db4bc605a4c4', 'bob', '', '192.168.0.4', '0',
'Wireless-802.11', 1536839369, 1536839369, NULL, '0', 'RADIUS', 'CONNECT
Unknown Radio', '', '0', '0', '00:0c:29:67:6d:ec', '18:f0:e4:b0:fe:fd',
'', '', '', '192.168.0.60')
(6) sql: ERROR: rlm_sql_mysql: ERROR 1292 (Incorrect datetime value:
'1536839369' for column 'acctstarttime' at row 1): 22007
(6) sql: SQL query returned: server error
rlm_sql (sql): Released connection (3)
Need 2 more connections to reach 10 spares
rlm_sql (sql): Opening additional connection (11), 1 of 24 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX
socket, server version 5.7.23-0ubuntu0.16.04.1, protocol version 10
(6) [sql] = fail
(6) } # accounting = fail
(6) Not sending reply to client.
(6) Finished request
(6) Cleaning up request packet ID 19 with timestamp +65
Waking up in 0.9 seconds.
(3) Cleaning up request packet ID 17 with timestamp +61
Ready to process requests
---------------------------------------------------------------------
On Thu, September 13, 2018 5:16 pm, Alan DeKok wrote:
> On Sep 13, 2018, at 7:34 AM, Somanath Mishra
> <somanath.mishra at planetsbrain.com> wrote:
>
>>
>> Hi,
>>
>>
>> i am facing issue in radacct insert. So it is showing incorrect
>> dattime. So in debug i found datetime cloumn is missing 'FROM_UNIXTIME'
>> in debug o/p . Below you can see debug msg. ...
>> ----------------------------------------------------------------------
>> but in insert stmt query looking ok. below is insert stmt query.
>
> The query from the debug output is not the same one as the query you
> posted here.
>
> The SQL configuration contains many, many, queries. The debug output is
> likely showing you a different one.
>
> i.e. the debug output includes "strftime". But the query you posted here
> doesn't use that. So they are different queries.
>
> You need to find the *correct* query in the config files and fix that.
>
>
> It looks like you're using the sqlite driver for SQL. Is this what you
> want to do?
>
> Alan DeKok.
>
>
>
> -
> List info/subscribe/unsubscribe? See
> http://www.freeradius.org/list/users.html
More information about the Freeradius-Users
mailing list