Freeradius 3.0.12 problems - redis and mysql pool connections

Michal Tomaszewski Michal.Tomaszewski at cca.pl
Wed Dec 28 15:53:57 CET 2016


Alan,
Some more Information in the subject.

> >> I don't see that ERROR as much of a problem. The server tried to use an
> old connection, it failed, and when the server tried another connection, that
> one failed, too.
> > Yes. But connection has expired and probably something in connection's
> pool management can be improved.
>
>   How?  Make a concrete suggestion.  Or send a patch.
>

There is an ERROR in case the data is written to the MySQL correctly.
As I understand this is not an ERROR situation.
Error shall be thrown where there is no possibility to write data.

> > Server is not down. Server is working perfectly all the time. Those
> messages are not because MySQL server is down. They are appearing in
> normal operation when server is 100% available. They are probably because
> idle_timeout closes the connection and freeradius does not record the fact
> that such connection does not exist.
>
>   No.  And why guess?  The source is available to you.

I've checked the source and deeply checked the problem.
The problem exists on Ubuntu 16.04 and MySQL client library 5.7 and newest build of freeradius.
The same situation we can observe on our stage environment: freeradius 3.12 on Ubuntu 14.04 and MySQL client library 5.5.46.
So suggested bug in the SQL library or its newer/older version seems to be not a real cause of the problem.

There is 'ERROR: SQL query failed: no connection' ONLY in case of INSERTs or REPLACEs to Mysql database.
Error is thrown but each INSERT and REPLACE is SUCCESSFUL.

We made a lot of tests and:
1. EVERY (even simple) INSERT or REPLACE throws ERROR. MySQL is available during query. Insert or replace is successful.
We made temporary table and tested inserts in accounting start/stop section:
Tue Dec 27 14:42:02 2016 : Debug: (2)         Executing select query:                   INSERT INTO                     debug_log (`data`)                      VALUES ('AAAAAAA')
Tue Dec 27 14:42:02 2016 : ERROR: (2)         SQL query failed: no connection

2. When you change insert query to select query - there are no errors.

3. Nor SELECT neither DELETE query throws error (to be sure we checked deletes with 0 rows deleted and 1 row deleted). Only INSERT and REPLACE. Each INSERT and each REPLACE.

3. There is also no error thrown when you change the insert query into: "INSERT INTO debug_log (`data`) VALUES ('AAAAAAA'); SELECT 1;"


Examples:

#1 real situation:

Mon Nov 28 21:53:09 2016 : Debug: rlm_sql (sql): Reserved connection (10)
Mon Nov 28 21:53:09 2016 : Debug: (12)         Executing select query:                          INSERT INTO radius_radacct_closed                                         (                             acctsessionid,          acctuniqueid,           username,                            additional_id,             device_id,                                                      realm,                  nasipaddress,           nasportid,                                      nasporttype,            acctstarttime,          acctupdatetime,                              acctstoptime,           acctsessiontime,        acctauthentic,                          connectinfo_start,      connectinfo_stop,       acctinputoctets,                             acctoutputoctets,       calledstationid,        callingstationid,                               acctterminatecause,     servicetype,            framedprotocol,                                 framedipaddress                                      )                                 VALUES                                         ('583c98d000000001',                                         '79ffcccafc3b54e87403444481bf65e5',                                         'z555',                                         '555',                                    '2',                                    '',                                         '192.168.176.1',                                         '00000001',                                         'Wireless-802.11',                                         FROM_UNIXTIME(1480366389 - 49),                                         FROM_UNIXTIME(1480366389),                                         FROM_UNIXTIME(1480366389),                                         49,                                         '',                                         '',                                         '',                                         '0' << 32 | '413029',                                         '0' << 32 | '3533411',                               
          'z5-d2',                                         '90-B0-ED-E6-AE-15',                                         'User-Request',                                         '',                                         '',                                         '192.168.176.2')
