radius accounting not starting....
Hi Team, i facing one problem in accounting part. So after authrization accounting part is not starting. i am getting data in radpostauth "Accept-Accept" ,but in radacct there is no data. here is debugging logs: freeradius | Ready to process requests freeradius | (0) Received Access-Request Id 153 from 192.168.0.4:47212 to 172.25.0.101:1812 length 182 freeradius | (0) Service-Type = Login-User freeradius | (0) Framed-MTU = 1250 freeradius | (0) User-Name = "12347@@TM11" freeradius | (0) User-Password = "b3957233dd5294cbf47d95fb3f584239" freeradius | (0) Calling-Station-Id = "9c:4e:36:9c:71:18" freeradius | (0) Called-Station-Id = "00:0c:29:67:6d:ec" freeradius | (0) Connect-Info = "CONNECT Unknown Radio" freeradius | (0) Framed-IP-Address = 10.0.1.24 freeradius | (0) NAS-IP-Address = 192.168.0.4 freeradius | (0) NAS-Port-Type = Wireless-802.11 freeradius | (0) NAS-Port = 0 freeradius | (0) Message-Authenticator = 0xda54bc22f970f04a4435875330451229 freeradius | (0) # Executing section authorize from file /etc/freeradius/sites-enabled/default freeradius | (0) authorize { freeradius | (0) policy filter_username { freeradius | (0) if (&User-Name) { freeradius | (0) if (&User-Name) -> TRUE freeradius | (0) if (&User-Name) { freeradius | (0) if (&User-Name =~ / /) { freeradius | (0) if (&User-Name =~ / /) -> FALSE freeradius | (0) if (&User-Name =~ /\.\./ ) { freeradius | (0) if (&User-Name =~ /\.\./ ) -> FALSE freeradius | (0) if (&User-Name =~ /\.$/) { freeradius | (0) if (&User-Name =~ /\.$/) -> FALSE freeradius | (0) if (&User-Name =~ /@\./) { freeradius | (0) if (&User-Name =~ /@\./) -> FALSE freeradius | (0) } # if (&User-Name) = notfound freeradius | (0) } # policy filter_username = notfound freeradius | (0) [preprocess] = ok freeradius | (0) [chap] = noop freeradius | (0) [mschap] = noop freeradius | (0) [digest] = noop freeradius | (0) suffix: Checking for suffix after "@" freeradius | (0) suffix: Looking up realm "TM11" for User-Name = "12347@@TM11" freeradius | (0) suffix: No such realm "TM11" freeradius | (0) [suffix] = noop freeradius | (0) eap: No EAP-Message, not doing EAP freeradius | (0) [eap] = noop freeradius | (0) [files] = noop freeradius | (0) sql: EXPAND %{User-Name} freeradius | (0) sql: --> 12347@@TM11 freeradius | (0) sql: SQL-User-Name set to '12347@@TM11' freeradius | rlm_sql (sql): Closing connection (1): Hit idle_timeout, was idle for 305 seconds freeradius | rlm_sql_mysql: Socket destructor called, closing socket freeradius | rlm_sql (sql): Closing connection (2): Hit idle_timeout, was idle for 305 seconds freeradius | rlm_sql_mysql: Socket destructor called, closing socket freeradius | rlm_sql (sql): Closing connection (3): Hit idle_timeout, was idle for 305 seconds freeradius | rlm_sql_mysql: Socket destructor called, closing socket freeradius | rlm_sql (sql): Closing connection (4): Hit idle_timeout, was idle for 305 seconds freeradius | rlm_sql (sql): You probably need to lower "min" freeradius | rlm_sql_mysql: Socket destructor called, closing socket freeradius | rlm_sql (sql): Closing connection (0): Hit idle_timeout, was idle for 305 seconds freeradius | rlm_sql (sql): You probably need to lower "min" freeradius | rlm_sql_mysql: Socket destructor called, closing socket freeradius | rlm_sql (sql): Closing connection (5): Hit idle_timeout, was idle for 305 seconds freeradius | rlm_sql (sql): You probably need to lower "min" freeradius | rlm_sql_mysql: Socket destructor called, closing socket freeradius | rlm_sql (sql): 0 of 0 connections in use. You may need to increase "spare" freeradius | rlm_sql (sql): Opening additional connection (6), 1 of 32 pending slots used freeradius | rlm_sql_mysql: Starting connect to MySQL server freeradius | rlm_sql_mysql: Connected to database 'radius' on 172.25.0.100 via TCP/IP, server version 5.7.25, protocol version 10 freeradius | rlm_sql (sql): Reserved connection (6) freeradius | (0) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id freeradius | (0) sql: --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = '12347@@TM11' ORDER BY id freeradius | (0) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '12347@@TM11' ORDER BY id freeradius | (0) sql: User found in radcheck table freeradius | (0) sql: Conditional check items matched, merging assignment check items freeradius | (0) sql: Cleartext-Password := "b3957233dd5294cbf47d95fb3f584239" freeradius | (0) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id freeradius | (0) sql: --> SELECT id, username, attribute, value, op FROM radreply WHERE username = '12347@@TM11' ORDER BY id freeradius | (0) sql: Executing select query: SELECT id, username, attribute, value, op FROM radreply WHERE username = '12347@@TM11' ORDER BY id freeradius | (0) sql: EXPAND SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority freeradius | (0) sql: --> SELECT groupname FROM radusergroup WHERE username = '12347@@TM11' ORDER BY priority freeradius | (0) sql: Executing select query: SELECT groupname FROM radusergroup WHERE username = '12347@@TM11' ORDER BY priority freeradius | (0) sql: User found in the group table freeradius | (0) sql: EXPAND SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id freeradius | (0) sql: --> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'allowall' ORDER BY id freeradius | (0) sql: Executing select query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'allowall' ORDER BY id freeradius | (0) sql: Group "allowall": Conditional check items matched freeradius | (0) sql: Group "allowall": Merging assignment check items freeradius | (0) sql: Framed-Protocol := 0 freeradius | (0) sql: EXPAND SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id freeradius | (0) sql: --> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'allowall' ORDER BY id freeradius | (0) sql: Executing select query: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'allowall' ORDER BY id freeradius | (0) sql: Group "allowall": Merging reply items freeradius | rlm_sql (sql): Released connection (6) freeradius | Need 2 more connections to reach min connections (3) freeradius | rlm_sql (sql): Opening additional connection (7), 1 of 31 pending slots used freeradius | rlm_sql_mysql: Starting connect to MySQL server freeradius | rlm_sql_mysql: Connected to database 'radius' on 172.25.0.100 via TCP/IP, server version 5.7.25, protocol version 10 freeradius | (0) [sql] = ok freeradius | (0) [expiration] = noop freeradius | (0) [logintime] = noop freeradius | (0) [pap] = updated freeradius | (0) } # authorize = updated freeradius | (0) Found Auth-Type = PAP freeradius | (0) # Executing group from file /etc/freeradius/sites-enabled/default freeradius | (0) Auth-Type PAP { freeradius | (0) pap: Login attempt with password freeradius | (0) pap: Comparing with "known good" Cleartext-Password freeradius | (0) pap: User authenticated successfully freeradius | (0) [pap] = ok freeradius | (0) } # Auth-Type PAP = ok freeradius | (0) # Executing section post-auth from file /etc/freeradius/sites-enabled/default freeradius | (0) post-auth { freeradius | (0) update { freeradius | (0) No attributes updated freeradius | (0) } # update = noop freeradius | (0) sql: EXPAND .query freeradius | (0) sql: --> .query freeradius | (0) sql: Using query template 'query' freeradius | rlm_sql (sql): Reserved connection (6) freeradius | (0) sql: EXPAND %{User-Name} freeradius | (0) sql: --> 12347@@TM11 freeradius | (0) sql: SQL-User-Name set to '12347@@TM11' freeradius | (0) sql: EXPAND INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') freeradius | (0) sql: --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '12347@@TM11', 'b3957233dd5294cbf47d95fb3f584239', 'Access-Accept', '2019-03-15 13:18:27') freeradius | (0) sql: Executing query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '12347@@TM11', 'b3957233dd5294cbf47d95fb3f584239', 'Access-Accept', '2019-03-15 13:18:27') freeradius | (0) sql: SQL query returned: success freeradius | (0) sql: 1 record(s) updated freeradius | rlm_sql (sql): Released connection (6) freeradius | (0) [sql] = ok freeradius | (0) [exec] = noop freeradius | (0) policy remove_reply_message_if_eap { freeradius | (0) if (&reply:EAP-Message && &reply:Reply-Message) { freeradius | (0) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE freeradius | (0) else { freeradius | (0) [noop] = noop freeradius | (0) } # else = noop freeradius | (0) } # policy remove_reply_message_if_eap = noop freeradius | (0) } # post-auth = ok freeradius | (0) Sent Access-Accept Id 153 from 172.25.0.101:1812 to 192.168.0.4:47212 length 0 freeradius | (0) Finished request freeradius | Waking up in 4.9 seconds. freeradius | (0) Cleaning up request packet ID 153 with timestamp +305 freeradius | Ready to process requests please help me on this. thanks in advance.
On Mar 15, 2019, at 9:41 AM, Somanath Mishra <somanath.mishra@planetsbrain.com> wrote:
Hi Team, i facing one problem in accounting part. So after authrization accounting part is not starting. i am getting data in radpostauth "Accept-Accept" ,but in radacct there is no data.
This is in the FAQ. The NAS isn't sending accounting packets. So... fix the NAS to send accounting packets. No amount of poking FreeRADIUS will make the NAS send accounting packets. Alan DeKok.
This is in the FAQ.
The NAS isn't sending accounting packets. So... fix the NAS to send accounting packets.
No amount of poking FreeRADIUS will make the NAS send accounting packets.
Alan DeKok.
Thanks for the help. It worked for me after modified ip in controller. but still radacct table not coming due to "Incorrect datetime value: '1552660521' for column 'acctstarttime' at row 1". is it due to server date time is different form client?Please help. here are debug logs: freeradius | (0) Received Access-Request Id 169 from 192.168.0.4:47212 to 172.25.0.101:1812 length 182 freeradius | (0) Service-Type = Login-User freeradius | (0) Framed-MTU = 1250 freeradius | (0) User-Name = "12378@@TM11" freeradius | (0) User-Password = "55587a910882016321201e6ebbc9f595" freeradius | (0) Calling-Station-Id = "9c:4e:36:9c:71:18" freeradius | (0) Called-Station-Id = "00:0c:29:67:6d:ec" freeradius | (0) Connect-Info = "CONNECT Unknown Radio" freeradius | (0) Framed-IP-Address = 10.0.1.24 freeradius | (0) NAS-IP-Address = 192.168.0.4 freeradius | (0) NAS-Port-Type = Wireless-802.11 freeradius | (0) NAS-Port = 0 freeradius | (0) Message-Authenticator = 0x6216234be27c84e63e635425868cbca5 freeradius | (0) # Executing section authorize from file /etc/freeradius/sites-enabled/default freeradius | (0) authorize { freeradius | (0) policy filter_username { freeradius | (0) if (&User-Name) { freeradius | (0) if (&User-Name) -> TRUE freeradius | (0) if (&User-Name) { freeradius | (0) if (&User-Name =~ / /) { freeradius | (0) if (&User-Name =~ / /) -> FALSE freeradius | (0) if (&User-Name =~ /\.\./ ) { freeradius | (0) if (&User-Name =~ /\.\./ ) -> FALSE freeradius | (0) if (&User-Name =~ /\.$/) { freeradius | (0) if (&User-Name =~ /\.$/) -> FALSE freeradius | (0) if (&User-Name =~ /@\./) { freeradius | (0) if (&User-Name =~ /@\./) -> FALSE freeradius | (0) } # if (&User-Name) = notfound freeradius | (0) } # policy filter_username = notfound freeradius | (0) [preprocess] = ok freeradius | (0) [chap] = noop freeradius | (0) [mschap] = noop freeradius | (0) [digest] = noop freeradius | (0) suffix: Checking for suffix after "@" freeradius | (0) suffix: Looking up realm "TM11" for User-Name = "12378@@TM11" freeradius | (0) suffix: No such realm "TM11" freeradius | (0) [suffix] = noop freeradius | (0) eap: No EAP-Message, not doing EAP freeradius | (0) [eap] = noop freeradius | (0) [files] = noop freeradius | (0) sql: EXPAND %{User-Name} freeradius | (0) sql: --> 12378@@TM11 freeradius | (0) sql: SQL-User-Name set to '12378@@TM11' freeradius | rlm_sql (sql): Closing connection (1): Hit idle_timeout, was idle for 68 seconds freeradius | rlm_sql_mysql: Socket destructor called, closing socket freeradius | rlm_sql (sql): Closing connection (2): Hit idle_timeout, was idle for 68 seconds freeradius | rlm_sql_mysql: Socket destructor called, closing socket freeradius | rlm_sql (sql): Closing connection (3): Hit idle_timeout, was idle for 68 seconds freeradius | rlm_sql_mysql: Socket destructor called, closing socket freeradius | rlm_sql (sql): Closing connection (4): Hit idle_timeout, was idle for 68 seconds freeradius | rlm_sql (sql): You probably need to lower "min" freeradius | rlm_sql_mysql: Socket destructor called, closing socket freeradius | rlm_sql (sql): Closing connection (0): Hit idle_timeout, was idle for 68 seconds freeradius | rlm_sql (sql): You probably need to lower "min" freeradius | rlm_sql_mysql: Socket destructor called, closing socket freeradius | rlm_sql (sql): Closing connection (5): Hit idle_timeout, was idle for 68 seconds freeradius | rlm_sql (sql): You probably need to lower "min" freeradius | rlm_sql_mysql: Socket destructor called, closing socket freeradius | rlm_sql (sql): 0 of 0 connections in use. You may need to increase "spare" freeradius | rlm_sql (sql): Opening additional connection (6), 1 of 32 pending slots used freeradius | rlm_sql_mysql: Starting connect to MySQL server freeradius | rlm_sql_mysql: Connected to database 'radius' on 172.25.0.100 via TCP/IP, server version 5.7.25, protocol version 10 freeradius | rlm_sql (sql): Reserved connection (6) freeradius | (0) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id freeradius | (0) sql: --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = '12378@@TM11' ORDER BY id freeradius | (0) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '12378@@TM11' ORDER BY id freeradius | (0) sql: User found in radcheck table freeradius | (0) sql: Conditional check items matched, merging assignment check items freeradius | (0) sql: Cleartext-Password := "55587a910882016321201e6ebbc9f595" freeradius | (0) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id freeradius | (0) sql: --> SELECT id, username, attribute, value, op FROM radreply WHERE username = '12378@@TM11' ORDER BY id freeradius | (0) sql: Executing select query: SELECT id, username, attribute, value, op FROM radreply WHERE username = '12378@@TM11' ORDER BY id freeradius | (0) sql: EXPAND SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority freeradius | (0) sql: --> SELECT groupname FROM radusergroup WHERE username = '12378@@TM11' ORDER BY priority freeradius | (0) sql: Executing select query: SELECT groupname FROM radusergroup WHERE username = '12378@@TM11' ORDER BY priority freeradius | (0) sql: User found in the group table freeradius | (0) sql: EXPAND SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id freeradius | (0) sql: --> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'allowall' ORDER BY id freeradius | (0) sql: Executing select query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'allowall' ORDER BY id freeradius | (0) sql: Group "allowall": Conditional check items matched freeradius | (0) sql: Group "allowall": Merging assignment check items freeradius | (0) sql: Framed-Protocol := 0 freeradius | (0) sql: EXPAND SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id freeradius | (0) sql: --> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'allowall' ORDER BY id freeradius | (0) sql: Executing select query: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'allowall' ORDER BY id freeradius | (0) sql: Group "allowall": Merging reply items freeradius | rlm_sql (sql): Released connection (6) freeradius | Need 2 more connections to reach min connections (3) freeradius | rlm_sql (sql): Opening additional connection (7), 1 of 31 pending slots used freeradius | rlm_sql_mysql: Starting connect to MySQL server freeradius | rlm_sql_mysql: Connected to database 'radius' on 172.25.0.100 via TCP/IP, server version 5.7.25, protocol version 10 freeradius | (0) [sql] = ok freeradius | (0) [expiration] = noop freeradius | (0) [logintime] = noop freeradius | (0) [pap] = updated freeradius | (0) } # authorize = updated freeradius | (0) Found Auth-Type = PAP freeradius | (0) # Executing group from file /etc/freeradius/sites-enabled/default freeradius | (0) Auth-Type PAP { freeradius | (0) pap: Login attempt with password freeradius | (0) pap: Comparing with "known good" Cleartext-Password freeradius | (0) pap: User authenticated successfully freeradius | (0) [pap] = ok freeradius | (0) } # Auth-Type PAP = ok freeradius | (0) # Executing section post-auth from file /etc/freeradius/sites-enabled/default freeradius | (0) post-auth { freeradius | (0) update { freeradius | (0) No attributes updated freeradius | (0) } # update = noop freeradius | (0) sql: EXPAND .query freeradius | (0) sql: --> .query freeradius | (0) sql: Using query template 'query' freeradius | rlm_sql (sql): Reserved connection (6) freeradius | (0) sql: EXPAND %{User-Name} freeradius | (0) sql: --> 12378@@TM11 freeradius | (0) sql: SQL-User-Name set to '12378@@TM11' freeradius | (0) sql: EXPAND INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') freeradius | (0) sql: --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '12378@@TM11', '55587a910882016321201e6ebbc9f595', 'Access-Accept', '2019-03-15 14:35:17') freeradius | (0) sql: Executing query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '12378@@TM11', '55587a910882016321201e6ebbc9f595', 'Access-Accept', '2019-03-15 14:35:17') freeradius | (0) sql: SQL query returned: success freeradius | (0) sql: 1 record(s) updated freeradius | rlm_sql (sql): Released connection (6) freeradius | (0) [sql] = ok freeradius | (0) [exec] = noop freeradius | (0) policy remove_reply_message_if_eap { freeradius | (0) if (&reply:EAP-Message && &reply:Reply-Message) { freeradius | (0) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE freeradius | (0) else { freeradius | (0) [noop] = noop freeradius | (0) } # else = noop freeradius | (0) } # policy remove_reply_message_if_eap = noop freeradius | (0) } # post-auth = ok freeradius | (0) Sent Access-Accept Id 169 from 172.25.0.101:1812 to 192.168.0.4:47212 length 0 freeradius | (0) Finished request freeradius | Waking up in 4.9 seconds. freeradius | (1) Received Accounting-Request Id 170 from 192.168.0.4:45646 to 172.25.0.101:1813 length 215 freeradius | (1) Acct-Status-Type = Start freeradius | (1) Acct-Session-Id = "1801000A-0001122B" freeradius | (1) Acct-Authentic = RADIUS freeradius | (1) User-Name = "12378@@TM11" freeradius | (1) Calling-Station-Id = "9c:4e:36:9c:71:18" freeradius | (1) Called-Station-Id = "00:0c:29:67:6d:ec" freeradius | (1) Connect-Info = "CONNECT Unknown Radio" freeradius | (1) NAS-Identifier = "00:0c:29:67:6d:ec" freeradius | (1) Meru-Access-Point-Id = 10 freeradius | (1) Meru-Access-Point-Name = "Bangalore" freeradius | (1) Attr-26.15983.3 = 0x0a000118 freeradius | (1) Framed-IP-Address = 10.0.1.24 freeradius | (1) NAS-IP-Address = 192.168.0.4 freeradius | (1) NAS-Port-Type = Wireless-802.11 freeradius | (1) NAS-Port = 0 freeradius | (1) Acct-Delay-Time = 0 freeradius | (1) # Executing section preacct from file /etc/freeradius/sites-enabled/default freeradius | (1) preacct { freeradius | (1) [preprocess] = ok freeradius | (1) policy acct_unique { freeradius | (1) update request { freeradius | (1) &Tmp-String-9 := "ai:" freeradius | (1) } # update request = noop freeradius | (1) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) { freeradius | (1) EXPAND %{hex:&Class} freeradius | (1) --> freeradius | (1) EXPAND ^%{hex:&Tmp-String-9} freeradius | (1) --> ^61693a freeradius | (1) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) -> FALSE freeradius | (1) else { freeradius | (1) update request { freeradius | (1) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} freeradius | (1) --> d99b6270bc08322e50fc1284c175858d freeradius | (1) &Acct-Unique-Session-Id := d99b6270bc08322e50fc1284c175858d freeradius | (1) } # update request = noop freeradius | (1) } # else = noop freeradius | (1) } # policy acct_unique = noop freeradius | (1) suffix: Checking for suffix after "@" freeradius | (1) suffix: Looking up realm "TM11" for User-Name = "12378@@TM11" freeradius | (1) suffix: No such realm "TM11" freeradius | (1) [suffix] = noop freeradius | (1) [files] = noop freeradius | (1) } # preacct = ok freeradius | (1) # Executing section accounting from file /etc/freeradius/sites-enabled/default freeradius | (1) accounting { freeradius | (1) detail: EXPAND /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d freeradius | (1) detail: --> /var/log/freeradius/radacct/192.168.0.4/detail-20190315 freeradius | (1) 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-20190315 freeradius | (1) detail: EXPAND %t freeradius | (1) detail: --> Fri Mar 15 14:35:17 2019 freeradius | (1) [detail] = ok freeradius | (1) [unix] = ok freeradius | (1) sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query} freeradius | (1) sql: --> type.start.query freeradius | (1) sql: Using query template 'query' freeradius | rlm_sql (sql): Reserved connection (7) freeradius | (1) sql: EXPAND %{User-Name} freeradius | (1) sql: --> 12378@@TM11 freeradius | (1) sql: SQL-User-Name set to '12378@@TM11' freeradius | (1) 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}') freeradius | (1) 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 ('1801000A-0001122B', 'd99b6270bc08322e50fc1284c175858d', '12378@@TM11', '', '192.168.0.4', '0', 'Wireless-802.11', 1552660517, 1552660517, NULL, '0', 'RADIUS', 'CONNECT Unknown Radio', '', '0', '0', '00:0c:29:67:6d:ec', '9c:4e:36:9c:71:18', '', '', '', '10.0.1.24') freeradius | (1) 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 ('1801000A-0001122B', 'd99b6270bc08322e50fc1284c175858d', '12378@@TM11', '', '192.168.0.4', '0', 'Wireless-802.11', 1552660517, 1552660517, NULL, '0', 'RADIUS', 'CONNECT Unknown Radio', '', '0', '0', '00:0c:29:67:6d:ec', '9c:4e:36:9c:71:18', '', '', '', '10.0.1.24') freeradius | (1) sql: ERROR: rlm_sql_mysql: ERROR 1292 (Incorrect datetime value: '1552660517' for column 'acctstarttime' at row 1): 22007 freeradius | (1) sql: SQL query returned: server error freeradius | rlm_sql (sql): Released connection (7) freeradius | (1) [sql] = fail freeradius | (1) } # accounting = fail freeradius | (1) Not sending reply to client. freeradius | (1) Finished request freeradius | (1) Cleaning up request packet ID 170 with timestamp +68 freeradius | Waking up in 4.9 seconds. freeradius | (2) Received Accounting-Request Id 170 from 192.168.0.4:45646 to 172.25.0.101:1813 length 215 freeradius | (2) Acct-Status-Type = Start freeradius | (2) Acct-Session-Id = "1801000A-0001122B" freeradius | (2) Acct-Authentic = RADIUS freeradius | (2) User-Name = "12378@@TM11" freeradius | (2) Calling-Station-Id = "9c:4e:36:9c:71:18" freeradius | (2) Called-Station-Id = "00:0c:29:67:6d:ec" freeradius | (2) Connect-Info = "CONNECT Unknown Radio" freeradius | (2) NAS-Identifier = "00:0c:29:67:6d:ec" freeradius | (2) Meru-Access-Point-Id = 10 freeradius | (2) Meru-Access-Point-Name = "Bangalore" freeradius | (2) Attr-26.15983.3 = 0x0a000118 freeradius | (2) Framed-IP-Address = 10.0.1.24 freeradius | (2) NAS-IP-Address = 192.168.0.4 freeradius | (2) NAS-Port-Type = Wireless-802.11 freeradius | (2) NAS-Port = 0 freeradius | (2) Acct-Delay-Time = 0 freeradius | (2) # Executing section preacct from file /etc/freeradius/sites-enabled/default freeradius | (2) preacct { freeradius | (2) [preprocess] = ok freeradius | (2) policy acct_unique { freeradius | (2) update request { freeradius | (2) &Tmp-String-9 := "ai:" freeradius | (2) } # update request = noop freeradius | (2) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) { freeradius | (2) EXPAND %{hex:&Class} freeradius | (2) --> freeradius | (2) EXPAND ^%{hex:&Tmp-String-9} freeradius | (2) --> ^61693a freeradius | (2) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) -> FALSE freeradius | (2) else { freeradius | (2) update request { freeradius | (2) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} freeradius | (2) --> d99b6270bc08322e50fc1284c175858d freeradius | (2) &Acct-Unique-Session-Id := d99b6270bc08322e50fc1284c175858d freeradius | (2) } # update request = noop freeradius | (2) } # else = noop freeradius | (2) } # policy acct_unique = noop freeradius | (2) suffix: Checking for suffix after "@" freeradius | (2) suffix: Looking up realm "TM11" for User-Name = "12378@@TM11" freeradius | (2) suffix: No such realm "TM11" freeradius | (2) [suffix] = noop freeradius | (2) [files] = noop freeradius | (2) } # preacct = ok freeradius | (2) # Executing section accounting from file /etc/freeradius/sites-enabled/default freeradius | (2) accounting { freeradius | (2) detail: EXPAND /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d freeradius | (2) detail: --> /var/log/freeradius/radacct/192.168.0.4/detail-20190315 freeradius | (2) 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-20190315 freeradius | (2) detail: EXPAND %t freeradius | (2) detail: --> Fri Mar 15 14:35:19 2019 freeradius | (2) [detail] = ok freeradius | (2) [unix] = ok freeradius | (2) sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query} freeradius | (2) sql: --> type.start.query freeradius | (2) sql: Using query template 'query' freeradius | rlm_sql (sql): Reserved connection (6) freeradius | (2) sql: EXPAND %{User-Name} freeradius | (2) sql: --> 12378@@TM11 freeradius | (2) sql: SQL-User-Name set to '12378@@TM11' freeradius | (2) 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}') freeradius | (2) 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 ('1801000A-0001122B', 'd99b6270bc08322e50fc1284c175858d', '12378@@TM11', '', '192.168.0.4', '0', 'Wireless-802.11', 1552660519, 1552660519, NULL, '0', 'RADIUS', 'CONNECT Unknown Radio', '', '0', '0', '00:0c:29:67:6d:ec', '9c:4e:36:9c:71:18', '', '', '', '10.0.1.24') freeradius | (2) 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 ('1801000A-0001122B', 'd99b6270bc08322e50fc1284c175858d', '12378@@TM11', '', '192.168.0.4', '0', 'Wireless-802.11', 1552660519, 1552660519, NULL, '0', 'RADIUS', 'CONNECT Unknown Radio', '', '0', '0', '00:0c:29:67:6d:ec', '9c:4e:36:9c:71:18', '', '', '', '10.0.1.24') freeradius | (2) sql: ERROR: rlm_sql_mysql: ERROR 1292 (Incorrect datetime value: '1552660519' for column 'acctstarttime' at row 1): 22007 freeradius | (2) sql: SQL query returned: server error freeradius | rlm_sql (sql): Released connection (6) freeradius | Need 1 more connections to reach min connections (3) freeradius | rlm_sql (sql): Opening additional connection (8), 1 of 30 pending slots used freeradius | rlm_sql_mysql: Starting connect to MySQL server freeradius | rlm_sql_mysql: Connected to database 'radius' on 172.25.0.100 via TCP/IP, server version 5.7.25, protocol version 10 freeradius | (2) [sql] = fail freeradius | (2) } # accounting = fail freeradius | (2) Not sending reply to client. freeradius | (2) Finished request freeradius | (2) Cleaning up request packet ID 170 with timestamp +70 freeradius | Waking up in 2.9 seconds. freeradius | (3) Received Accounting-Request Id 170 from 192.168.0.4:45646 to 172.25.0.101:1813 length 215 freeradius | (3) Acct-Status-Type = Start freeradius | (3) Acct-Session-Id = "1801000A-0001122B" freeradius | (3) Acct-Authentic = RADIUS freeradius | (3) User-Name = "12378@@TM11" freeradius | (3) Calling-Station-Id = "9c:4e:36:9c:71:18" freeradius | (3) Called-Station-Id = "00:0c:29:67:6d:ec" freeradius | (3) Connect-Info = "CONNECT Unknown Radio" freeradius | (3) NAS-Identifier = "00:0c:29:67:6d:ec" freeradius | (3) Meru-Access-Point-Id = 10 freeradius | (3) Meru-Access-Point-Name = "Bangalore" freeradius | (3) Attr-26.15983.3 = 0x0a000118 freeradius | (3) Framed-IP-Address = 10.0.1.24 freeradius | (3) NAS-IP-Address = 192.168.0.4 freeradius | (3) NAS-Port-Type = Wireless-802.11 freeradius | (3) NAS-Port = 0 freeradius | (3) Acct-Delay-Time = 0 freeradius | (3) # Executing section preacct from file /etc/freeradius/sites-enabled/default freeradius | (3) preacct { freeradius | (3) [preprocess] = ok freeradius | (3) policy acct_unique { freeradius | (3) update request { freeradius | (3) &Tmp-String-9 := "ai:" freeradius | (3) } # update request = noop freeradius | (3) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) { freeradius | (3) EXPAND %{hex:&Class} freeradius | (3) --> freeradius | (3) EXPAND ^%{hex:&Tmp-String-9} freeradius | (3) --> ^61693a freeradius | (3) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) -> FALSE freeradius | (3) else { freeradius | (3) update request { freeradius | (3) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} freeradius | (3) --> d99b6270bc08322e50fc1284c175858d freeradius | (3) &Acct-Unique-Session-Id := d99b6270bc08322e50fc1284c175858d freeradius | (3) } # update request = noop freeradius | (3) } # else = noop freeradius | (3) } # policy acct_unique = noop freeradius | (3) suffix: Checking for suffix after "@" freeradius | (3) suffix: Looking up realm "TM11" for User-Name = "12378@@TM11" freeradius | (3) suffix: No such realm "TM11" freeradius | (3) [suffix] = noop freeradius | (3) [files] = noop freeradius | (3) } # preacct = ok freeradius | (3) # Executing section accounting from file /etc/freeradius/sites-enabled/default freeradius | (3) accounting { freeradius | (3) detail: EXPAND /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d freeradius | (3) detail: --> /var/log/freeradius/radacct/192.168.0.4/detail-20190315 freeradius | (3) 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-20190315 freeradius | (3) detail: EXPAND %t freeradius | (3) detail: --> Fri Mar 15 14:35:21 2019 freeradius | (3) [detail] = ok freeradius | (3) [unix] = ok freeradius | (3) sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query} freeradius | (3) sql: --> type.start.query freeradius | (3) sql: Using query template 'query' freeradius | rlm_sql (sql): Reserved connection (7) freeradius | (3) sql: EXPAND %{User-Name} freeradius | (3) sql: --> 12378@@TM11 freeradius | (3) sql: SQL-User-Name set to '12378@@TM11' freeradius | (3) 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}') freeradius | (3) 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 ('1801000A-0001122B', 'd99b6270bc08322e50fc1284c175858d', '12378@@TM11', '', '192.168.0.4', '0', 'Wireless-802.11', 1552660521, 1552660521, NULL, '0', 'RADIUS', 'CONNECT Unknown Radio', '', '0', '0', '00:0c:29:67:6d:ec', '9c:4e:36:9c:71:18', '', '', '', '10.0.1.24') freeradius | (3) 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 ('1801000A-0001122B', 'd99b6270bc08322e50fc1284c175858d', '12378@@TM11', '', '192.168.0.4', '0', 'Wireless-802.11', 1552660521, 1552660521, NULL, '0', 'RADIUS', 'CONNECT Unknown Radio', '', '0', '0', '00:0c:29:67:6d:ec', '9c:4e:36:9c:71:18', '', '', '', '10.0.1.24') freeradius | (3) sql: ERROR: rlm_sql_mysql: ERROR 1292 (Incorrect datetime value: '1552660521' for column 'acctstarttime' at row 1): 22007 freeradius | (3) sql: SQL query returned: server error freeradius | rlm_sql (sql): Released connection (7) freeradius | Need 7 more connections to reach 10 spares freeradius | rlm_sql (sql): Opening additional connection (9), 1 of 29 pending slots used freeradius | rlm_sql_mysql: Starting connect to MySQL server freeradius | rlm_sql_mysql: Connected to database 'radius' on 172.25.0.100 via TCP/IP, server version 5.7.25, protocol version 10 freeradius | (3) [sql] = fail freeradius | (3) } # accounting = fail freeradius | (3) Not sending reply to client. freeradius | (3) Finished request freeradius | (3) Cleaning up request packet ID 170 with timestamp +72 freeradius | Waking up in 0.9 seconds. freeradius | (0) Cleaning up request packet ID 169 with timestamp +68 freeradius | Ready to process requests
The NAS isn't sending accounting packets. So... fix the NAS to send accounting packets.
No amount of poking FreeRADIUS will make the NAS send accounting packets.
Alan DeKok.
Many thanks for the suggestion.after modified radius IP in controller it worked. but still not getting data in radaact table.showing error like "Incorrect datetime value: '1552660521' for column 'acctstarttime' at row 1". Please help. here are the logs: freeradius | (0) Received Access-Request Id 169 from 192.168.0.4:47212 to 172.25.0.101:1812 length 182 freeradius | (0) Service-Type = Login-User freeradius | (0) Framed-MTU = 1250 freeradius | (0) User-Name = "12378@@TM11" freeradius | (0) User-Password = "55587a910882016321201e6ebbc9f595" freeradius | (0) Calling-Station-Id = "9c:4e:36:9c:71:18" freeradius | (0) Called-Station-Id = "00:0c:29:67:6d:ec" freeradius | (0) Connect-Info = "CONNECT Unknown Radio" freeradius | (0) Framed-IP-Address = 10.0.1.24 freeradius | (0) NAS-IP-Address = 192.168.0.4 freeradius | (0) NAS-Port-Type = Wireless-802.11 freeradius | (0) NAS-Port = 0 freeradius | (0) Message-Authenticator = 0x6216234be27c84e63e635425868cbca5 freeradius | (0) # Executing section authorize from file /etc/freeradius/sites-enabled/default freeradius | (0) authorize { freeradius | (0) policy filter_username { freeradius | (0) if (&User-Name) { freeradius | (0) if (&User-Name) -> TRUE freeradius | (0) if (&User-Name) { freeradius | (0) if (&User-Name =~ / /) { freeradius | (0) if (&User-Name =~ / /) -> FALSE freeradius | (0) if (&User-Name =~ /\.\./ ) { freeradius | (0) if (&User-Name =~ /\.\./ ) -> FALSE freeradius | (0) if (&User-Name =~ /\.$/) { freeradius | (0) if (&User-Name =~ /\.$/) -> FALSE freeradius | (0) if (&User-Name =~ /@\./) { freeradius | (0) if (&User-Name =~ /@\./) -> FALSE freeradius | (0) } # if (&User-Name) = notfound freeradius | (0) } # policy filter_username = notfound freeradius | (0) [preprocess] = ok freeradius | (0) [chap] = noop freeradius | (0) [mschap] = noop freeradius | (0) [digest] = noop freeradius | (0) suffix: Checking for suffix after "@" freeradius | (0) suffix: Looking up realm "TM11" for User-Name = "12378@@TM11" freeradius | (0) suffix: No such realm "TM11" freeradius | (0) [suffix] = noop freeradius | (0) eap: No EAP-Message, not doing EAP freeradius | (0) [eap] = noop freeradius | (0) [files] = noop freeradius | (0) sql: EXPAND %{User-Name} freeradius | (0) sql: --> 12378@@TM11 freeradius | (0) sql: SQL-User-Name set to '12378@@TM11' freeradius | rlm_sql (sql): Closing connection (1): Hit idle_timeout, was idle for 68 seconds freeradius | rlm_sql_mysql: Socket destructor called, closing socket freeradius | rlm_sql (sql): Closing connection (2): Hit idle_timeout, was idle for 68 seconds freeradius | rlm_sql_mysql: Socket destructor called, closing socket freeradius | rlm_sql (sql): Closing connection (3): Hit idle_timeout, was idle for 68 seconds freeradius | rlm_sql_mysql: Socket destructor called, closing socket freeradius | rlm_sql (sql): Closing connection (4): Hit idle_timeout, was idle for 68 seconds freeradius | rlm_sql (sql): You probably need to lower "min" freeradius | rlm_sql_mysql: Socket destructor called, closing socket freeradius | rlm_sql (sql): Closing connection (0): Hit idle_timeout, was idle for 68 seconds freeradius | rlm_sql (sql): You probably need to lower "min" freeradius | rlm_sql_mysql: Socket destructor called, closing socket freeradius | rlm_sql (sql): Closing connection (5): Hit idle_timeout, was idle for 68 seconds freeradius | rlm_sql (sql): You probably need to lower "min" freeradius | rlm_sql_mysql: Socket destructor called, closing socket freeradius | rlm_sql (sql): 0 of 0 connections in use. You may need to increase "spare" freeradius | rlm_sql (sql): Opening additional connection (6), 1 of 32 pending slots used freeradius | rlm_sql_mysql: Starting connect to MySQL server freeradius | rlm_sql_mysql: Connected to database 'radius' on 172.25.0.100 via TCP/IP, server version 5.7.25, protocol version 10 freeradius | rlm_sql (sql): Reserved connection (6) freeradius | (0) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id freeradius | (0) sql: --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = '12378@@TM11' ORDER BY id freeradius | (0) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '12378@@TM11' ORDER BY id freeradius | (0) sql: User found in radcheck table freeradius | (0) sql: Conditional check items matched, merging assignment check items freeradius | (0) sql: Cleartext-Password := "55587a910882016321201e6ebbc9f595" freeradius | (0) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id freeradius | (0) sql: --> SELECT id, username, attribute, value, op FROM radreply WHERE username = '12378@@TM11' ORDER BY id freeradius | (0) sql: Executing select query: SELECT id, username, attribute, value, op FROM radreply WHERE username = '12378@@TM11' ORDER BY id freeradius | (0) sql: EXPAND SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority freeradius | (0) sql: --> SELECT groupname FROM radusergroup WHERE username = '12378@@TM11' ORDER BY priority freeradius | (0) sql: Executing select query: SELECT groupname FROM radusergroup WHERE username = '12378@@TM11' ORDER BY priority freeradius | (0) sql: User found in the group table freeradius | (0) sql: EXPAND SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id freeradius | (0) sql: --> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'allowall' ORDER BY id freeradius | (0) sql: Executing select query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'allowall' ORDER BY id freeradius | (0) sql: Group "allowall": Conditional check items matched freeradius | (0) sql: Group "allowall": Merging assignment check items freeradius | (0) sql: Framed-Protocol := 0 freeradius | (0) sql: EXPAND SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id freeradius | (0) sql: --> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'allowall' ORDER BY id freeradius | (0) sql: Executing select query: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'allowall' ORDER BY id freeradius | (0) sql: Group "allowall": Merging reply items freeradius | rlm_sql (sql): Released connection (6) freeradius | Need 2 more connections to reach min connections (3) freeradius | rlm_sql (sql): Opening additional connection (7), 1 of 31 pending slots used freeradius | rlm_sql_mysql: Starting connect to MySQL server freeradius | rlm_sql_mysql: Connected to database 'radius' on 172.25.0.100 via TCP/IP, server version 5.7.25, protocol version 10 freeradius | (0) [sql] = ok freeradius | (0) [expiration] = noop freeradius | (0) [logintime] = noop freeradius | (0) [pap] = updated freeradius | (0) } # authorize = updated freeradius | (0) Found Auth-Type = PAP freeradius | (0) # Executing group from file /etc/freeradius/sites-enabled/default freeradius | (0) Auth-Type PAP { freeradius | (0) pap: Login attempt with password freeradius | (0) pap: Comparing with "known good" Cleartext-Password freeradius | (0) pap: User authenticated successfully freeradius | (0) [pap] = ok freeradius | (0) } # Auth-Type PAP = ok freeradius | (0) # Executing section post-auth from file /etc/freeradius/sites-enabled/default freeradius | (0) post-auth { freeradius | (0) update { freeradius | (0) No attributes updated freeradius | (0) } # update = noop freeradius | (0) sql: EXPAND .query freeradius | (0) sql: --> .query freeradius | (0) sql: Using query template 'query' freeradius | rlm_sql (sql): Reserved connection (6) freeradius | (0) sql: EXPAND %{User-Name} freeradius | (0) sql: --> 12378@@TM11 freeradius | (0) sql: SQL-User-Name set to '12378@@TM11' freeradius | (0) sql: EXPAND INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') freeradius | (0) sql: --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '12378@@TM11', '55587a910882016321201e6ebbc9f595', 'Access-Accept', '2019-03-15 14:35:17') freeradius | (0) sql: Executing query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '12378@@TM11', '55587a910882016321201e6ebbc9f595', 'Access-Accept', '2019-03-15 14:35:17') freeradius | (0) sql: SQL query returned: success freeradius | (0) sql: 1 record(s) updated freeradius | rlm_sql (sql): Released connection (6) freeradius | (0) [sql] = ok freeradius | (0) [exec] = noop freeradius | (0) policy remove_reply_message_if_eap { freeradius | (0) if (&reply:EAP-Message && &reply:Reply-Message) { freeradius | (0) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE freeradius | (0) else { freeradius | (0) [noop] = noop freeradius | (0) } # else = noop freeradius | (0) } # policy remove_reply_message_if_eap = noop freeradius | (0) } # post-auth = ok freeradius | (0) Sent Access-Accept Id 169 from 172.25.0.101:1812 to 192.168.0.4:47212 length 0 freeradius | (0) Finished request freeradius | Waking up in 4.9 seconds. freeradius | (1) Received Accounting-Request Id 170 from 192.168.0.4:45646 to 172.25.0.101:1813 length 215 freeradius | (1) Acct-Status-Type = Start freeradius | (1) Acct-Session-Id = "1801000A-0001122B" freeradius | (1) Acct-Authentic = RADIUS freeradius | (1) User-Name = "12378@@TM11" freeradius | (1) Calling-Station-Id = "9c:4e:36:9c:71:18" freeradius | (1) Called-Station-Id = "00:0c:29:67:6d:ec" freeradius | (1) Connect-Info = "CONNECT Unknown Radio" freeradius | (1) NAS-Identifier = "00:0c:29:67:6d:ec" freeradius | (1) Meru-Access-Point-Id = 10 freeradius | (1) Meru-Access-Point-Name = "Bangalore" freeradius | (1) Attr-26.15983.3 = 0x0a000118 freeradius | (1) Framed-IP-Address = 10.0.1.24 freeradius | (1) NAS-IP-Address = 192.168.0.4 freeradius | (1) NAS-Port-Type = Wireless-802.11 freeradius | (1) NAS-Port = 0 freeradius | (1) Acct-Delay-Time = 0 freeradius | (1) # Executing section preacct from file /etc/freeradius/sites-enabled/default freeradius | (1) preacct { freeradius | (1) [preprocess] = ok freeradius | (1) policy acct_unique { freeradius | (1) update request { freeradius | (1) &Tmp-String-9 := "ai:" freeradius | (1) } # update request = noop freeradius | (1) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) { freeradius | (1) EXPAND %{hex:&Class} freeradius | (1) --> freeradius | (1) EXPAND ^%{hex:&Tmp-String-9} freeradius | (1) --> ^61693a freeradius | (1) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) -> FALSE freeradius | (1) else { freeradius | (1) update request { freeradius | (1) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} freeradius | (1) --> d99b6270bc08322e50fc1284c175858d freeradius | (1) &Acct-Unique-Session-Id := d99b6270bc08322e50fc1284c175858d freeradius | (1) } # update request = noop freeradius | (1) } # else = noop freeradius | (1) } # policy acct_unique = noop freeradius | (1) suffix: Checking for suffix after "@" freeradius | (1) suffix: Looking up realm "TM11" for User-Name = "12378@@TM11" freeradius | (1) suffix: No such realm "TM11" freeradius | (1) [suffix] = noop freeradius | (1) [files] = noop freeradius | (1) } # preacct = ok freeradius | (1) # Executing section accounting from file /etc/freeradius/sites-enabled/default freeradius | (1) accounting { freeradius | (1) detail: EXPAND /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d freeradius | (1) detail: --> /var/log/freeradius/radacct/192.168.0.4/detail-20190315 freeradius | (1) 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-20190315 freeradius | (1) detail: EXPAND %t freeradius | (1) detail: --> Fri Mar 15 14:35:17 2019 freeradius | (1) [detail] = ok freeradius | (1) [unix] = ok freeradius | (1) sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query} freeradius | (1) sql: --> type.start.query freeradius | (1) sql: Using query template 'query' freeradius | rlm_sql (sql): Reserved connection (7) freeradius | (1) sql: EXPAND %{User-Name} freeradius | (1) sql: --> 12378@@TM11 freeradius | (1) sql: SQL-User-Name set to '12378@@TM11' freeradius | (1) 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}') freeradius | (1) 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 ('1801000A-0001122B', 'd99b6270bc08322e50fc1284c175858d', '12378@@TM11', '', '192.168.0.4', '0', 'Wireless-802.11', 1552660517, 1552660517, NULL, '0', 'RADIUS', 'CONNECT Unknown Radio', '', '0', '0', '00:0c:29:67:6d:ec', '9c:4e:36:9c:71:18', '', '', '', '10.0.1.24') freeradius | (1) 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 ('1801000A-0001122B', 'd99b6270bc08322e50fc1284c175858d', '12378@@TM11', '', '192.168.0.4', '0', 'Wireless-802.11', 1552660517, 1552660517, NULL, '0', 'RADIUS', 'CONNECT Unknown Radio', '', '0', '0', '00:0c:29:67:6d:ec', '9c:4e:36:9c:71:18', '', '', '', '10.0.1.24') freeradius | (1) sql: ERROR: rlm_sql_mysql: ERROR 1292 (Incorrect datetime value: '1552660517' for column 'acctstarttime' at row 1): 22007 freeradius | (1) sql: SQL query returned: server error freeradius | rlm_sql (sql): Released connection (7) freeradius | (1) [sql] = fail freeradius | (1) } # accounting = fail freeradius | (1) Not sending reply to client. freeradius | (1) Finished request freeradius | (1) Cleaning up request packet ID 170 with timestamp +68 freeradius | Waking up in 4.9 seconds. freeradius | (2) Received Accounting-Request Id 170 from 192.168.0.4:45646 to 172.25.0.101:1813 length 215 freeradius | (2) Acct-Status-Type = Start freeradius | (2) Acct-Session-Id = "1801000A-0001122B" freeradius | (2) Acct-Authentic = RADIUS freeradius | (2) User-Name = "12378@@TM11" freeradius | (2) Calling-Station-Id = "9c:4e:36:9c:71:18" freeradius | (2) Called-Station-Id = "00:0c:29:67:6d:ec" freeradius | (2) Connect-Info = "CONNECT Unknown Radio" freeradius | (2) NAS-Identifier = "00:0c:29:67:6d:ec" freeradius | (2) Meru-Access-Point-Id = 10 freeradius | (2) Meru-Access-Point-Name = "Bangalore" freeradius | (2) Attr-26.15983.3 = 0x0a000118 freeradius | (2) Framed-IP-Address = 10.0.1.24 freeradius | (2) NAS-IP-Address = 192.168.0.4 freeradius | (2) NAS-Port-Type = Wireless-802.11 freeradius | (2) NAS-Port = 0 freeradius | (2) Acct-Delay-Time = 0 freeradius | (2) # Executing section preacct from file /etc/freeradius/sites-enabled/default freeradius | (2) preacct { freeradius | (2) [preprocess] = ok freeradius | (2) policy acct_unique { freeradius | (2) update request { freeradius | (2) &Tmp-String-9 := "ai:" freeradius | (2) } # update request = noop freeradius | (2) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) { freeradius | (2) EXPAND %{hex:&Class} freeradius | (2) --> freeradius | (2) EXPAND ^%{hex:&Tmp-String-9} freeradius | (2) --> ^61693a freeradius | (2) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) -> FALSE freeradius | (2) else { freeradius | (2) update request { freeradius | (2) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} freeradius | (2) --> d99b6270bc08322e50fc1284c175858d freeradius | (2) &Acct-Unique-Session-Id := d99b6270bc08322e50fc1284c175858d freeradius | (2) } # update request = noop freeradius | (2) } # else = noop freeradius | (2) } # policy acct_unique = noop freeradius | (2) suffix: Checking for suffix after "@" freeradius | (2) suffix: Looking up realm "TM11" for User-Name = "12378@@TM11" freeradius | (2) suffix: No such realm "TM11" freeradius | (2) [suffix] = noop freeradius | (2) [files] = noop freeradius | (2) } # preacct = ok freeradius | (2) # Executing section accounting from file /etc/freeradius/sites-enabled/default freeradius | (2) accounting { freeradius | (2) detail: EXPAND /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d freeradius | (2) detail: --> /var/log/freeradius/radacct/192.168.0.4/detail-20190315 freeradius | (2) 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-20190315 freeradius | (2) detail: EXPAND %t freeradius | (2) detail: --> Fri Mar 15 14:35:19 2019 freeradius | (2) [detail] = ok freeradius | (2) [unix] = ok freeradius | (2) sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query} freeradius | (2) sql: --> type.start.query freeradius | (2) sql: Using query template 'query' freeradius | rlm_sql (sql): Reserved connection (6) freeradius | (2) sql: EXPAND %{User-Name} freeradius | (2) sql: --> 12378@@TM11 freeradius | (2) sql: SQL-User-Name set to '12378@@TM11' freeradius | (2) 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}') freeradius | (2) 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 ('1801000A-0001122B', 'd99b6270bc08322e50fc1284c175858d', '12378@@TM11', '', '192.168.0.4', '0', 'Wireless-802.11', 1552660519, 1552660519, NULL, '0', 'RADIUS', 'CONNECT Unknown Radio', '', '0', '0', '00:0c:29:67:6d:ec', '9c:4e:36:9c:71:18', '', '', '', '10.0.1.24') freeradius | (2) 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 ('1801000A-0001122B', 'd99b6270bc08322e50fc1284c175858d', '12378@@TM11', '', '192.168.0.4', '0', 'Wireless-802.11', 1552660519, 1552660519, NULL, '0', 'RADIUS', 'CONNECT Unknown Radio', '', '0', '0', '00:0c:29:67:6d:ec', '9c:4e:36:9c:71:18', '', '', '', '10.0.1.24') freeradius | (2) sql: ERROR: rlm_sql_mysql: ERROR 1292 (Incorrect datetime value: '1552660519' for column 'acctstarttime' at row 1): 22007 freeradius | (2) sql: SQL query returned: server error freeradius | rlm_sql (sql): Released connection (6) freeradius | Need 1 more connections to reach min connections (3) freeradius | rlm_sql (sql): Opening additional connection (8), 1 of 30 pending slots used freeradius | rlm_sql_mysql: Starting connect to MySQL server freeradius | rlm_sql_mysql: Connected to database 'radius' on 172.25.0.100 via TCP/IP, server version 5.7.25, protocol version 10 freeradius | (2) [sql] = fail freeradius | (2) } # accounting = fail freeradius | (2) Not sending reply to client. freeradius | (2) Finished request freeradius | (2) Cleaning up request packet ID 170 with timestamp +70 freeradius | Waking up in 2.9 seconds. freeradius | (3) Received Accounting-Request Id 170 from 192.168.0.4:45646 to 172.25.0.101:1813 length 215 freeradius | (3) Acct-Status-Type = Start freeradius | (3) Acct-Session-Id = "1801000A-0001122B" freeradius | (3) Acct-Authentic = RADIUS freeradius | (3) User-Name = "12378@@TM11" freeradius | (3) Calling-Station-Id = "9c:4e:36:9c:71:18" freeradius | (3) Called-Station-Id = "00:0c:29:67:6d:ec" freeradius | (3) Connect-Info = "CONNECT Unknown Radio" freeradius | (3) NAS-Identifier = "00:0c:29:67:6d:ec" freeradius | (3) Meru-Access-Point-Id = 10 freeradius | (3) Meru-Access-Point-Name = "Bangalore" freeradius | (3) Attr-26.15983.3 = 0x0a000118 freeradius | (3) Framed-IP-Address = 10.0.1.24 freeradius | (3) NAS-IP-Address = 192.168.0.4 freeradius | (3) NAS-Port-Type = Wireless-802.11 freeradius | (3) NAS-Port = 0 freeradius | (3) Acct-Delay-Time = 0 freeradius | (3) # Executing section preacct from file /etc/freeradius/sites-enabled/default freeradius | (3) preacct { freeradius | (3) [preprocess] = ok freeradius | (3) policy acct_unique { freeradius | (3) update request { freeradius | (3) &Tmp-String-9 := "ai:" freeradius | (3) } # update request = noop freeradius | (3) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) { freeradius | (3) EXPAND %{hex:&Class} freeradius | (3) --> freeradius | (3) EXPAND ^%{hex:&Tmp-String-9} freeradius | (3) --> ^61693a freeradius | (3) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) -> FALSE freeradius | (3) else { freeradius | (3) update request { freeradius | (3) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} freeradius | (3) --> d99b6270bc08322e50fc1284c175858d freeradius | (3) &Acct-Unique-Session-Id := d99b6270bc08322e50fc1284c175858d freeradius | (3) } # update request = noop freeradius | (3) } # else = noop freeradius | (3) } # policy acct_unique = noop freeradius | (3) suffix: Checking for suffix after "@" freeradius | (3) suffix: Looking up realm "TM11" for User-Name = "12378@@TM11" freeradius | (3) suffix: No such realm "TM11" freeradius | (3) [suffix] = noop freeradius | (3) [files] = noop freeradius | (3) } # preacct = ok freeradius | (3) # Executing section accounting from file /etc/freeradius/sites-enabled/default freeradius | (3) accounting { freeradius | (3) detail: EXPAND /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d freeradius | (3) detail: --> /var/log/freeradius/radacct/192.168.0.4/detail-20190315 freeradius | (3) 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-20190315 freeradius | (3) detail: EXPAND %t freeradius | (3) detail: --> Fri Mar 15 14:35:21 2019 freeradius | (3) [detail] = ok freeradius | (3) [unix] = ok freeradius | (3) sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query} freeradius | (3) sql: --> type.start.query freeradius | (3) sql: Using query template 'query' freeradius | rlm_sql (sql): Reserved connection (7) freeradius | (3) sql: EXPAND %{User-Name} freeradius | (3) sql: --> 12378@@TM11 freeradius | (3) sql: SQL-User-Name set to '12378@@TM11' freeradius | (3) 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}') freeradius | (3) 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 ('1801000A-0001122B', 'd99b6270bc08322e50fc1284c175858d', '12378@@TM11', '', '192.168.0.4', '0', 'Wireless-802.11', 1552660521, 1552660521, NULL, '0', 'RADIUS', 'CONNECT Unknown Radio', '', '0', '0', '00:0c:29:67:6d:ec', '9c:4e:36:9c:71:18', '', '', '', '10.0.1.24') freeradius | (3) 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 ('1801000A-0001122B', 'd99b6270bc08322e50fc1284c175858d', '12378@@TM11', '', '192.168.0.4', '0', 'Wireless-802.11', 1552660521, 1552660521, NULL, '0', 'RADIUS', 'CONNECT Unknown Radio', '', '0', '0', '00:0c:29:67:6d:ec', '9c:4e:36:9c:71:18', '', '', '', '10.0.1.24') freeradius | (3) sql: ERROR: rlm_sql_mysql: ERROR 1292 (Incorrect datetime value: '1552660521' for column 'acctstarttime' at row 1): 22007 freeradius | (3) sql: SQL query returned: server error freeradius | rlm_sql (sql): Released connection (7) freeradius | Need 7 more connections to reach 10 spares freeradius | rlm_sql (sql): Opening additional connection (9), 1 of 29 pending slots used freeradius | rlm_sql_mysql: Starting connect to MySQL server freeradius | rlm_sql_mysql: Connected to database 'radius' on 172.25.0.100 via TCP/IP, server version 5.7.25, protocol version 10 freeradius | (3) [sql] = fail freeradius | (3) } # accounting = fail freeradius | (3) Not sending reply to client. freeradius | (3) Finished request freeradius | (3) Cleaning up request packet ID 170 with timestamp +72 freeradius | Waking up in 0.9 seconds. freeradius | (0) Cleaning up request packet ID 169 with timestamp +68 freeradius | Ready to process requests
On Mar 15, 2019, at 10:55 AM, Somanath Mishra <somanath.mishra@planetsbrain.com> wrote:
Many thanks for the suggestion.after modified radius IP in controller it worked. but still not getting data in radaact table.showing error like "Incorrect datetime value: '1552660521' for column 'acctstarttime' at row 1". Please help.
here are the logs:
freeradius | (0) Received Access-Request Id 169 from 192.168.0.4:47212 to 172.25.0.101:1812 length 182
Please just post the output of "radiusd -X". There's no need to add a "freeradius | " header to every line. That makes it harder to read. And only post the *relevant* logs. If you have a question about accounting, you don't need to post authentication requests.
freeradius | (1) 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 ('1801000A-0001122B', 'd99b6270bc08322e50fc1284c175858d', '12378@@TM11', '', '192.168.0.4', '0', 'Wireless-802.11', 1552660517, 1552660517, NULL, '0', 'RADIUS', 'CONNECT Unknown Radio', '', '0', '0', '00:0c:29:67:6d:ec', '9c:4e:36:9c:71:18', '', '', '', '10.0.1.24') freeradius | (1) sql: ERROR: rlm_sql_mysql: ERROR 1292 (Incorrect datetime value: '1552660517' for column 'acctstarttime' at row 1): 22007
You're either running a very old version of FreeRADIUS, or you edited the MySQL queries and broke them. The default configuration in v3 (mods-config/sql/main/mysql/queries.conf) contains: ... AcctStartTime = FROM_UNIXTIME(%{integer:Event-Timestamp}), \ ... Which works. Use the standard queries that come with FreeRADIUS. Alan DeKok.
You're either running a very old version of FreeRADIUS, or you edited the MySQL queries and broke them.
The default configuration in v3 (mods-config/sql/main/mysql/queries.conf) contains:
... AcctStartTime = FROM_UNIXTIME(%{integer:Event-Timestamp}), \ ...
Which works.
Use the standard queries that come with FreeRADIUS.
Alan DeKok.
Sorry Alan, i am using docker freeradius v3.0.16. and my (mods-config/sql/main/mysql/queries.conf) file: 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}', \ FROM_UNIXTIME(%{integer:Event-Timestamp}), \ FROM_UNIXTIME(%{integer:Event-Timestamp}), \ NULL, \ '0', \ '%{Acct-Authentic}', \ '%{Connect-Info}', \ '', \ '0', \ '0', \ '%{Called-Station-Id}', \ '%{Calling-Station-Id}', \ '', \ '%{Service-Type}', \ '%{Framed-Protocol}', \ '%{Framed-IP-Address}')" still i am facing "(Incorrect datetime value: '1552805684' for column 'acctstarttime' at row 1)" Here are debug logs: (8) sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query} freeradius | (8) sql: --> type.start.query freeradius | (8) sql: Using query template 'query' freeradius | rlm_sql (sql): Reserved connection (14) freeradius | (8) sql: EXPAND %{User-Name} freeradius | (8) sql: --> 12345@@TM11 freeradius | (8) sql: SQL-User-Name set to '12345@@TM11' freeradius | (8) 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}') freeradius | (8) 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 ('1801000A-00079105', '67d23904224156d50faf08b6890cab2e', '12345@@TM11', '', '192.168.0.4', '0', 'Wireless-802.11', 1552805682, 1552805682, NULL, '0', 'RADIUS', 'CONNECT Unknown Radio', '', '0', '0', '00:0c:29:67:6d:ec', '9c:4e:36:9c:71:18', '', '', '', '10.0.1.24') freeradius | (8) 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 ('1801000A-00079105', '67d23904224156d50faf08b6890cab2e', '12345@@TM11', '', '192.168.0.4', '0', 'Wireless-802.11', 1552805682, 1552805682, NULL, '0', 'RADIUS', 'CONNECT Unknown Radio', '', '0', '0', '00:0c:29:67:6d:ec', '9c:4e:36:9c:71:18', '', '', '', '10.0.1.24') freeradius | (8) sql: ERROR: rlm_sql_mysql: ERROR 1292 (Incorrect datetime value: '1552805682' for column 'acctstarttime' at row 1): 22007 freeradius | (8) sql: SQL query returned: server error freeradius | rlm_sql (sql): Released connection (14) Please help me.
On Sun, 2019-03-17 at 12:35 +0530, Somanath Mishra wrote:
'%{NAS-Port-Type}', \ FROM_UNIXTIME(%{integer:Event -Timestamp}), \ FROM_UNIXTIME(%{integer:Event -Timestamp}), \
...
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',
You need to find out what config file FreeRADIUS is actually using, because it's not using the one you quoted above. The query is different. -- Matthew
On Sun, March 17, 2019 7:25 pm, Matthew Newton wrote:
On Sun, 2019-03-17 at 12:35 +0530, Somanath Mishra wrote:
'%{NAS-Port-Type}', \ FROM_UNIXTIME(%{integer:Event -Timestamp}), \ FROM_UNIXTIME(%{integer:Event -Timestamp}), \
...
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',
You need to find out what config file FreeRADIUS is actually using, because it's not using the one you quoted above. The query is different.
-- Matthew
so i did fresh installation of V3.0.18 from docker hub.... still have same issue "Incorrect datetime value: '1552831358' for column 'acctstarttime' at row 1" error.. Here are Logs: freeradius | (6) sql: --> 98789@@TM11 freeradius | (6) sql: SQL-User-Name set to '98789@@TM11' freeradius | (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, framedipv6address, framedipv6prefix, framedinterfaceid, delegatedipv6prefix) 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}', '%{Framed-IPv6-Address}', '%{Framed-IPv6-Prefix}', '%{Framed-Interface-Id}', '%{Delegated-IPv6-Prefix}') freeradius | (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, framedipv6address, framedipv6prefix, framedinterfaceid, delegatedipv6prefix) VALUES ('1801000A-000B2EFA', 'a7b6b2a2756c0cca834f46639edde9bf', '98789@@TM11', '', '192.168.0.4', '0', 'Wireless-802.11', 1552831358, 1552831358, NULL, '0', 'RADIUS', 'CONNECT Unknown Radio', '', '0', '0', '00:0c:29:67:6d:ec', '9c:4e:36:9c:71:18', '', '', '', '10.0.1.24', '', '', '', '') freeradius | (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, framedipv6address, framedipv6prefix, framedinterfaceid, delegatedipv6prefix) VALUES ('1801000A-000B2EFA', 'a7b6b2a2756c0cca834f46639edde9bf', '98789@@TM11', '', '192.168.0.4', '0', 'Wireless-802.11', 1552831358, 1552831358, NULL, '0', 'RADIUS', 'CONNECT Unknown Radio', '', '0', '0', '00:0c:29:67:6d:ec', '9c:4e:36:9c:71:18', '', '', '', '10.0.1.24', '', '', '', '') freeradius | (6) sql: ERROR: rlm_sql_mysql: ERROR 1292 (Incorrect datetime value: '1552831358' for column 'acctstarttime' at row 1): 22007 freeradius | (6) sql: SQL query returned: server error freeradius | rlm_sql (sql): Released connection (10) freeradius | Need 6 more connections to reach 10 spares freeradius | rlm_sql (sql): Opening additional connection (14), 1 of 28 pending slots used freeradius | rlm_sql_mysql: Starting connect to MySQL server freeradius | rlm_sql_mysql: Connected to database 'radius' on 172.25.0.100 via TCP/IP, server version 5.7.25, protocol version 10 freeradius | (6) [sql] = fail freeradius | (6) } # accounting = fail freeradius | (6) Not sending reply to client. freeradius | (6) Finished request freeradius | (6) Cleaning up request packet ID 99 with timestamp +172 freeradius | Waking up in 0.9 seconds. freeradius | (3) Cleaning up request packet ID 97 with timestamp +168 freeradius | Ready to process requests and in queries.conf file we have : 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}', \ FROM_UNIXTIME(%{integer:Event-Timestamp}), \ FROM_UNIXTIME(%{integer: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}')" still have confusion why it is throwing error????please help...Is there any issue with docker hub freeradius server files???
On Mar 17, 2019, at 10:12 AM, Somanath Mishra <somanath.mishra@planetsbrain.com> wrote:
so i did fresh installation of V3.0.18 from docker hub....
That doesn't matter. You've clearly configured it wrong. The most likely thing is that you've configured it to use the MySQL back-end, but are using queries from some other database.
still have same issue "Incorrect datetime value: '1552831358' for column 'acctstarttime' at row 1" error..
You've said that lots. We get it.
Here are Logs:
We don't need to see the same logs posted over and over again. Stop posting them here.
and in queries.conf file we have :
WHICH queries.conf file? The point of the debug log is for you to read it. ALL OF IT. READ THE DEBUG LOG TO SEE WHICH "queries.conf" FILE IT IS LOADING. Is it loading the MySQL one? Or another one? Odds are you've configured it to read the queries from another database. Fix that. i.e. you're using the MySQL back-end, but have configured "mods-enabled/sql" to load the sqlite queries. Don't do that. And READ the files you're editing. And READ the debug output. It's all there for a good reason. If you're not reading it, then you're wasting everyones time.
still have confusion why it is throwing error????please help...
We're trying.
Is there any issue with docker hub freeradius server files???
No. There's an issue with your local configuration. Fix it. Alan DeKok.
On Sun, March 17, 2019 7:49 pm, Alan DeKok wrote:
On Mar 17, 2019, at 10:12 AM, Somanath Mishra <somanath.mishra@planetsbrain.com> wrote:
so i did fresh installation of V3.0.18 from docker hub....
That doesn't matter.
You've clearly configured it wrong.
The most likely thing is that you've configured it to use the MySQL back-end, but are using queries from some other database.
still have same issue "Incorrect datetime value: '1552831358' for column 'acctstarttime' at row 1" error..
You've said that lots. We get it.
Here are Logs:
We don't need to see the same logs posted over and over again. Stop posting them here.
and in queries.conf file we have :
WHICH queries.conf file?
The point of the debug log is for you to read it. ALL OF IT.
READ THE DEBUG LOG TO SEE WHICH "queries.conf" FILE IT IS LOADING.
Is it loading the MySQL one? Or another one? Odds are you've configured it to read the queries from another database. Fix that.
i.e. you're using the MySQL back-end, but have configured "mods-enabled/sql" to load the sqlite queries.
To enable the sql module we are creating link from mods-available/sql to mods-enabled/sql....and this sql file contains mysql connection string which is another server.... and mysql radius database created from "/etc/freeradius/mods-config/sql/main/mysql/schema.sql".... so where will be the mismatch of queries??? and freeradius is talking with mysql otherwise it throws error....
Don't do that. And READ the files you're editing. And READ the debug output. It's all there for a good reason. If you're not reading it, then you're wasting everyones time.
still have confusion why it is throwing error????please help...
We're trying.
Is there any issue with docker hub freeradius server files???
No. There's an issue with your local configuration. Fix it.
Alan DeKok.
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
On Mar 17, 2019, at 10:43 AM, Somanath Mishra <somanath.mishra@planetsbrain.com> wrote:
To enable the sql module we are creating link from mods-available/sql to mods-enabled/sql....and this sql file contains mysql connection string which is another server....
and mysql radius database created from "/etc/freeradius/mods-config/sql/main/mysql/schema.sql".... so where will be the mismatch of queries???
i.e. you're not going to read my instructions, or the mods-enabled/sql file. Which means you're not going to get the problem fixed. If you have no intention of following instructions, why are you asking questions here? Alan DeKok.
participants (3)
-
Alan DeKok -
Matthew Newton -
Somanath Mishra