Freeradius 3.0.12 problems - mysql pool connections
Michal Tomaszewski
Michal.Tomaszewski at cca.pl
Fri Jan 27 13:38:25 CET 2017
Hi Alan,
As you can see the problem described below was not exactly - as you previously stated - caused by SQL library but somehow FR itself...
I understand that your fixes solved the problem, e.g.:
https://github.com/FreeRADIUS/freeradius-server/commit/8aaf545d6c011dd5d4a2f98832afb5a2a87e58e4
Unfortunately current build of freeradius 3.0.13 makes (in our server once a minute) segmentation fault after SQL INSERT command
user at server:~$ sudo freeradius -Xx > log20170127b.txt
Segmentation fault (core dumped)
Last lines in log:
...
Fri Jan 27 13:27:28 2017 : Debug: %{User-Name}
Fri Jan 27 13:27:28 2017 : Debug: Parsed xlat tree:
Fri Jan 27 13:27:28 2017 : Debug: attribute --> User-Name
Fri Jan 27 13:27:28 2017 : Debug: (19) EXPAND %{User-Name}
Fri Jan 27 13:27:28 2017 : Debug: (19) --> h274_free
Fri Jan 27 13:27:28 2017 : Debug: (19) SQL-User-Name set to 'h274_free'
Fri Jan 27 13:27:28 2017 : Debug: rlm_sql (sql): Reserved connection (2)
Fri Jan 27 13:27:28 2017 : Debug: (19) Executing select query: INSERT INTO radius_radacct_active ( acctsessionid, acctuniqueid, username, hotspot_id, device_id, felogin_id, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, servicetype, framedprotocol, framedipaddress ) VALUES ('588b3ca500000003', '477164ffa8f0efb5af020028af87b6fc', 'user_user', 'hotspotid-2', 'deviceis-36', '4988732', '', '192.168.176.1', '00000003', 'Wireless-802.11', FROM_UNIXTIME(1485520048), FROM_UNIXTIME(1485520048 + 1800), '', '', '', '0' << 32 | '0', '0' << 32 | '0', 'calledid', 'A4-70-D6-82-4C-82',
'Login-User', '', '192.168.176.83')
Regards,
Mike
> -----Original Message-----
> From: Freeradius-Users [mailto:freeradius-users-
> bounces+michal.tomaszewski=cca.pl at lists.freeradius.org] On Behalf Of
> Michal Tomaszewski
> Sent: Wednesday, December 28, 2016 3:54 PM
> To: FreeRadius users mailing list <freeradius-users at lists.freeradius.org>
> Subject: RE: Freeradius 3.0.12 problems - redis and mysql pool connections
>
> 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.
>
________________________________________ 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