Mon Nov 28 21:53:09 2016 : ERROR: (12)         SQL query failed: no connection
--
--
--
--
Mon Nov 28 21:54:45 2016 : Debug: rlm_sql (sql): Reserved connection (13)
Mon Nov 28 21:54:45 2016 : Debug: (14)       Executing select query:                         INSERT INTO radius_radacct_active                                        (                                 acctsessionid,          acctuniqueid,           username,                                 additional_id,             device_id,                                                       realm,                  nasipaddress,           nasportid,                                 nasporttype,            acctstarttime, acctstoptime,                                acctauthentic,                                 connectinfo_start,      connectinfo_stop,       acctinputoctets,                                 acctoutputoctets,       calledstationid,        callingstationid,                                 servicetype,            framedprotocol,                                 framedipaddress                                         )                                 VALUES                                         ('583c996300000001',                                         '3c96a44b069782db0d7076274139e521',                                         'z555',                                         '5555',                                        '2',                                        '',                                         '192.168.176.1',                                         '00000001',                                         'Wireless-802.11',                                         FROM_UNIXTIME(1480366485),                                       FROM_UNIXTIME(1480366485 + 2700),                                         '',                                         '',                                         '',                                         '0' << 32 | '0',                                         '0' << 32 | '0',                                         'z5-d2',                                         '90-B0-ED-E6-AE-15',                                         'Login-User',                                         '',
                                         '192.168.176.2')
Mon Nov 28 21:54:45 2016 : ERROR: (14)       SQL query failed: no connection


#2
Test scenarios:

Tue Dec 27 14:42:02 2016 : Debug: %{sql:                        INSERT INTO                     debug_log (`data`)                      VALUES ('AAAAAAA')                 }
Tue Dec 27 14:42:02 2016 : Debug: Parsed xlat tree:
Tue Dec 27 14:42:02 2016 : Debug: xlat --> sql
Tue Dec 27 14:42:02 2016 : Debug: {
Tue Dec 27 14:42:02 2016 : Debug:       literal -->                     INSERT INTO                     debug_log (`data`)                      VALUES ('AAAAAAA')
Tue Dec 27 14:42:02 2016 : Debug: }
Tue Dec 27 14:42:02 2016 : Debug: %{User-Name}
Tue Dec 27 14:42:02 2016 : Debug: Parsed xlat tree:
Tue Dec 27 14:42:02 2016 : Debug: attribute --> User-Name
Tue Dec 27 14:42:02 2016 : Debug: (2)         EXPAND %{User-Name}
Tue Dec 27 14:42:02 2016 : Debug: (2)            --> z555
Tue Dec 27 14:42:02 2016 : Debug: (2)         SQL-User-Name set to 'z555'
Tue Dec 27 14:42:02 2016 : Debug: rlm_sql (sql): Reserved connection (1)
Tue Dec 27 14:42:02 2016 : Debug: (2)         Executing select query:                   INSERT INTO                     debug_log (`data`)                      VALUES ('AAAAAAA')
**************************Tue Dec 27 14:42:02 2016 : ERROR: (2)         SQL query failed: no connection
Tue Dec 27 14:42:02 2016 : Debug: rlm_sql (sql): Released connection (1)
Tue Dec 27 14:42:02 2016 : Info: Need 2 more connections to reach min connections (5)
Tue Dec 27 14:42:02 2016 : Info: rlm_sql (sql): Opening additional connection (3), 1 of 29 pending slots used
Tue Dec 27 14:42:02 2016 : Debug: rlm_sql_mysql: Starting connect to MySQL server
Tue Dec 27 14:42:02 2016 : Debug: rlm_sql_mysql: Connected to database 'Radius' on 127.0.0.1 via TCP/IP, server version 5.6.34-79.1-56-log, protocol version 10
Tue Dec 27 14:42:02 2016 : Debug: (2)         EXPAND %{sql:                     INSERT INTO                     debug_log (`data`)                      VALUES ('AAAAAAA')                 }
Tue Dec 27 14:42:02 2016 : Debug: (2)            -->


Wed Dec 28 10:56:08 2016 : Debug: rlm_sql (sql): Reserved connection (0)
Wed Dec 28 10:56:08 2016 : Debug: (0)     Executing select query:  INSERT INTO debug_log                        (data) VALUES                ('CCCCCCCCCCCCCCCCCCCCCCC')
**************************Wed Dec 28 10:56:08 2016 : ERROR: (0)     SQL query failed: no connection
--
Wed Dec 28 10:56:08 2016 : Debug: Parsed xlat tree:
Wed Dec 28 10:56:08 2016 : Debug: attribute --> User-Name
Wed Dec 28 10:56:08 2016 : Debug: (0)     EXPAND %{User-Name}
Wed Dec 28 10:56:08 2016 : Debug: (0)        --> z555
Wed Dec 28 10:56:08 2016 : Debug: (0)     SQL-User-Name set to 'z555'
Wed Dec 28 10:56:08 2016 : Debug: rlm_sql (sql): Reserved connection (0)
Wed Dec 28 10:56:08 2016 : Debug: (0)     Executing select query:  INSERT INTO debug_log                        (data) VALUES                ('AAAAAAAAAAAAAAAAAAAA')
**************************Wed Dec 28 10:56:08 2016 : ERROR: (0)     SQL query failed: no connection


