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