RE: Freeradius 3.0.12 problems - mysql pool connections
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/8aaf545d6c011dd5d4a2f... Unfortunately current build of freeradius 3.0.13 makes (in our server once a minute) segmentation fault after SQL INSERT command user@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@lists.freeradius.org] On Behalf Of Michal Tomaszewski Sent: Wednesday, December 28, 2016 3:54 PM To: FreeRadius users mailing list <freeradius-users@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. ________________________________
On Jan 27, 2017, at 7:38 AM, Michal Tomaszewski <Michal.Tomaszewski@cca.pl> wrote:
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/8aaf545d6c011dd5d4a2f...
Unfortunately current build of freeradius 3.0.13 makes (in our server once a minute) segmentation fault after SQL INSERT command
user@server:~$ sudo freeradius -Xx > log20170127b.txt Segmentation fault (core dumped)
There are instructions for getting useful information out of gdb. https://github.com/FreeRADIUS/freeradius-server/blob/v3.0.x/doc/bugs
Last lines in log:
That doesn't contain anything useful. We need the gdb logs. Please follow the documentation link above. Alan DeKok.
Unfortunately current build of freeradius 3.0.13 makes (in our server once a minute) segmentation fault after SQL INSERT command
user@server:~$ sudo freeradius -Xx > log20170127b.txt Segmentation fault (core dumped)
There are instructions for getting useful information out of gdb.
https://github.com/FreeRADIUS/freeradius-server/blob/v3.0.x/doc/bugs
The info is below: cat gdb-radiusd.log Starting program: /usr/sbin/freeradius -f [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1". [New Thread 0x7fffeef31700 (LWP 3991)] [New Thread 0x7fffee730700 (LWP 3992)] [New Thread 0x7fffedf2f700 (LWP 3993)] [New Thread 0x7fffed72e700 (LWP 3994)] [New Thread 0x7fffecf2d700 (LWP 3995)] Thread 4 "freeradius" received signal SIGSEGV, Segmentation fault. [Switching to Thread 0x7fffedf2f700 (LWP 3993)] strlen () at ../sysdeps/x86_64/strlen.S:106 106 ../sysdeps/x86_64/strlen.S: No such file or directory. Id Target Id Frame 1 Thread 0x7ffff7fe9740 (LWP 3986) "freeradius" 0x00007ffff67829e3 in select () at ../sysdeps/unix/syscall-template.S:84 2 Thread 0x7fffeef31700 (LWP 3991) "freeradius" 0x00007ffff6c96827 in futex_abstimed_wait_cancelable (private=0, abstime=0x0, expected=0, futex_word=0x669d10) at ../sysdeps/unix/sysv/linux/futex-internal.h:205 3 Thread 0x7fffee730700 (LWP 3992) "freeradius" 0x00007ffff6c96827 in futex_abstimed_wait_cancelable (private=0, abstime=0x0, expected=0, futex_word=0x669d10) at ../sysdeps/unix/sysv/linux/futex-internal.h:205 * 4 Thread 0x7fffedf2f700 (LWP 3993) "freeradius" strlen () at ../sysdeps/x86_64/strlen.S:106 5 Thread 0x7fffed72e700 (LWP 3994) "freeradius" 0x00007ffff6c96827 in futex_abstimed_wait_cancelable (private=0, abstime=0x0, expected=0, futex_word=0x669d10) at ../sysdeps/unix/sysv/linux/futex-internal.h:205 6 Thread 0x7fffecf2d700 (LWP 3995) "freeradius" 0x00007ffff6c96827 in futex_abstimed_wait_cancelable (private=0, abstime=0x0, expected=0, futex_word=0x669d10) at ../sysdeps/unix/sysv/linux/futex-internal.h:205 Thread 6 (Thread 0x7fffecf2d700 (LWP 3995)): #0 0x00007ffff6c96827 in futex_abstimed_wait_cancelable (private=0, abstime=0x0, expected=0, futex_word=0x669d10) at ../sysdeps/unix/sysv/linux/futex-internal.h:205 __ret = -512 oldtype = 0 err = <optimized out> #1 do_futex_wait (sem=sem@entry=0x669d10, abstime=0x0) at sem_waitcommon.c:111 No locals. #2 0x00007ffff6c968d4 in __new_sem_wait_slow (sem=0x669d10, abstime=0x0) at sem_waitcommon.c:181 _buffer = {__routine = 0x7ffff6c967e0 <__sem_wait_cleanup>, __arg = 0x669d10, __canceltype = 1485522500, __prev = 0x0} err = <optimized out> d = 17179869184 #3 0x00007ffff6c9697a in __new_sem_wait (sem=<optimized out>) at sem_wait.c:29 No locals. #4 0x000000000042df47 in ?? () No symbol table info available. #5 0x00007ffff6c8e6ba in start_thread (arg=0x7fffecf2d700) at pthread_create.c:333 __res = <optimized out> pd = 0x7fffecf2d700 now = <optimized out> unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140737168725760, -6108926390961328707, 0, 140737488348175, 140737168726464, 1, 6108959402645892541, 6108946259262287293}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}} not_first_call = <optimized out> pagesize_m1 = <optimized out> sp = <optimized out> freesize = <optimized out> __PRETTY_FUNCTION__ = "start_thread" #6 0x00007ffff678c82d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109 No locals. Thread 5 (Thread 0x7fffed72e700 (LWP 3994)): #0 0x00007ffff6c96827 in futex_abstimed_wait_cancelable (private=0, abstime=0x0, expected=0, futex_word=0x669d10) at ../sysdeps/unix/sysv/linux/futex-internal.h:205 __ret = -512 oldtype = 0 err = <optimized out> #1 do_futex_wait (sem=sem@entry=0x669d10, abstime=0x0) at sem_waitcommon.c:111 No locals. #2 0x00007ffff6c968d4 in __new_sem_wait_slow (sem=0x669d10, abstime=0x0) at sem_waitcommon.c:181 _buffer = {__routine = 0x7ffff6c967e0 <__sem_wait_cleanup>, __arg = 0x669d10, __canceltype = 1485522500, __prev = 0x0} err = <optimized out> d = 17179869184 #3 0x00007ffff6c9697a in __new_sem_wait (sem=<optimized out>) at sem_wait.c:29 No locals. #4 0x000000000042df47 in ?? () No symbol table info available. #5 0x00007ffff6c8e6ba in start_thread (arg=0x7fffed72e700) at pthread_create.c:333 __res = <optimized out> pd = 0x7fffed72e700 now = <optimized out> unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140737177118464, -6108926390961328707, 0, 140737488348175, 140737177119168, 1, 6108958303671135677, 6108946259262287293}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}} not_first_call = <optimized out> pagesize_m1 = <optimized out> sp = <optimized out> freesize = <optimized out> __PRETTY_FUNCTION__ = "start_thread" #6 0x00007ffff678c82d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109 No locals. Thread 4 (Thread 0x7fffedf2f700 (LWP 3993)): #0 strlen () at ../sysdeps/x86_64/strlen.S:106 No locals. #1 0x00007ffff53f07f2 in ?? () from /usr/lib/freeradius/rlm_sql.so No symbol table info available. #2 0x00007ffff7bc401c in ?? () from /usr/lib/freeradius/libfreeradius-server.so No symbol table info available. #3 0x00007ffff7bc4c0b in ?? () from /usr/lib/freeradius/libfreeradius-server.so No symbol table info available. #4 0x00007ffff7bc4c64 in ?? () from /usr/lib/freeradius/libfreeradius-server.so No symbol table info available. #5 0x00007ffff7bc51ab in ?? () from /usr/lib/freeradius/libfreeradius-server.so No symbol table info available. #6 0x00007ffff7bc66b3 in radius_xlat () from /usr/lib/freeradius/libfreeradius-server.so No symbol table info available. #7 0x0000000000426999 in ?? () No symbol table info available. #8 0x00000000004256e9 in ?? () No symbol table info available. #9 0x00000000004259fc in ?? () No symbol table info available. #10 0x00000000004256e9 in ?? () No symbol table info available. #11 0x00000000004259fc in ?? () No symbol table info available. #12 0x00000000004256e9 in ?? () No symbol table info available. #13 0x00000000004259fc in ?? () No symbol table info available. #14 0x0000000000426b06 in modcall () No symbol table info available. #15 0x00000000004216fd in indexed_modcall () No symbol table info available. #16 0x000000000040fe61 in rad_accounting () No symbol table info available. #17 0x000000000043579a in ?? () No symbol table info available. #18 0x000000000042e208 in ?? () No symbol table info available. #19 0x00007ffff6c8e6ba in start_thread (arg=0x7fffedf2f700) at pthread_create.c:333 __res = <optimized out> pd = 0x7fffedf2f700 now = <optimized out> unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140737185511168, -6108926390961328707, 0, 140737488348175, 140737185511872, 1, 6108957202548895165, 6108946259262287293}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}} not_first_call = <optimized out> pagesize_m1 = <optimized out> sp = <optimized out> freesize = <optimized out> __PRETTY_FUNCTION__ = "start_thread" #20 0x00007ffff678c82d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109 No locals. Thread 3 (Thread 0x7fffee730700 (LWP 3992)): #0 0x00007ffff6c96827 in futex_abstimed_wait_cancelable (private=0, abstime=0x0, expected=0, futex_word=0x669d10) at ../sysdeps/unix/sysv/linux/futex-internal.h:205 __ret = -512 oldtype = 0 err = <optimized out> #1 do_futex_wait (sem=sem@entry=0x669d10, abstime=0x0) at sem_waitcommon.c:111 No locals. #2 0x00007ffff6c968d4 in __new_sem_wait_slow (sem=0x669d10, abstime=0x0) at sem_waitcommon.c:181 _buffer = {__routine = 0x7ffff6c967e0 <__sem_wait_cleanup>, __arg = 0x669d10, __canceltype = 1485522500, __prev = 0x0} err = <optimized out> d = 17179869184 #3 0x00007ffff6c9697a in __new_sem_wait (sem=<optimized out>) at sem_wait.c:29 No locals. #4 0x000000000042df47 in ?? () No symbol table info available. #5 0x00007ffff6c8e6ba in start_thread (arg=0x7fffee730700) at pthread_create.c:333 __res = <optimized out> pd = 0x7fffee730700 now = <optimized out> unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140737193903872, -6108926390961328707, 0, 140737488348175, 140737193904576, 1, 6108964899667160509, 6108946259262287293}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}} not_first_call = <optimized out> pagesize_m1 = <optimized out> sp = <optimized out> freesize = <optimized out> __PRETTY_FUNCTION__ = "start_thread" #6 0x00007ffff678c82d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109 No locals. Thread 2 (Thread 0x7fffeef31700 (LWP 3991)): #0 0x00007ffff6c96827 in futex_abstimed_wait_cancelable (private=0, abstime=0x0, expected=0, futex_word=0x669d10) at ../sysdeps/unix/sysv/linux/futex-internal.h:205 __ret = -512 oldtype = 0 err = <optimized out> #1 do_futex_wait (sem=sem@entry=0x669d10, abstime=0x0) at sem_waitcommon.c:111 No locals. #2 0x00007ffff6c968d4 in __new_sem_wait_slow (sem=0x669d10, abstime=0x0) at sem_waitcommon.c:181 _buffer = {__routine = 0x7ffff6c967e0 <__sem_wait_cleanup>, __arg = 0x669d10, __canceltype = 12061904, __prev = 0x0} err = <optimized out> d = 17179869184 #3 0x00007ffff6c9697a in __new_sem_wait (sem=<optimized out>) at sem_wait.c:29 No locals. #4 0x000000000042df47 in ?? () No symbol table info available. #5 0x00007ffff6c8e6ba in start_thread (arg=0x7fffeef31700) at pthread_create.c:333 __res = <optimized out> pd = 0x7fffeef31700 now = <optimized out> unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140737202296576, -6108926390961328707, 0, 140737488348175, 140737202297280, 1, 6108963802839887293, 6108946259262287293}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}} not_first_call = <optimized out> pagesize_m1 = <optimized out> sp = <optimized out> freesize = <optimized out> __PRETTY_FUNCTION__ = "start_thread" #6 0x00007ffff678c82d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109 No locals. Thread 1 (Thread 0x7ffff7fe9740 (LWP 3986)): #0 0x00007ffff67829e3 in select () at ../sysdeps/unix/syscall-template.S:84 No locals. #1 0x00007ffff79906b4 in fr_event_loop () from /usr/lib/freeradius/libfreeradius-radius.so No symbol table info available. #2 0x000000000040f971 in main () No symbol table info available. ________________________________________ 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. ________________________________
Program received signal SIGSEGV, Segmentation fault. strlen () at ../sysdeps/x86_64/strlen.S:106 106 ../sysdeps/x86_64/strlen.S: No such file or directory. (gdb) bt #0 strlen () at ../sysdeps/x86_64/strlen.S:106 #1 0x00007ffff53f07f2 in ?? () from /usr/lib/freeradius/rlm_sql.so #2 0x00007ffff7bc401c in ?? () from /usr/lib/freeradius/libfreeradius-server.so #3 0x00007ffff7bc4c0b in ?? () from /usr/lib/freeradius/libfreeradius-server.so #4 0x00007ffff7bc4c64 in ?? () from /usr/lib/freeradius/libfreeradius-server.so #5 0x00007ffff7bc51ab in ?? () from /usr/lib/freeradius/libfreeradius-server.so #6 0x00007ffff7bc66b3 in radius_xlat () from /usr/lib/freeradius/libfreeradius-server.so #7 0x0000000000426999 in ?? () #8 0x00000000004256e9 in ?? () #9 0x00000000004259fc in ?? () #10 0x00000000004256e9 in ?? () #11 0x00000000004259fc in ?? () #12 0x0000000000426b06 in modcall () #13 0x00000000004216fd in indexed_modcall () #14 0x0000000000410419 in rad_postauth () #15 0x0000000000434e60 in ?? () #16 0x0000000000431350 in ?? () #17 0x0000000000432dd7 in request_receive () #18 0x000000000041c2be in ?? () #19 0x000000000042f83e in ?? () #20 0x00007ffff7990766 in fr_event_loop () from /usr/lib/freeradius/libfreeradius-radius.so #21 0x000000000040f971 in main () (gdb)
Unfortunately current build of freeradius 3.0.13 makes (in our server once a minute) segmentation fault after SQL INSERT command
user@server:~$ sudo freeradius -Xx > log20170127b.txt Segmentation fault (core dumped)
There are instructions for getting useful information out of gdb.
https://github.com/FreeRADIUS/freeradius-server/blob/v3.0.x/doc/bugs
The info is below: cat gdb-radiusd.log
Starting program: /usr/sbin/freeradius -f [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/x86_64-linux- gnu/libthread_db.so.1". [New Thread 0x7fffeef31700 (LWP 3991)] [New Thread 0x7fffee730700 (LWP 3992)] [New Thread 0x7fffedf2f700 (LWP 3993)] [New Thread 0x7fffed72e700 (LWP 3994)] [New Thread 0x7fffecf2d700 (LWP 3995)]
Thread 4 "freeradius" received signal SIGSEGV, Segmentation fault. [Switching to Thread 0x7fffedf2f700 (LWP 3993)] strlen () at ../sysdeps/x86_64/strlen.S:106 106 ../sysdeps/x86_64/strlen.S: No such file or directory. Id Target Id Frame 1 Thread 0x7ffff7fe9740 (LWP 3986) "freeradius" 0x00007ffff67829e3 in select () at ../sysdeps/unix/syscall-template.S:84 2 Thread 0x7fffeef31700 (LWP 3991) "freeradius" 0x00007ffff6c96827 in futex_abstimed_wait_cancelable (private=0, abstime=0x0, expected=0, futex_word=0x669d10) at ../sysdeps/unix/sysv/linux/futex-internal.h:205 3 Thread 0x7fffee730700 (LWP 3992) "freeradius" 0x00007ffff6c96827 in futex_abstimed_wait_cancelable (private=0, abstime=0x0, expected=0, futex_word=0x669d10) at ../sysdeps/unix/sysv/linux/futex-internal.h:205 * 4 Thread 0x7fffedf2f700 (LWP 3993) "freeradius" strlen () at ../sysdeps/x86_64/strlen.S:106 5 Thread 0x7fffed72e700 (LWP 3994) "freeradius" 0x00007ffff6c96827 in futex_abstimed_wait_cancelable (private=0, abstime=0x0, expected=0, futex_word=0x669d10) at ../sysdeps/unix/sysv/linux/futex-internal.h:205 6 Thread 0x7fffecf2d700 (LWP 3995) "freeradius" 0x00007ffff6c96827 in futex_abstimed_wait_cancelable (private=0, abstime=0x0, expected=0, futex_word=0x669d10) at ../sysdeps/unix/sysv/linux/futex-internal.h:205
Thread 6 (Thread 0x7fffecf2d700 (LWP 3995)): #0 0x00007ffff6c96827 in futex_abstimed_wait_cancelable (private=0, abstime=0x0, expected=0, futex_word=0x669d10) at ../sysdeps/unix/sysv/linux/futex-internal.h:205 __ret = -512 oldtype = 0 err = <optimized out> #1 do_futex_wait (sem=sem@entry=0x669d10, abstime=0x0) at sem_waitcommon.c:111 No locals. #2 0x00007ffff6c968d4 in __new_sem_wait_slow (sem=0x669d10, abstime=0x0) at sem_waitcommon.c:181 _buffer = {__routine = 0x7ffff6c967e0 <__sem_wait_cleanup>, __arg = 0x669d10, __canceltype = 1485522500, __prev = 0x0} err = <optimized out> d = 17179869184 #3 0x00007ffff6c9697a in __new_sem_wait (sem=<optimized out>) at sem_wait.c:29 No locals. #4 0x000000000042df47 in ?? () No symbol table info available. #5 0x00007ffff6c8e6ba in start_thread (arg=0x7fffecf2d700) at pthread_create.c:333 __res = <optimized out> pd = 0x7fffecf2d700 now = <optimized out> unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140737168725760, - 6108926390961328707, 0, 140737488348175, 140737168726464, 1, 6108959402645892541, 6108946259262287293}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}} not_first_call = <optimized out> pagesize_m1 = <optimized out> sp = <optimized out> freesize = <optimized out> __PRETTY_FUNCTION__ = "start_thread" #6 0x00007ffff678c82d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109 No locals.
Thread 5 (Thread 0x7fffed72e700 (LWP 3994)): #0 0x00007ffff6c96827 in futex_abstimed_wait_cancelable (private=0, abstime=0x0, expected=0, futex_word=0x669d10) at ../sysdeps/unix/sysv/linux/futex-internal.h:205 __ret = -512 oldtype = 0 err = <optimized out> #1 do_futex_wait (sem=sem@entry=0x669d10, abstime=0x0) at sem_waitcommon.c:111 No locals. #2 0x00007ffff6c968d4 in __new_sem_wait_slow (sem=0x669d10, abstime=0x0) at sem_waitcommon.c:181 _buffer = {__routine = 0x7ffff6c967e0 <__sem_wait_cleanup>, __arg = 0x669d10, __canceltype = 1485522500, __prev = 0x0} err = <optimized out> d = 17179869184 #3 0x00007ffff6c9697a in __new_sem_wait (sem=<optimized out>) at sem_wait.c:29 No locals. #4 0x000000000042df47 in ?? () No symbol table info available. #5 0x00007ffff6c8e6ba in start_thread (arg=0x7fffed72e700) at pthread_create.c:333 __res = <optimized out> pd = 0x7fffed72e700 now = <optimized out> unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140737177118464, - 6108926390961328707, 0, 140737488348175, 140737177119168, 1, 6108958303671135677, 6108946259262287293}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}} not_first_call = <optimized out> pagesize_m1 = <optimized out> sp = <optimized out> freesize = <optimized out> __PRETTY_FUNCTION__ = "start_thread" #6 0x00007ffff678c82d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109 No locals.
Thread 4 (Thread 0x7fffedf2f700 (LWP 3993)): #0 strlen () at ../sysdeps/x86_64/strlen.S:106 No locals. #1 0x00007ffff53f07f2 in ?? () from /usr/lib/freeradius/rlm_sql.so No symbol table info available. #2 0x00007ffff7bc401c in ?? () from /usr/lib/freeradius/libfreeradius- server.so No symbol table info available. #3 0x00007ffff7bc4c0b in ?? () from /usr/lib/freeradius/libfreeradius- server.so No symbol table info available. #4 0x00007ffff7bc4c64 in ?? () from /usr/lib/freeradius/libfreeradius- server.so No symbol table info available. #5 0x00007ffff7bc51ab in ?? () from /usr/lib/freeradius/libfreeradius- server.so No symbol table info available. #6 0x00007ffff7bc66b3 in radius_xlat () from /usr/lib/freeradius/libfreeradius-server.so No symbol table info available. #7 0x0000000000426999 in ?? () No symbol table info available. #8 0x00000000004256e9 in ?? () No symbol table info available. #9 0x00000000004259fc in ?? () No symbol table info available. #10 0x00000000004256e9 in ?? () No symbol table info available. #11 0x00000000004259fc in ?? () No symbol table info available. #12 0x00000000004256e9 in ?? () No symbol table info available. #13 0x00000000004259fc in ?? () No symbol table info available. #14 0x0000000000426b06 in modcall () No symbol table info available. #15 0x00000000004216fd in indexed_modcall () No symbol table info available. #16 0x000000000040fe61 in rad_accounting () No symbol table info available. #17 0x000000000043579a in ?? () No symbol table info available. #18 0x000000000042e208 in ?? () No symbol table info available. #19 0x00007ffff6c8e6ba in start_thread (arg=0x7fffedf2f700) at pthread_create.c:333 __res = <optimized out> pd = 0x7fffedf2f700 now = <optimized out> unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140737185511168, - 6108926390961328707, 0, 140737488348175, 140737185511872, 1, 6108957202548895165, 6108946259262287293}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}} not_first_call = <optimized out> pagesize_m1 = <optimized out> sp = <optimized out> freesize = <optimized out> __PRETTY_FUNCTION__ = "start_thread" #20 0x00007ffff678c82d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109 No locals.
Thread 3 (Thread 0x7fffee730700 (LWP 3992)): #0 0x00007ffff6c96827 in futex_abstimed_wait_cancelable (private=0, abstime=0x0, expected=0, futex_word=0x669d10) at ../sysdeps/unix/sysv/linux/futex-internal.h:205 __ret = -512 oldtype = 0 err = <optimized out> #1 do_futex_wait (sem=sem@entry=0x669d10, abstime=0x0) at sem_waitcommon.c:111 No locals. #2 0x00007ffff6c968d4 in __new_sem_wait_slow (sem=0x669d10, abstime=0x0) at sem_waitcommon.c:181 _buffer = {__routine = 0x7ffff6c967e0 <__sem_wait_cleanup>, __arg = 0x669d10, __canceltype = 1485522500, __prev = 0x0} err = <optimized out> d = 17179869184 #3 0x00007ffff6c9697a in __new_sem_wait (sem=<optimized out>) at sem_wait.c:29 No locals. #4 0x000000000042df47 in ?? () No symbol table info available. #5 0x00007ffff6c8e6ba in start_thread (arg=0x7fffee730700) at pthread_create.c:333 __res = <optimized out> pd = 0x7fffee730700 now = <optimized out> unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140737193903872, - 6108926390961328707, 0, 140737488348175, 140737193904576, 1, 6108964899667160509, 6108946259262287293}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}} not_first_call = <optimized out> pagesize_m1 = <optimized out> sp = <optimized out> freesize = <optimized out> __PRETTY_FUNCTION__ = "start_thread" #6 0x00007ffff678c82d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109 No locals.
Thread 2 (Thread 0x7fffeef31700 (LWP 3991)): #0 0x00007ffff6c96827 in futex_abstimed_wait_cancelable (private=0, abstime=0x0, expected=0, futex_word=0x669d10) at ../sysdeps/unix/sysv/linux/futex-internal.h:205 __ret = -512 oldtype = 0 err = <optimized out> #1 do_futex_wait (sem=sem@entry=0x669d10, abstime=0x0) at sem_waitcommon.c:111 No locals. #2 0x00007ffff6c968d4 in __new_sem_wait_slow (sem=0x669d10, abstime=0x0) at sem_waitcommon.c:181 _buffer = {__routine = 0x7ffff6c967e0 <__sem_wait_cleanup>, __arg = 0x669d10, __canceltype = 12061904, __prev = 0x0} err = <optimized out> d = 17179869184 #3 0x00007ffff6c9697a in __new_sem_wait (sem=<optimized out>) at sem_wait.c:29 No locals. #4 0x000000000042df47 in ?? () No symbol table info available. #5 0x00007ffff6c8e6ba in start_thread (arg=0x7fffeef31700) at pthread_create.c:333 __res = <optimized out> pd = 0x7fffeef31700 now = <optimized out> unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140737202296576, - 6108926390961328707, 0, 140737488348175, 140737202297280, 1, 6108963802839887293, 6108946259262287293}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}} not_first_call = <optimized out> pagesize_m1 = <optimized out> sp = <optimized out> freesize = <optimized out> __PRETTY_FUNCTION__ = "start_thread" #6 0x00007ffff678c82d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109 No locals.
Thread 1 (Thread 0x7ffff7fe9740 (LWP 3986)): #0 0x00007ffff67829e3 in select () at ../sysdeps/unix/syscall-template.S:84 No locals. #1 0x00007ffff79906b4 in fr_event_loop () from /usr/lib/freeradius/libfreeradius-radius.so No symbol table info available. #2 0x000000000040f971 in main () No symbol table info available. ________________________________________ 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. ________________________________
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
________________________________________ 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. ________________________________
On Jan 27, 2017, at 8:12 AM, Michal Tomaszewski <Michal.Tomaszewski@cca.pl> wrote:
Thread 4 (Thread 0x7fffedf2f700 (LWP 3993)): #0 strlen () at ../sysdeps/x86_64/strlen.S:106 No locals. #1 0x00007ffff53f07f2 in ?? () from /usr/lib/freeradius/rlm_sql.so No symbol table info available. #2 0x00007ffff7bc401c in ?? () from /usr/lib/freeradius/libfreeradius-server.so No symbol table info available. #3 0x00007ffff7bc4c0b in ?? () from /usr/lib/freeradius/libfreeradius-server.so No symbol table info available. #4 0x00007ffff7bc4c64 in ?? () from /usr/lib/freeradius/libfreeradius-server.so No symbol table info available. #5 0x00007ffff7bc51ab in ?? () from /usr/lib/freeradius/libfreeradius-server.so No symbol table info available.
That's not helpful. The documentation contains instructions for building with debugging symbols. Please follow the documentation. Alan DeKok.
That's not helpful. This one is ok?
Fri Jan 27 15:42:27 2017 : Debug: (25) 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 ('588b5bfb00000002', 'b8c70d39220a02cad06916722ecb5e60', 'xxx', '268', 'yyyy', '4997573', '', '192.168.176.1', '00000002', 'Wireless-802.11', FROM_UNIXTIME(1485528147), FROM_UNIXTIME(1485528147 + 1800), '', '', '', '0' << 32 | '0', '0' << 32 | '0', 'zzzz', '10-00-98-37-E5-C0', 'Login-User ', '', '192.168.176.3') Program received signal SIGSEGV, Segmentation fault. strlen () at ../sysdeps/x86_64/strlen.S:106 106 ../sysdeps/x86_64/strlen.S: No such file or directory. (gdb) (gdb) bt #0 strlen () at ../sysdeps/x86_64/strlen.S:106 #1 0x00007ffff53cc025 in sql_xlat (instance=0x9f8500, request=0xbec010, query=0xc19c10 ' ' <repeats 24 times>, "INSERT INTO radius_radacct_active", ' ' <repeats 40 times>, "(", ' ' <repeats 33 times>, "acctsessionid, acctuniqueid,", ' ' <repeats 11 times>, "username,", ' ' <repeats 12 times>..., out=0xc1a690 "", freespace=2048) at src/modules/rlm_sql/rlm_sql.c:251 #2 0x00007ffff7bc590b in xlat_aprint (ctx=0xbec010, request=0xbec010, node=0xbefdf0, escape=0x0, escape_ctx=0x0, lvl=0) at src/main/xlat.c:2320 #3 0x00007ffff7bc5c94 in xlat_process (out=0x7fffffffc648, request=0xbec010, head=0xbefdf0, escape=0x0, escape_ctx=0x0) at src/main/xlat.c:2425 #4 0x00007ffff7bc5fb2 in xlat_expand_struct (out=0x7fffffffc6f8, outlen=128, request=0xbec010, node=0xbefdf0, escape=0x0, escape_ctx=0x0) at src/main/xlat.c:2497 #5 0x00007ffff7bc6160 in xlat_expand (out=0x7fffffffc6f8, outlen=128, request=0xbec010, fmt=0xae33e0 "%{sql:", ' ' <repeats 24 times>, "INSERT INTO radius_radacct_active", ' ' <repeats 40 times>, "(", ' ' <repeats 33 times>, "acctsessionid, acctuniqueid,", ' ' <repeats 11 times>, "username, "..., escape=0x0, escape_ctx=0x0) at src/main/xlat.c:2562 #6 0x00007ffff7bc6406 in radius_xlat (out=0x7fffffffc970 "1", outlen=128, request=0xbec010, fmt=0xae33e0 "%{sql:", ' ' <repeats 24 times>, "INSERT INTO radius_radacct_active", ' ' <repeats 40 times>, "(", ' ' <repeats 33 times>, "acctsessionid, acctuniqueid,", ' ' <repeats 11 times>, "username, "..., escape=0x0, ctx=0x0) at src/main/xlat.c:2621 #7 0x000000000042cc9b in modcall_recurse (request=0xbec010, component=MOD_POST_AUTH, depth=2, entry=0x7fffffffdba0, do_next_sibling=true) at src/main/modcall.c:1014 #8 0x000000000042b0ff in modcall_child (request=0xbec010, component=MOD_POST_AUTH, depth=2, entry=0x7fffffffdb88, c=0xadec00, result=0x7fffffffce20, do_next_sibling=true) at src/main/modcall.c:408 #9 0x000000000042c177 in modcall_recurse (request=0xbec010, component=MOD_POST_AUTH, depth=1, entry=0x7fffffffdb88, do_next_sibling=true) at src/main/modcall.c:789 #10 0x000000000042b0ff in modcall_child (request=0xbec010, component=MOD_POST_AUTH, depth=1, entry=0x7fffffffdb70, c=0xadea00, result=0x7fffffffd500, do_next_sibling=true) at src/main/modcall.c:408 #11 0x000000000042c177 in modcall_recurse (request=0xbec010, component=MOD_POST_AUTH, depth=0, entry=0x7fffffffdb70, do_next_sibling=true) at src/main/modcall.c:789 #12 0x000000000042cfe9 in modcall (component=MOD_POST_AUTH, c=0xade500, request=0xbec010) at src/main/modcall.c:1134 #13 0x000000000042844a in indexed_modcall (comp=MOD_POST_AUTH, idx=0, request=0xbec010) at src/main/modules.c:1028 #14 0x000000000042a970 in process_post_auth (postauth_type=0, request=0xbec010) at src/main/modules.c:2240 #15 0x000000000040f8b7 in rad_postauth (request=0xbec010) at src/main/auth.c:317 #16 0x000000000043ff0c in request_finish (request=0xbec010, action=1) at src/main/process.c:1324 #17 0x0000000000440696 in request_running (request=0xbec010, action=1) at src/main/process.c:1555 #18 0x000000000043f351 in request_queue_or_run (request=0xbec010, process=0x4404fc <request_running>) at src/main/process.c:1015 #19 0x0000000000440ef0 in request_receive (ctx=0xbebd00, listener=0xb73dc0, packet=0xbebd60, client=0x85b6c0, fun=0x40fb0f <rad_authenticate>) at src/main/process.c:1783 #20 0x000000000041938f in auth_socket_recv (listener=0xb73dc0) at src/main/listen.c:1571 #21 0x000000000044861e in event_socket_handler (xel=0x9ef010, fd=9, ctx=0xb73dc0) at src/main/process.c:4585 #22 0x00007ffff797f92a in fr_event_loop (el=0x9ef010) at src/lib/event.c:649 #23 0x000000000044a5e3 in radius_event_process () at src/main/process.c:5658 #24 0x0000000000433abb in main (argc=2, argv=0x7fffffffe648) at src/main/radiusd.c:578 ________________________________________ 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. ________________________________
Hi, Do you need anything more to track the problem? Regards, Mike
This one is ok?
Fri Jan 27 15:42:27 2017 : Debug: (25) 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 ('588b5bfb00000002', 'b8c70d39220a02cad06916722ecb5e60', 'xxx', '268', 'yyyy', '4997573', '', '192.168.176.1', '00000002', 'Wireless-802.11', FROM_UNIXTIME(1485528147), FROM_UNIXTIME(1485528147 + 1800), '', '', '', '0' << 32 | '0', '0' << 32 | '0', 'zzzz', '10-00-98-37-E5- C0', 'Login-User ', '', '192.168.176.3')
Program received signal SIGSEGV, Segmentation fault. strlen () at ../sysdeps/x86_64/strlen.S:106 106 ../sysdeps/x86_64/strlen.S: No such file or directory. (gdb) (gdb) bt #0 strlen () at ../sysdeps/x86_64/strlen.S:106 #1 0x00007ffff53cc025 in sql_xlat (instance=0x9f8500, request=0xbec010, query=0xc19c10 ' ' <repeats 24 times>, "INSERT INTO radius_radacct_active", ' ' <repeats 40 times>, "(", ' ' <repeats 33 times>, "acctsessionid, acctuniqueid,", ' ' <repeats 11 times>, "username,", ' ' <repeats 12 times>..., out=0xc1a690 "", freespace=2048) at src/modules/rlm_sql/rlm_sql.c:251 #2 0x00007ffff7bc590b in xlat_aprint (ctx=0xbec010, request=0xbec010, node=0xbefdf0, escape=0x0, escape_ctx=0x0, lvl=0) at src/main/xlat.c:2320 #3 0x00007ffff7bc5c94 in xlat_process (out=0x7fffffffc648, request=0xbec010, head=0xbefdf0, escape=0x0, escape_ctx=0x0) at src/main/xlat.c:2425 #4 0x00007ffff7bc5fb2 in xlat_expand_struct (out=0x7fffffffc6f8, outlen=128, request=0xbec010, node=0xbefdf0, escape=0x0, escape_ctx=0x0) at src/main/xlat.c:2497 #5 0x00007ffff7bc6160 in xlat_expand (out=0x7fffffffc6f8, outlen=128, request=0xbec010, fmt=0xae33e0 "%{sql:", ' ' <repeats 24 times>, "INSERT INTO radius_radacct_active", ' ' <repeats 40 times>, "(", ' ' <repeats 33 times>, "acctsessionid, acctuniqueid,", ' ' <repeats 11 times>, "username, "..., escape=0x0, escape_ctx=0x0) at src/main/xlat.c:2562 #6 0x00007ffff7bc6406 in radius_xlat (out=0x7fffffffc970 "1", outlen=128, request=0xbec010, fmt=0xae33e0 "%{sql:", ' ' <repeats 24 times>, "INSERT INTO radius_radacct_active", ' ' <repeats 40 times>, "(", ' ' <repeats 33 times>, "acctsessionid, acctuniqueid,", ' ' <repeats 11 times>, "username, "..., escape=0x0, ctx=0x0) at src/main/xlat.c:2621 #7 0x000000000042cc9b in modcall_recurse (request=0xbec010, component=MOD_POST_AUTH, depth=2, entry=0x7fffffffdba0, do_next_sibling=true) at src/main/modcall.c:1014 #8 0x000000000042b0ff in modcall_child (request=0xbec010, component=MOD_POST_AUTH, depth=2, entry=0x7fffffffdb88, c=0xadec00, result=0x7fffffffce20, do_next_sibling=true) at src/main/modcall.c:408 #9 0x000000000042c177 in modcall_recurse (request=0xbec010, component=MOD_POST_AUTH, depth=1, entry=0x7fffffffdb88, do_next_sibling=true) at src/main/modcall.c:789 #10 0x000000000042b0ff in modcall_child (request=0xbec010, component=MOD_POST_AUTH, depth=1, entry=0x7fffffffdb70, c=0xadea00, result=0x7fffffffd500, do_next_sibling=true) at src/main/modcall.c:408 #11 0x000000000042c177 in modcall_recurse (request=0xbec010, component=MOD_POST_AUTH, depth=0, entry=0x7fffffffdb70, do_next_sibling=true) at src/main/modcall.c:789 #12 0x000000000042cfe9 in modcall (component=MOD_POST_AUTH, c=0xade500, request=0xbec010) at src/main/modcall.c:1134 #13 0x000000000042844a in indexed_modcall (comp=MOD_POST_AUTH, idx=0, request=0xbec010) at src/main/modules.c:1028 #14 0x000000000042a970 in process_post_auth (postauth_type=0, request=0xbec010) at src/main/modules.c:2240 #15 0x000000000040f8b7 in rad_postauth (request=0xbec010) at src/main/auth.c:317 #16 0x000000000043ff0c in request_finish (request=0xbec010, action=1) at src/main/process.c:1324 #17 0x0000000000440696 in request_running (request=0xbec010, action=1) at src/main/process.c:1555 #18 0x000000000043f351 in request_queue_or_run (request=0xbec010, process=0x4404fc <request_running>) at src/main/process.c:1015 #19 0x0000000000440ef0 in request_receive (ctx=0xbebd00, listener=0xb73dc0, packet=0xbebd60, client=0x85b6c0, fun=0x40fb0f <rad_authenticate>) at src/main/process.c:1783 #20 0x000000000041938f in auth_socket_recv (listener=0xb73dc0) at src/main/listen.c:1571 #21 0x000000000044861e in event_socket_handler (xel=0x9ef010, fd=9, ctx=0xb73dc0) at src/main/process.c:4585 #22 0x00007ffff797f92a in fr_event_loop (el=0x9ef010) at src/lib/event.c:649 #23 0x000000000044a5e3 in radius_event_process () at src/main/process.c:5658 #24 0x0000000000433abb in main (argc=2, argv=0x7fffffffe648) at src/main/radiusd.c:578 ________________________________________
________________________________________ 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. ________________________________
On Feb 1, 2017, at 7:48 AM, Michal Tomaszewski <Michal.Tomaszewski@cca.pl> wrote:
Do you need anything more to track the problem?
It's not clear what's going on. It looks like the data returned is a string which is not NUL terminated. That's bad, and not entirely under our control. Alan DeKok.
Strongly suspect MySQL client bug here. This is partially user triggered though. By sticking a crapload of whitespace in front of your INSERT query, you're messing up the query prefix detection, so the server is treating it as a select query instead of an insert query. "Executing select query: INSERT " I can fix that at least, and have the xlat function trim the whitespace for prefix detection. As for the rest... I guess mysql_store_result is behaving weirdly when you try and get the result of an insert. I've changed the way the result from mysql_result_next is used. Could you pull v3.0.x and see if it's any better? -Arran Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS Development Team FD31 3077 42EC 7FCD 32FE 5EE2 56CF 27F9 30A8 CAA2
Hi Arran, Thank you for quick fix!
Strongly suspect MySQL client bug here. This is partially user triggered though.
Few previous freeradius versions have not such a problem using the same SQL client library and the same query.
By sticking a crapload of whitespace in front of your INSERT query, you're messing up the query prefix detection, so the server is treating it as a select query instead of an insert query.
"Executing select query: INSERT "
I can fix that at least, and have the xlat function trim the whitespace for prefix detection.
As for the rest... I guess mysql_store_result is behaving weirdly when you try and get the result of an insert.
I've changed the way the result from mysql_result_next is used. Could you pull v3.0.x and see if it's any better?
It seems everything is working properly, even in case of queries having whitespaces on front. Thank you. 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. ________________________________
On Jan 27, 2017, at 9:46 AM, Michal Tomaszewski <Michal.Tomaszewski@cca.pl> wrote:
That's not helpful. This one is ok?
Fri Jan 27 15:42:27 2017 : Debug: (25) Executing select query: INSERT
On closer examination, this seems wrong. You have a whole bunch of spaces before the INSERT text. Delete the spaces, and it should work. In the mean time, we'll track down the underlying crash. Alan DeKok.
participants (4)
-
Alan DeKok -
Arran Cudbard-Bell -
Brian Candler -
Michal Tomaszewski