RES: RES: Freeradius 3.0.20 Fresh Install not storing radacct logs in mysql table radacct
Pedro Daniel Costa
portalnet2 at outlook.com.br
Sat Sep 3 15:42:38 UTC 2022
Hi Jonathan, Matthew and all the other guys helping me on this subject..
first of all let me thank you all for your patience in trying to explain the newbie here..
in fact it was a (router device mikrotik config failure i had left accounting enabled on it.. but the update somehow was set to update every 5days instead of every 5minutes.. i would never figured it out if untill i double checked it again..
ok so i have gone one step further, now i can see the radacct update-interim sending data on the log, but its giving update sql fail.. log below described.. but looks like its something related to the nas port id.. which has a name of my vlan port looks like its too long i will try to set it something else and do a new check.
Ready to process requests
(0) Received Accounting-Request Id 195 from 10.5.5.17:50610 to 10.5.5.200:1813 length 61
(0) Acct-Status-Type = Accounting-On
(0) NAS-Identifier = "ROUTER P0NT4L PPP0E 2"
(0) Acct-Delay-Time = 0
(0) NAS-IP-Address = 10.5.5.17
(0) # Executing section preacct from file /etc/freeradius/3.0/sites-enabled/default
(0) preacct {
(0) policy acct_unique {
(0) update request {
(0) &Tmp-String-9 := "ai:"
(0) } # update request = noop
(0) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) {
(0) EXPAND %{hex:&Class}
(0) -->
(0) EXPAND ^%{hex:&Tmp-String-9}
(0) --> ^61693a
(0) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) -> FALSE
(0) else {
(0) update request {
(0) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}
(0) --> 12369f69a3d53cce0950d272fd455f2e
(0) &Acct-Unique-Session-Id := 12369f69a3d53cce0950d272fd455f2e
(0) } # update request = noop
(0) } # else = noop
(0) } # policy acct_unique = noop
(0) update request {
(0) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}}
(0) --> 1662219243
(0) &FreeRADIUS-Acct-Session-Start-Time = Sep 3 2022 12:34:03 -03
(0) } # update request = noop
(0) } # preacct = noop
(0) # Executing section accounting from file /etc/freeradius/3.0/sites-enabled/default
(0) accounting {
(0) sql: EXPAND %{tolower:type.%{%{Acct-Status-Type}:-%{Request-Processing-Stage}}.query}
(0) sql: --> type.accounting-on.query
(0) sql: Using query template 'query'
rlm_sql (sql): Reserved connection (1)
(0) sql: EXPAND %{User-Name}
(0) sql: -->
(0) sql: SQL-User-Name set to ''
(0) sql: EXPAND UPDATE radacct SET acctstoptime = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctsessiontime = '%{integer:Event-Timestamp}' - UNIX_TIMESTAMP(acctstarttime), acctterminatecause = '%{%{Acct-Terminate-Cause}:-NAS-Reboot}' WHERE acctstoptime IS NULL AND nasipaddress = '%{NAS-IP-Address}' AND acctstarttime <= FROM_UNIXTIME(%{integer:Event-Timestamp})
(0) sql: --> UPDATE radacct SET acctstoptime = FROM_UNIXTIME(), acctsessiontime = '' - UNIX_TIMESTAMP(acctstarttime), acctterminatecause = 'NAS-Reboot' WHERE acctstoptime IS NULL AND nasipaddress = '10.5.5.17' AND acctstarttime <= FROM_UNIXTIME()
(0) sql: EXPAND /var/log/freeradius/accounting.sql
(0) sql: --> /var/log/freeradius/accounting.sql
(0) sql: Executing query: UPDATE radacct SET acctstoptime = FROM_UNIXTIME(), acctsessiontime = '' - UNIX_TIMESTAMP(acctstarttime), acctterminatecause = 'NAS-Reboot' WHERE acctstoptime IS NULL AND nasipaddress = '10.5.5.17' AND acctstarttime <= FROM_UNIXTIME()
(0) sql: ERROR: rlm_sql_mysql: ERROR 1582 (Incorrect parameter count in the call to native function 'FROM_UNIXTIME'): 42000
(0) sql: SQL query returned: server error
rlm_sql (sql): Released connection (1)
Need 4 more connections to reach 10 spares
rlm_sql (sql): Opening additional connection (6), 1 of 26 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10
(0) [sql] = fail
(0) } # accounting = fail
(0) Not sending reply to client.
(0) Finished request
(0) Cleaning up request packet ID 195 with timestamp +4
Ready to process requests
(1) Received Accounting-Request Id 196 from 10.5.5.17:43765 to 10.5.5.200:1813 length 284
(1) Service-Type = Framed-User
(1) Framed-Protocol = PPP
(1) NAS-Port = 15751564
(1) NAS-Port-Type = Ethernet
(1) User-Name = "ispteste200"
(1) Calling-Station-Id = "80:8F:E8:F2:73:DB"
(1) Called-Station-Id = "PPPOE-FIBRA"
(1) NAS-Port-Id = "VLAN1250 - FIBRA PPPOE-PONTAL"
(1) Acct-Session-Id = "81e05982"
(1) Framed-IP-Address = 100.64.20.144
(1) Acct-Authentic = RADIUS
(1) Event-Timestamp = "Sep 2 2022 13:16:17 -03"
(1) Acct-Session-Time = 54
(1) Idle-Timeout = 0
(1) Session-Timeout = 0
(1) X-Ascend-Data-Rate = 500000000
(1) Ascend-Xmit-Rate = 500000000
(1) Mikrotik-Rate-Limit = "500M/500M"
(1) Acct-Input-Octets = 6451
(1) Acct-Input-Gigawords = 0
(1) Acct-Input-Packets = 58
(1) Acct-Output-Octets = 11266
(1) Acct-Output-Gigawords = 0
(1) Acct-Output-Packets = 55
(1) Acct-Status-Type = Stop
(1) Acct-Terminate-Cause = User-Request
(1) NAS-Identifier = "ROUTER P0NT4L PPP0E 2"
(1) Acct-Delay-Time = 0
(1) NAS-IP-Address = 10.5.5.17
(1) # Executing section preacct from file /etc/freeradius/3.0/sites-enabled/default
(1) preacct {
(1) policy acct_unique {
(1) update request {
(1) &Tmp-String-9 := "ai:"
(1) } # update request = noop
(1) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) {
(1) EXPAND %{hex:&Class}
(1) -->
(1) EXPAND ^%{hex:&Tmp-String-9}
(1) --> ^61693a
(1) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) -> FALSE
(1) else {
(1) update request {
(1) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}
(1) --> 36b328d576161a68a3d1ce1db12f88a4
(1) &Acct-Unique-Session-Id := 36b328d576161a68a3d1ce1db12f88a4
(1) } # update request = noop
(1) } # else = noop
(1) } # policy acct_unique = noop
(1) update request {
(1) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}}
(1) --> 1662219189
(1) &FreeRADIUS-Acct-Session-Start-Time = Sep 3 2022 12:33:09 -03
(1) } # update request = noop
(1) } # preacct = noop
(1) # Executing section accounting from file /etc/freeradius/3.0/sites-enabled/default
(1) accounting {
(1) sql: EXPAND %{tolower:type.%{%{Acct-Status-Type}:-%{Request-Processing-Stage}}.query}
(1) sql: --> type.stop.query
(1) sql: Using query template 'query'
rlm_sql (sql): Reserved connection (2)
(1) sql: EXPAND %{User-Name}
(1) sql: --> ispteste200
(1) sql: SQL-User-Name set to 'ispteste200'
(1) sql: EXPAND UPDATE radacct SET acctstoptime = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctsessiontime = %{%{Acct-Session-Time}:-NULL}, acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', acctterminatecause = '%{Acct-Terminate-Cause}', connectinfo_stop = '%{Connect-Info}' WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}'
(1) sql: --> UPDATE radacct SET acctstoptime = FROM_UNIXTIME(1662135377), acctsessiontime = 54, acctinputoctets = '0' << 32 | '6451', acctoutputoctets = '0' << 32 | '11266', acctterminatecause = 'User-Request', connectinfo_stop = '' WHERE AcctUniqueId = '36b328d576161a68a3d1ce1db12f88a4'
(1) sql: EXPAND /var/log/freeradius/accounting.sql
(1) sql: --> /var/log/freeradius/accounting.sql
(1) sql: Executing query: UPDATE radacct SET acctstoptime = FROM_UNIXTIME(1662135377), acctsessiontime = 54, acctinputoctets = '0' << 32 | '6451', acctoutputoctets = '0' << 32 | '11266', acctterminatecause = 'User-Request', connectinfo_stop = '' WHERE AcctUniqueId = '36b328d576161a68a3d1ce1db12f88a4'
rlm_sql_mysql: Rows matched: 0 Changed: 0 Warnings: 0
(1) sql: SQL query returned: success
(1) sql: 0 record(s) updated
(1) sql: Trying next query...
(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, 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}', FROM_UNIXTIME(%{integer:Event-Timestamp} - %{%{Acct-Session-Time}:-0}), FROM_UNIXTIME(%{integer:Event-Timestamp}), FROM_UNIXTIME(%{integer:Event-Timestamp}), %{%{Acct-Session-Time}:-NULL}, '%{Acct-Authentic}', '', '%{Connect-Info}', '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Acct-Terminate-Cause}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '%{Framed-IPv6-Address}', '%{Framed-IPv6-Prefix}', '%{Framed-Interface-Id}', '%{Delegated-IPv6-Prefix}')
(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, framedipv6address, framedipv6prefix, framedinterfaceid, delegatedipv6prefix) VALUES ('81e05982', '36b328d576161a68a3d1ce1db12f88a4', 'ispteste200', '', '10.5.5.17', 'VLAN1250 - FIBRA PPPOE-PONTAL', 'Ethernet', FROM_UNIXTIME(1662135377 - 54), FROM_UNIXTIME(1662135377), FROM_UNIXTIME(1662135377), 54, 'RADIUS', '', '', '0' << 32 | '6451', '0' << 32 | '11266', 'PPPOE-FIBRA', '80:8F:E8:F2:73:DB', 'User-Request', 'Framed-User', 'PPP', '100.64.20.144', '', '', '', '')
(1) sql: EXPAND /var/log/freeradius/accounting.sql
(1) sql: --> /var/log/freeradius/accounting.sql
(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, framedipv6address, framedipv6prefix, framedinterfaceid, delegatedipv6prefix) VALUES ('81e05982', '36b328d576161a68a3d1ce1db12f88a4', 'ispteste200', '', '10.5.5.17', 'VLAN1250 - FIBRA PPPOE-PONTAL', 'Ethernet', FROM_UNIXTIME(1662135377 - 54), FROM_UNIXTIME(1662135377), FROM_UNIXTIME(1662135377), 54, 'RADIUS', '', '', '0' << 32 | '6451', '0' << 32 | '11266', 'PPPOE-FIBRA', '80:8F:E8:F2:73:DB', 'User-Request', 'Framed-User', 'PPP', '100.64.20.144', '', '', '', '')
(1) sql: ERROR: rlm_sql_mysql: ERROR 1406 (Data too long for column 'nasportid' at row 1): 22001
(1) sql: SQL query returned: server error
rlm_sql (sql): Released connection (2)
(1) [sql] = fail
(1) } # accounting = fail
(1) Not sending reply to client.
(1) Finished request
(1) Cleaning up request packet ID 196 with timestamp +4
Enviado do Outlook<http://aka.ms/weboutlook>
________________________________
De: Freeradius-Users <freeradius-users-bounces+portalnet2=outlook.com.br at lists.freeradius.org> em nome de Jonathan Davis <jonathan at prioritycolo.com>
Enviado: sábado, 3 de setembro de 2022 12:07
Para: freeradius-users at lists.freeradius.org <freeradius-users at lists.freeradius.org>
Assunto: Re: RES: RES: Freeradius 3.0.20 Fresh Install not storing radacct logs in mysql table radacct
Again, run a tcpdump to see what's going on. Freeradius isn't seeing
accounting packets, why is that? Are they getting dropped, or are they
not being sent?
Once you know this you can continue troubleshooting, e.g. opening ports
on a firewall, checking the NAS to figure out why it is not sending
accounting backings. As Matthew said, no amount of configuring
FreeRadius will resolve this if nothing is being received by FreeRadius.
Regards,
Jonathan Davis - Priority Colo Inc.
On 2022-09-03 10:34 a.m., Pedro Daniel Costa wrote:
> Thats the problem, o freeradius -x no accounting shown on the log all i can see is on init modules and accounting being loaded.. but when device connects.. only radipool gets updated..
>
> As shown on log below once freeradius reveices request from my radius server mikrotik device
>
>
> Ready to process requests
> (0) Received Access-Request Id 185 from 1.5.5.17:47154 to 10.5.5.200:1812 length 196
> (0) Service-Type = Framed-User
> (0) Framed-Protocol = PPP
> (0) NAS-Port = 15751547
> (0) NAS-Port-Type = Ethernet
> (0) User-Name = "ispteste200"
> (0) Calling-Station-Id = "80:8F:E8:F2:73:DB"
> (0) Called-Station-Id = "PPPOE-FIBRA"
> (0) NAS-Port-Id = "VLAN1250 - FIBRA PPPOE-PONTAL"
> (0) Acct-Session-Id = "81e05971"
> (0) CHAP-Challenge = 0xc602bf8d4fbf361e9d3746f5ae6dbe1e
> (0) CHAP-Password = 0x011b258f5bb0b1aad089ab2593de5d2fab
> (0) NAS-Identifier = "ROUTER P0NT4L PPP0E 2"
> (0) NAS-IP-Address = 1.5.5.17
> (0) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default
> (0) authorize {
> (0) chap: &control:Auth-Type := CHAP
> (0) [chap] = ok
> (0) [mschap] = noop
> (0) eap: No EAP-Message, not doing EAP
> (0) [eap] = noop
> (0) sql: EXPAND %{User-Name}
> (0) sql: --> ispteste200
> (0) sql: SQL-User-Name set to 'ispteste200'
> rlm_sql (sql): Closing connection (1): Hit idle_timeout, was idle for 206 seconds
> rlm_sql_mysql: Socket destructor called, closing socket
> rlm_sql (sql): Closing connection (2): Hit idle_timeout, was idle for 206 seconds
> rlm_sql_mysql: Socket destructor called, closing socket
> rlm_sql (sql): Closing connection (3): Hit idle_timeout, was idle for 206 seconds
> rlm_sql_mysql: Socket destructor called, closing socket
> rlm_sql (sql): Closing connection (4): Hit idle_timeout, was idle for 206 seconds
> rlm_sql (sql): You probably need to lower "min"
> rlm_sql_mysql: Socket destructor called, closing socket
> rlm_sql (sql): Closing connection (0): Hit idle_timeout, was idle for 206 seconds
> rlm_sql (sql): You probably need to lower "min"
> rlm_sql_mysql: Socket destructor called, closing socket
> rlm_sql (sql): Closing connection (5): Hit idle_timeout, was idle for 206 seconds
> rlm_sql (sql): You probably need to lower "min"
> rlm_sql_mysql: Socket destructor called, closing socket
> rlm_sql (sql): 0 of 0 connections in use. You may need to increase "spare"
> rlm_sql (sql): Opening additional connection (6), 1 of 32 pending slots used
> rlm_sql_mysql: Starting connect to MySQL server
> rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10
> rlm_sql (sql): Reserved connection (6)
> (0) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id
> (0) sql: --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'ispteste200' ORDER BY id
> (0) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'ispteste200' ORDER BY id
> (0) sql: User found in radcheck table
> (0) sql: Conditional check items matched, merging assignment check items
> (0) sql: Cleartext-Password := "123123"
> (0) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id
> (0) sql: --> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'ispteste200' ORDER BY id
> (0) sql: Executing select query: SELECT id, username, attribute, value, op FROM radreply WHERE username = 'ispteste200' ORDER BY id
> rlm_sql (sql): 1 of 1 connections in use. You may need to increase "spare"
> rlm_sql (sql): Opening additional connection (7), 1 of 31 pending slots used
> rlm_sql_mysql: Starting connect to MySQL server
> rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10
> rlm_sql (sql): Reserved connection (7)
> rlm_sql (sql): Released connection (7)
> Need 1 more connections to reach min connections (3)
> rlm_sql (sql): Opening additional connection (8), 1 of 30 pending slots used
> rlm_sql_mysql: Starting connect to MySQL server
> rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10
> (0) sql: EXPAND SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority
> (0) sql: --> SELECT groupname FROM radusergroup WHERE username = 'ispteste200' ORDER BY priority
> (0) sql: Executing select query: SELECT groupname FROM radusergroup WHERE username = 'ispteste200' ORDER BY priority
> (0) sql: User found in the group table
> (0) sql: EXPAND SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id
> (0) sql: --> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'fibra_50' ORDER BY id
> (0) sql: Executing select query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'fibra_50' ORDER BY id
> (0) sql: Group "fibra_50": Conditional check items matched
> (0) sql: Group "fibra_50": Merging assignment check items
> (0) sql: Framed-Protocol := PPP
> (0) sql: Pool-Name := "pool_pontal"
> (0) sql: EXPAND SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id
> (0) sql: --> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'fibra_50' ORDER BY id
> (0) sql: Executing select query: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'fibra_50' ORDER BY id
> (0) sql: Group "fibra_50": Merging reply items
> (0) sql: Mikrotik-Rate-Limit := "500M/500M"
> (0) sql: Acct-Interim-Interval := 300
> (0) sql: MS-Primary-DNS-Server := 192.168.10.10
> (0) sql: MS-Secondary-DNS-Server := 192.168.10.11
> rlm_sql (sql): Released connection (6)
> (0) [sql] = ok
> (0) [expiration] = noop
> (0) [logintime] = noop
> (0) } # authorize = ok
> (0) Found Auth-Type = CHAP
> (0) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
> (0) Auth-Type CHAP {
> (0) chap: Comparing with "known good" Cleartext-Password
> (0) chap: CHAP user "ispteste200" authenticated successfully
> (0) [chap] = ok
> (0) } # Auth-Type CHAP = ok
> (0) # Executing section post-auth from file /etc/freeradius/3.0/sites-enabled/default
> (0) post-auth {
> (0) update {
> (0) No attributes updated for RHS &session-state:
> (0) } # update = noop
> (0) sql: EXPAND .query
> (0) sql: --> .query
> (0) sql: Using query template 'query'
> rlm_sql (sql): Reserved connection (6)
> (0) sql: EXPAND %{User-Name}
> (0) sql: --> ispteste200
> (0) sql: SQL-User-Name set to 'ispteste200'
> (0) sql: EXPAND INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')
> (0) sql: --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'ispteste200', '0x011b258f5bb0b1aad089ab2593de5d2fab', 'Access-Accept', '2022-09-03 10:54:19')
> (0) sql: EXPAND /var/log/freeradius/post-auth.sql
> (0) sql: --> /var/log/freeradius/post-auth.sql
> (0) sql: Executing query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'ispteste200', '0x011b258f5bb0b1aad089ab2593de5d2fab', 'Access-Accept', '2022-09-03 10:54:19')
> (0) sql: SQL query returned: success
> (0) sql: 1 record(s) updated
> rlm_sql (sql): Released connection (6)
> (0) [sql] = ok
> rlm_sql (sql): Reserved connection (7)
> (0) sqlippool: EXPAND %{User-Name}
> (0) sqlippool: --> ispteste200
> (0) sqlippool: SQL-User-Name set to 'ispteste200'
> (0) sqlippool: EXPAND START TRANSACTION
> (0) sqlippool: --> START TRANSACTION
> (0) sqlippool: Executing query: START TRANSACTION
> (0) sqlippool: EXPAND UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE pool_key = '%{Calling-Station-Id}'
> (0) sqlippool: --> UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE pool_key = '80:8F:E8:F2:73:DB'
> (0) sqlippool: Executing query: UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE pool_key = '80:8F:E8:F2:73:DB'
> rlm_sql_mysql: Rows matched: 1 Changed: 1 Warnings: 0
> (0) sqlippool: EXPAND COMMIT
> (0) sqlippool: --> COMMIT
> (0) sqlippool: Executing query: COMMIT
> (0) sqlippool: EXPAND START TRANSACTION
> (0) sqlippool: --> START TRANSACTION
> (0) sqlippool: Executing query: START TRANSACTION
> (0) sqlippool: EXPAND SELECT framedipaddress FROM radippool WHERE pool_name = '%{control:Pool-Name}' AND expiry_time IS NULL ORDER BY RAND() LIMIT 1 FOR UPDATE
> (0) sqlippool: --> SELECT framedipaddress FROM radippool WHERE pool_name = 'pool_pontal' AND expiry_time IS NULL ORDER BY RAND() LIMIT 1 FOR UPDATE
> (0) sqlippool: Executing select query: SELECT framedipaddress FROM radippool WHERE pool_name = 'pool_pontal' AND expiry_time IS NULL ORDER BY RAND() LIMIT 1 FOR UPDATE
> (0) sqlippool: Allocated IP 100.64.20.144
> (0) sqlippool: EXPAND UPDATE radippool SET nasipaddress = '%{NAS-IP-Address}', pool_key = '%{Calling-Station-Id}', callingstationid = '%{Calling-Station-Id}', username = '%{User-Name}', expiry_time = NOW() + INTERVAL 1600 SECOND WHERE framedipaddress = '100.64.20.144'
> (0) sqlippool: --> UPDATE radippool SET nasipaddress = '1.5.5.17', pool_key = '80:8F:E8:F2:73:DB', callingstationid = '80:8F:E8:F2:73:DB', username = 'ispteste200', expiry_time = NOW() + INTERVAL 1600 SECOND WHERE framedipaddress = '100.64.20.144'
> (0) sqlippool: Executing query: UPDATE radippool SET nasipaddress = '1.5.5.17', pool_key = '80:8F:E8:F2:73:DB', callingstationid = '80:8F:E8:F2:73:DB', username = 'ispteste200', expiry_time = NOW() + INTERVAL 1600 SECOND WHERE framedipaddress = '100.64.20.144'
> rlm_sql_mysql: Rows matched: 1 Changed: 1 Warnings: 0
> (0) sqlippool: EXPAND COMMIT
> (0) sqlippool: --> COMMIT
> (0) sqlippool: Executing query: COMMIT
> rlm_sql (sql): Released connection (7)
> (0) sqlippool: EXPAND Allocated IP: %{reply:Framed-IP-Address} from %{control:Pool-Name} (did %{Called-Station-Id} cli %{Calling-Station-Id} port %{NAS-Port} user %{User-Name})
> (0) sqlippool: --> Allocated IP: 100.64.20.144 from pool_pontal (did PPPOE-FIBRA cli 80:8F:E8:F2:73:DB port 15751547 user ispteste200)
> (0) [sqlippool] = ok
> (0) policy remove_reply_message_if_eap {
> (0) if (&reply:EAP-Message && &reply:Reply-Message) {
> (0) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE
> (0) else {
> (0) [noop] = noop
> (0) } # else = noop
> (0) } # policy remove_reply_message_if_eap = noop
> (0) } # post-auth = ok
> (0) Sent Access-Accept Id 185 from 10.5.5.200:1812 to 1.5.5.17:47154 length 0
> (0) Mikrotik-Rate-Limit = "500M/500M"
> (0) Acct-Interim-Interval = 300
> (0) MS-Primary-DNS-Server = 192.168.10.10
> (0) MS-Secondary-DNS-Server = 192.168.10.11
> (0) Framed-IP-Address = 100.64.20.144
> (0) Finished request
> Waking up in 4.9 seconds.
> (0) Cleaning up request packet ID 185 with timestamp +206
> Ready to process requests
>
>
> Enviado do Email<https://go.microsoft.com/fwlink/?LinkId=550986> para Windows
>
> De: Jonathan Davis<mailto:jonathan at prioritycolo.com>
> Enviado:sábado, 3 de setembro de 2022 11:26
> Para: FreeRadius users mailing list<mailto:freeradius-users at lists.freeradius.org>
> Assunto: Re: RES: Freeradius 3.0.20 Fresh Install not storing radacct logs in mysql table radacct
>
> If you do a tcpdump on the radius server, are you seeing accounting packets arriving on port 1813 from 10.5.5.17 ?
>
>> On Sep 3, 2022, at 10:15 AM, Pedro Daniel Costa <portalnet2 at outlook.com.br> wrote:
>>
>>
>>
>> As I said, you need to configure your NAS (the device with IP 10.5.5.17)
>> to send accounting packets. No amount of configuring FreeRADIUS will fix
>> this.
>>
>>
>> Ok i think i understood now what you meant with device with ip 10.5.5.17 , you meant my hardware radius server (my mikrotik test device)
>> Yes i did check this yesterday and its enabled.. on accounting port 1813
>> -
>> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
>
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
More information about the Freeradius-Users
mailing list