Wed Dec 28 11:11:15 2016 : Debug:       literal -->  INSERT INTO debug_log                        (data) VALUES                ('BBBBBBBBBBBBBBB');SELECT 1
Wed Dec 28 11:11:15 2016 : Debug: (0)     Executing select query:  INSERT INTO debug_log                        (data) VALUES                ('BBBBBBBBBBBBBBB');SELECT 1
Wed Dec 28 11:11:15 2016 : Debug: (0)     EXPAND %{sql: INSERT INTO debug_log                        (data) VALUES                ('BBBBBBBBBBBBBBB');SELECT 1       }
Wed Dec 28 11:13:15 2016 : Debug: %{sql: INSERT INTO debug_log                        (data) VALUES                ('CCCCCCCCCCCCCCCCCCCCCCC');SELECT 1       }
Wed Dec 28 11:13:15 2016 : Debug:       literal -->  INSERT INTO debug_log                        (data) VALUES                ('CCCCCCCCCCCCCCCCCCCCCCC');SELECT 1
Wed Dec 28 11:13:15 2016 : Debug: (1)     Executing select query:  INSERT INTO debug_log                        (data) VALUES                ('CCCCCCCCCCCCCCCCCCCCCCC');SELECT 1
Wed Dec 28 11:13:15 2016 : Debug: (1)     Executing select query:  INSERT INTO debug_log                        (data) VALUES                ('CCCCCCCCCCCCCCCCCCCCCCC');SELECT 1
Wed Dec 28 11:13:15 2016 : Debug: (1)     EXPAND %{sql: INSERT INTO debug_log                        (data) VALUES                ('CCCCCCCCCCCCCCCCCCCCCCC');SELECT 1       }
Wed Dec 28 11:13:15 2016 : Debug: %{sql: INSERT INTO debug_log (data) VALUES ('FFFFFFFFFFF');SELECT 1}
Wed Dec 28 11:13:15 2016 : Debug:       literal -->  INSERT INTO debug_log (data) VALUES ('FFFFFFFFFFF');SELECT 1
Wed Dec 28 11:13:15 2016 : Debug: (1)     Executing select query:  INSERT INTO debug_log (data) VALUES ('FFFFFFFFFFF');SELECT 1
Wed Dec 28 11:13:15 2016 : Debug: (1)     Executing select query:  INSERT INTO debug_log (data) VALUES ('FFFFFFFFFFF');SELECT 1
Wed Dec 28 11:13:15 2016 : Debug: (1)     EXPAND %{sql: INSERT INTO debug_log (data) VALUES ('FFFFFFFFFFF');SELECT 1}
Wed Dec 28 11:13:15 2016 : Debug: %{sql: INSERT INTO debug_log                        (data) VALUES                ('AAAAAAAAAAAAAAAAAAAA');SELECT 1       }
Wed Dec 28 11:13:15 2016 : Debug:       literal -->  INSERT INTO debug_log                        (data) VALUES                ('AAAAAAAAAAAAAAAAAAAA');SELECT 1
Wed Dec 28 11:13:15 2016 : Debug: (1)     Executing select query:  INSERT INTO debug_log                        (data) VALUES                ('AAAAAAAAAAAAAAAAAAAA');SELECT 1
Wed Dec 28 11:13:15 2016 : Debug: (1)     Executing select query:  INSERT INTO debug_log                        (data) VALUES                ('AAAAAAAAAAAAAAAAAAAA');SELECT 1


