Sorry, here is the log missing part in previous mail. (1) Received Accounting-Request Id 128 from 127.0.0.1:38016 to 127.0.0.1:1813 length 49 (1) User-Name = "testuser@domain" (1) Acct-Status-Type = Start (1) NAS-Port = 3 (1) # Executing section preacct from file /etc/raddb/sites-enabled/default (1) preacct { (1) [preprocess] = ok (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) --> 073b176091b6bacf69830880ad81e980 (1) &Acct-Unique-Session-Id := 073b176091b6bacf69830880ad81e980 (1) } # update request = noop (1) } # else = noop (1) update request { (1) &Tmp-String-9 !* ANY (1) } # update request = noop (1) } # policy acct_unique = noop (1) suffix: Checking for suffix after "@" (1) suffix: Looking up realm "domain" for User-Name = "testuser@domain" (1) suffix: No such realm "domain" (1) [suffix] = noop (1) [files] = noop (1) } # preacct = ok (1) # Executing section accounting from file /etc/raddb/sites-enabled/default (1) accounting { (1) if ("%{User-Name}" =~ /@/) { (1) EXPAND %{User-Name} (1) --> testuser@domain (1) if ("%{User-Name}" =~ /@/) -> TRUE (1) if ("%{User-Name}" =~ /@/) { (1) radutmp: EXPAND /opt/Fradius_log/shared/radius/radutmp (1) radutmp: --> /opt/Fradius_log/shared/radius/radutmp (1) radutmp: EXPAND %{User-Name} (1) radutmp: --> testuser@domain (1) [radutmp] = ok (1) sql_Fradius_log: EXPAND %{tolower:type.%{%{Acct-Status-Type}:-%{Request-Processing-Stage}}.query} (1) sql_Fradius_log: --> type.start.query (1) sql_Fradius_log: Using query template 'query' rlm_sql (sql_Fradius_log): Reserved connection (2) (1) sql_Fradius_log: EXPAND %{User-Name} (1) sql_Fradius_log: --> testuser@domain (1) sql_Fradius_log: SQL-User-Name set to 'testuser@domain' (1) sql_Fradius_log: 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}:-%l}), FROM_UNIXTIME(%{%{integer:Event-Timestamp}:-%l}), NULL, '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '%{Framed-IPv6-Address}', '%{Framed-IPv6-Prefix}', '%{Framed-Interface-Id}', '%{Delegated-IPv6-Prefix}' ) (1) sql_Fradius_log: --> 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 ('', '073b176091b6bacf69830880ad81e980', 'testuser@domain', '', '127.0.0.1', '3', '', FROM_UNIXTIME(1741879057), FROM_UNIXTIME(1741879057), NULL, '0', '', '', '', '0', '0', '', '', '', '', '', '', '', '', '', '' ) (1) sql_Fradius_log: 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 ('', '073b176091b6bacf69830880ad81e980', 'testuser@domain', '', '127.0.0.1', '3', '', FROM_UNIXTIME(1741879057), FROM_UNIXTIME(1741879057), NULL, '0', '', '', '', '0', '0', '', '', '', '', '', '', '', '', '', '' ) (1) sql_Fradius_log: ERROR: rlm_sql_mysql: ERROR 1927 (Connection was killed): 70100 (1) sql_Fradius_log: SQL query returned: server error rlm_sql (sql_Fradius_log): Released connection (2) Need more connections to reach 10 spares rlm_sql (sql_Fradius_log): Opening additional connection (7), 1 of 25 pending slots used rlm_sql_mysql: Starting connect to MySQL server rlm_sql_mysql: Couldn't connect to MySQL server root@10.0.0.79:Fradius rlm_sql_mysql: MySQL error: Can't connect to MySQL server on '10.0.0.79' (111) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql_Fradius_log): Opening connection failed (7) rlm_sql (sql_Fradius_log): Closing expired connection (5) - Hit idle_timeout limit rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql_Fradius_log): Closing expired connection (4) - Hit idle_timeout limit rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql_Fradius_log): Closing expired connection (3) - Hit idle_timeout limit rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql_Fradius_log): Closing expired connection (0) - Hit idle_timeout limit rlm_sql_mysql: Socket destructor called, closing socket (1) [sql_Fradius_log] = fail (1) } # if ("%{User-Name}" =~ /@/) = fail (1) } # accounting = fail (1) Not sending reply to client. (1) Finished request (1) Cleaning up request packet ID 128 with timestamp +68 due to done Ready to process requests
On 13 Mar 2025, at 10:55 PM, Alan DeKok <aland@deployingradius.com> wrote:
On Mar 13, 2025, at 4:53 PM, (null) (null) via Freeradius-Users <freeradius-users@lists.freeradius.org> wrote:
Tried the following settings, but it still doesn't work.
If only there was some kind of debug output which could help.
The accounting log breaks when SQL fails to connect, and it only returns successfully when the SQL server is up. I want to ensure that accounting responds even if it fails to save the log to radutmp or SQL.
1) read the debug output to see what's going on
2) write a policy (e.g. using the "redundant" keyword ) which handles this situation.
This is documented extensively.
Alan DeKok.