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:52:02 UTC 2022
Guys .. all confirmed now everything working as expected i have increased the size value on the column nasportid inside radacct and its now storing the data sent from mikrotik sucessful.
Once again thank you all for the support.
Enviado do Outlook<http://aka.ms/weboutlook>
________________________________
De: Freeradius-Users <freeradius-users-bounces+portalnet2=outlook.com.br at lists.freeradius.org> em nome de Pedro Daniel Costa <portalnet2 at outlook.com.br>
Enviado: sábado, 3 de setembro de 2022 11:34
Para: FreeRadius users mailing list <freeradius-users at lists.freeradius.org>
Assunto: RES: RES: Freeradius 3.0.20 Fresh Install not storing radacct logs in mysql table radacct
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
More information about the Freeradius-Users
mailing list