In case of replace:
Wed Dec 28 15:14:01 2016 : Debug: rlm_sql (sql): Reserved connection (0)
Wed Dec 28 15:14:01 2016 : Debug: (0)     Executing select query:  REPLACE INTO debug_log                        (id,data) VALUES                 (1,'CCCCCCCCCCCCCCCCCCCCCCC')
**************************Wed Dec 28 15:14:01 2016 : ERROR: (0)     SQL query failed: no connection
Wed Dec 28 15:14:01 2016 : Debug: rlm_sql (sql): Released connection (0)
Wed Dec 28 15:14:01 2016 : Info: Need 4 more connections to reach min connections (5)
Wed Dec 28 15:14:01 2016 : Info: rlm_sql (sql): Opening additional connection (1), 1 of 31 pending slots used
Wed Dec 28 15:14:01 2016 : Debug: rlm_sql_mysql: Starting connect to MySQL server
Wed Dec 28 15:14:01 2016 : Debug: rlm_sql_mysql: Connected to database 'WiFi-Spot-Radius' on 127.0.0.1 via TCP/IP, server version 5.6.34-79.1-56-log, protocol version 10
Wed Dec 28 15:14:01 2016 : Debug: (0)     EXPAND %{sql: REPLACE INTO debug_log                        (id,data) VALUES                 (1,'CCCCCCCCCCCCCCCCCCCCCCC')       }
Wed Dec 28 15:14:01 2016 : Debug: (0)        -->
Wed Dec 28 15:14:01 2016 : Debug: %{sql: REPLACE INTO debug_log                        (id,data) VALUES                 (3,'CCCCCCCCCCCCCCCCCCCCCCC')       }
Wed Dec 28 15:14:01 2016 : Debug: Parsed xlat tree:
Wed Dec 28 15:14:01 2016 : Debug: xlat --> sql
Wed Dec 28 15:14:01 2016 : Debug: {
Wed Dec 28 15:14:01 2016 : Debug:       literal -->  REPLACE INTO debug_log                        (id,data) VALUES                 (3,'CCCCCCCCCCCCCCCCCCCCCCC')
Wed Dec 28 15:14:01 2016 : Debug: }
Wed Dec 28 15:14:01 2016 : Debug: %{User-Name}
Wed Dec 28 15:14:01 2016 : Debug: Parsed xlat tree:
Wed Dec 28 15:14:01 2016 : Debug: attribute --> User-Name
Wed Dec 28 15:14:01 2016 : Debug: (0)     EXPAND %{User-Name}
Wed Dec 28 15:14:01 2016 : Debug: (0)        --> z555
Wed Dec 28 15:14:01 2016 : Debug: (0)     SQL-User-Name set to 'z555'
Wed Dec 28 15:14:01 2016 : Debug: rlm_sql (sql): Reserved connection (0)
Wed Dec 28 15:14:01 2016 : Debug: (0)     Executing select query:  REPLACE INTO debug_log                        (id,data) VALUES                 (3,'CCCCCCCCCCCCCCCCCCCCCCC')
**************************Wed Dec 28 15:14:01 2016 : ERROR: (0)     SQL query failed: no connection
Wed Dec 28 15:14:01 2016 : Debug: rlm_sql (sql): Released connection (0)
Wed Dec 28 15:14:01 2016 : Debug: (0)     EXPAND %{sql: REPLACE INTO debug_log                        (id,data) VALUES                 (3,'CCCCCCCCCCCCCCCCCCCCCCC')       }
Wed Dec 28 15:14:01 2016 : Debug: (0)        -->
Wed Dec 28 15:14:01 2016 : Debug: %{sql: REPLACE INTO debug_log                        (id,data) VALUES                 (4,'CCCCCCCCCCCCCCCCCCCCCCC')       }
Wed Dec 28 15:14:01 2016 : Debug: Parsed xlat tree:
Wed Dec 28 15:14:01 2016 : Debug: xlat --> sql
Wed Dec 28 15:14:01 2016 : Debug: {
Wed Dec 28 15:14:01 2016 : Debug:       literal -->  REPLACE INTO debug_log                        (id,data) VALUES                 (4,'CCCCCCCCCCCCCCCCCCCCCCC')
Wed Dec 28 15:14:01 2016 : Debug: }
Wed Dec 28 15:14:01 2016 : Debug: %{User-Name}
Wed Dec 28 15:14:01 2016 : Debug: Parsed xlat tree:
Wed Dec 28 15:14:01 2016 : Debug: attribute --> User-Name
Wed Dec 28 15:14:01 2016 : Debug: (0)     EXPAND %{User-Name}
Wed Dec 28 15:14:01 2016 : Debug: (0)        --> z555
Wed Dec 28 15:14:01 2016 : Debug: (0)     SQL-User-Name set to 'z555'
Wed Dec 28 15:14:01 2016 : Debug: rlm_sql (sql): Reserved connection (1)
Wed Dec 28 15:14:01 2016 : Debug: (0)     Executing select query:  REPLACE INTO debug_log                        (id,data) VALUES                 (4,'CCCCCCCCCCCCCCCCCCCCCCC')
**************************Wed Dec 28 15:14:01 2016 : ERROR: (0)     SQL query failed: no connection
Wed Dec 28 15:14:01 2016 : Debug: rlm_sql (sql): Released connection (1)
Wed Dec 28 15:14:01 2016 : Debug: (0)     EXPAND %{sql: REPLACE INTO debug_log                        (id,data) VALUES                 (4,'CCCCCCCCCCCCCCCCCCCCCCC')       }
Wed Dec 28 15:14:01 2016 : Debug: (0)        -->
Wed Dec 28 15:14:01 2016 : Debug: %{sql: REPLACE INTO debug_log                        (id,data) VALUES                 (5,'CCCCCCCCCCCCCCCCCCCCCCC');SELECT 1       }
Wed Dec 28 15:14:01 2016 : Debug: Parsed xlat tree:
Wed Dec 28 15:14:01 2016 : Debug: xlat --> sql
Wed Dec 28 15:14:01 2016 : Debug: {
Wed Dec 28 15:14:01 2016 : Debug:       literal -->  REPLACE INTO debug_log                        (id,data) VALUES                 (5,'CCCCCCCCCCCCCCCCCCCCCCC');SELECT 1
Wed Dec 28 15:14:01 2016 : Debug: }
Wed Dec 28 15:14:01 2016 : Debug: %{User-Name}
Wed Dec 28 15:14:01 2016 : Debug: Parsed xlat tree:
Wed Dec 28 15:14:01 2016 : Debug: attribute --> User-Name
Wed Dec 28 15:14:01 2016 : Debug: (0)     EXPAND %{User-Name}
Wed Dec 28 15:14:01 2016 : Debug: (0)        --> z555
Wed Dec 28 15:14:01 2016 : Debug: (0)     SQL-User-Name set to 'z555'
**************************Wed Dec 28 15:14:01 2016 : Debug: rlm_sql (sql): Reserved connection (0)
Wed Dec 28 15:14:01 2016 : Debug: (0)     Executing select query:  REPLACE INTO debug_log                        (id,data) VALUES                 (5,'CCCCCCCCCCCCCCCCCCCCCCC');SELECT 1
Wed Dec 28 15:14:01 2016 : Debug: rlm_sql (sql): Released connection (0)
Wed Dec 28 15:14:01 2016 : Debug: (0)     EXPAND %{sql: REPLACE INTO debug_log                        (id,data) VALUES                 (5,'CCCCCCCCCCCCCCCCCCCCCCC');SELECT 1       }
Wed Dec 28 15:14:01 2016 : Debug: (0)        --> 1
Wed Dec 28 15:14:01 2016 : Debug: %{sql: REPLACE INTO debug_log                        (id,data) VALUES                 (6,'CCCCCCCCCCCCCCCCCCCCCCC')       }
Wed Dec 28 15:14:01 2016 : Debug: Parsed xlat tree:
Wed Dec 28 15:14:01 2016 : Debug: xlat --> sql
Wed Dec 28 15:14:01 2016 : Debug: {
Wed Dec 28 15:14:01 2016 : Debug:       literal -->  REPLACE INTO debug_log                        (id,data) VALUES                 (6,'CCCCCCCCCCCCCCCCCCCCCCC')
Wed Dec 28 15:14:01 2016 : Debug: }
Wed Dec 28 15:14:01 2016 : Debug: %{User-Name}
Wed Dec 28 15:14:01 2016 : Debug: Parsed xlat tree:
Wed Dec 28 15:14:01 2016 : Debug: attribute --> User-Name
Wed Dec 28 15:14:01 2016 : Debug: (0)     EXPAND %{User-Name}
Wed Dec 28 15:14:01 2016 : Debug: (0)        --> z555
Wed Dec 28 15:14:01 2016 : Debug: (0)     SQL-User-Name set to 'z555'
Wed Dec 28 15:14:01 2016 : Debug: rlm_sql (sql): Reserved connection (1)
Wed Dec 28 15:14:01 2016 : Debug: (0)     Executing select query:  REPLACE INTO debug_log                        (id,data) VALUES                 (6,'CCCCCCCCCCCCCCCCCCCCCCC')
**************************Wed Dec 28 15:14:01 2016 : ERROR: (0)     SQL query failed: no connection
Wed Dec 28 15:14:01 2016 : Debug: rlm_sql (sql): Released connection (1)
Wed Dec 28 15:14:01 2016 : Debug: (0)     EXPAND %{sql: REPLACE INTO debug_log                        (id,data) VALUES                 (6,'CCCCCCCCCCCCCCCCCCCCCCC')       }




