radius accounting not starting....

Somanath Mishra somanath.mishra at planetsbrain.com
Fri Mar 15 15:52:02 CET 2019


>
> 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






More information about the Freeradius-Users mailing list