#3
Same query log analysis:

WITH ERROR:
Wed Dec 28 11:01:33 2016 : Debug: %{sql: INSERT INTO debug_log                        (data) VALUES                ('AAAAAAAAAAAAAAAAAAAA')       }
Wed Dec 28 11:01:33 2016 : Debug: Parsed xlat tree:
Wed Dec 28 11:01:33 2016 : Debug: xlat --> sql
Wed Dec 28 11:01:33 2016 : Debug: {
Wed Dec 28 11:01:33 2016 : Debug:       literal -->  INSERT INTO debug_log                        (data) VALUES                ('AAAAAAAAAAAAAAAAAAAA')
Wed Dec 28 11:01:33 2016 : Debug: }
Wed Dec 28 11:01:33 2016 : Debug: %{User-Name}
Wed Dec 28 11:01:33 2016 : Debug: Parsed xlat tree:
Wed Dec 28 11:01:33 2016 : Debug: attribute --> User-Name
Wed Dec 28 11:01:33 2016 : Debug: (0)     EXPAND %{User-Name}
Wed Dec 28 11:01:33 2016 : Debug: (0)        --> z555
Wed Dec 28 11:01:33 2016 : Debug: (0)     SQL-User-Name set to 'z555'
Wed Dec 28 11:01:33 2016 : Debug: rlm_sql (sql): Reserved connection (1)
Wed Dec 28 11:01:33 2016 : Debug: (0)     Executing select query:  INSERT INTO debug_log                        (data) VALUES                ('AAAAAAAAAAAAAAAAAAAA')
Wed Dec 28 11:01:33 2016 : ERROR: (0)     SQL query failed: no connection
Wed Dec 28 11:01:33 2016 : Debug: rlm_sql (sql): Released connection (1)
Wed Dec 28 11:01:33 2016 : Debug: (0)     EXPAND %{sql: INSERT INTO debug_log                        (data) VALUES                ('AAAAAAAAAAAAAAAAAAAA')       }
Wed Dec 28 11:01:33 2016 : Debug: (0)        -->
Wed Dec 28 11:01:33 2016 : Debug: (0)     policy wifi-sessions.accounting {
Wed Dec 28 11:01:33 2016 : Debug: (0)       if (&Acct-Status-Type == start){
Wed Dec 28 11:01:33 2016 : Debug: (0)       if (&Acct-Status-Type == start) -> FALSE
Wed Dec 28 11:01:33 2016 : Debug: (0)       elsif (&Acct-Status-Type == stop){
Wed Dec 28 11:01:33 2016 : Debug: (0)       elsif (&Acct-Status-Type == stop) -> TRUE
Wed Dec 28 11:01:33 2016 : Debug: (0)       elsif (&Acct-Status-Type == stop) {


WITHOUT ERROR (query modified to have select 1 on the end):
Wed Dec 28 11:13:15 2016 : Debug: %{sql: INSERT INTO debug_log                        (data) VALUES                ('AAAAAAAAAAAAAAAAAAAA');SELECT 1       }
Wed Dec 28 11:13:15 2016 : Debug: Parsed xlat tree:
Wed Dec 28 11:13:15 2016 : Debug: xlat --> sql
Wed Dec 28 11:13:15 2016 : Debug: {
Wed Dec 28 11:13:15 2016 : Debug:       literal -->  INSERT INTO debug_log                        (data) VALUES                ('AAAAAAAAAAAAAAAAAAAA');SELECT 1
Wed Dec 28 11:13:15 2016 : Debug: }
Wed Dec 28 11:13:15 2016 : Debug: %{User-Name}
Wed Dec 28 11:13:15 2016 : Debug: Parsed xlat tree:
Wed Dec 28 11:13:15 2016 : Debug: attribute --> User-Name
Wed Dec 28 11:13:15 2016 : Debug: (1)     EXPAND %{User-Name}
Wed Dec 28 11:13:15 2016 : Debug: (1)        --> z555
Wed Dec 28 11:13:15 2016 : Debug: (1)     SQL-User-Name set to 'z555'
Wed Dec 28 11:13:15 2016 : Debug: rlm_sql (sql): Reserved connection (1)
Wed Dec 28 11:13:15 2016 : Debug: (1)     Executing select query:  INSERT INTO debug_log                        (data) VALUES                ('AAAAAAAAAAAAAAAAAAAA');SELECT 1
Wed Dec 28 11:13:15 2016 : Debug: rlm_sql_mysql: Socket destructor called, closing socket
Wed Dec 28 11:13:15 2016 : Debug: rlm_sql (sql): Reconnecting (1)
Wed Dec 28 11:13:15 2016 : Debug: rlm_sql_mysql: Starting connect to MySQL server
Wed Dec 28 11:13:15 2016 : Debug: rlm_sql_mysql: Connected to database 'Radius' on 127.0.0.1 via TCP/IP, server version 5.6.34-79.1-56-log, protocol version 10
Wed Dec 28 11:13:15 2016 : Debug: (1)     Executing select query:  INSERT INTO debug_log                        (data) VALUES                ('AAAAAAAAAAAAAAAAAAAA');SELECT 1
Wed Dec 28 11:13:15 2016 : Debug: rlm_sql (sql): Released connection (1)
Wed Dec 28 11:13:15 2016 : Debug: (1)     EXPAND %{sql: INSERT INTO debug_log                        (data) VALUES                ('AAAAAAAAAAAAAAAAAAAA');SELECT 1       }
Wed Dec 28 11:13:15 2016 : Debug: (1)        --> 1
Wed Dec 28 11:13:15 2016 : Debug: (1)     policy wifi-sessions.accounting {
Wed Dec 28 11:13:15 2016 : Debug: (1)       if (&Acct-Status-Type == start){
Wed Dec 28 11:13:15 2016 : Debug: (1)       if (&Acct-Status-Type == start) -> FALSE
Wed Dec 28 11:13:15 2016 : Debug: (1)       elsif (&Acct-Status-Type == stop){
Wed Dec 28 11:13:15 2016 : Debug: (1)       elsif (&Acct-Status-Type == stop) -> TRUE
Wed Dec 28 11:13:15 2016 : Debug: (1)       elsif (&Acct-Status-Type == stop) {


As you can in second case see in place of:
Wed Dec 28 11:01:33 2016 : ERROR: (0)     SQL query failed: no connection
Wed Dec 28 11:01:33 2016 : Debug: rlm_sql (sql): Released connection (1)

after changing the query we have no ERROR message and in case of socket unavailable there is:
Wed Dec 28 11:13:15 2016 : Debug: rlm_sql_mysql: Socket destructor called, closing socket
Wed Dec 28 11:13:15 2016 : Debug: rlm_sql (sql): Reconnecting (1)
Wed Dec 28 11:13:15 2016 : Debug: rlm_sql_mysql: Starting connect to MySQL server
Wed Dec 28 11:13:15 2016 : Debug: rlm_sql_mysql: Connected to database 'Radius' on 127.0.0.1 via TCP/IP, server version 5.6.34-79.1-56-log, protocol version 10
Wed Dec 28 11:13:15 2016 : Debug: (1)     Executing select query:  INSERT INTO debug_log                        (data) VALUES                ('AAAAAAAAAAAAAAAAAAAA');SELECT 1
Wed Dec 28 11:13:15 2016 : Debug: rlm_sql (sql): Released connection (1)
what - I suppose - is normal and desired situation.

Regards,
Mike
________________________________________ Uwaga: Treść niniejszej wiadomości może być poufna i objęta zakazem jej ujawniania. Jeśli czytelnik tej wiadomości nie jest jej zamierzonym adresatem, pracownikiem lub pośrednikiem upoważnionym do jej przekazania adresatowi, informujemy że wszelkie rozprowadzanie, rozpowszechnianie lub powielanie niniejszej wiadomości jest zabronione. Jeśli otrzymałeś tę wiadomość omyłkowo, proszę bezzwłocznie odesłać ją nadawcy, a samą wiadomość usunąć z komputera. Dziękujemy. ________________________________ Note: The information contained in this message may be privileged and confidential and protected from disclosure. If the reader of this message is not the intended recipient, or an employee or agent responsible for delivering this message to the intended recipient, you are hereby notified that any dissemination, distribution or copying of this communication is strictly prohibited.If you have received this communication in error, please notify the sender immediately by replying to the message and deleting it from your computer. Thank you. ________________________________



More information about the Freeradius-Users mailing list