DB handles dying slowly

[Milan Holub]

Hi all,

with cvs head from May 10 I've observed following behaviour(which is
actually hard to debug):

Configuration:
* FreeRADIUS Version 2.0.0-pre0, for host i386-pc-linux-gnu, built on May
10 2007 at 13:56:28
* mysql  Ver 14.7 Distrib 4.1.8, for pc-linux-gnu (i386)
* Linux 2.4.26 , debian-woody

Users + clients stored completely in mysql + doing accounting in mysql.

in my sql.conf:
...
num_sql_socks = 10
...

and if I start freeradius I can see that there are 10 DB handles open by
freeradius.

In my /etc/mysql/my.cnf I have:
...
wait_timeout    = 3600
...
(to close DB handles inactive for longer than 1 hour)

The server is working fine for tens of hours handling 30 authorization
requests and 600 accounting requests in average per hour.

Then after several hours I can see that some DB handles are getting
"retired" - not used by the server for some reason:

mysql> show processlist;
+------+--------+-----------+--------+---------+------+-------+------------------+
| Id   | User   | Host      | db     | Command | Time | State | Info             |
+------+--------+-----------+--------+---------+------+-------+------------------+
| 2359 | radius | localhost | radius | Sleep   |   14 |       | NULL             |
| 2361 | radius | localhost | radius | Sleep   | 1543 |       | NULL             |
| 2364 | radius | localhost | radius | Sleep   |   18 |       | NULL             |
| 2365 | radius | localhost | radius | Sleep   |    5 |       | NULL             |
| 2366 | radius | localhost | radius | Sleep   |    6 |       | NULL             |
| 2854 | root   | localhost | radius | Query   |    0 | NULL  | show processlist |
| 2884 | radius | localhost | radius | Sleep   |   47 |       | NULL             |
+------+--------+-----------+--------+---------+------+-------+------------------+
7 rows in set (0.00 sec)
==> only 6 radius DB handles instead of 10; please note that thread with
ID 2361 is not used by freeradius 1543 seconds for some unknown reason.

Another check after 1 hour shows that the thread with ID 2361 has been
closed(timeout by mysql)
mysql> show processlist;
+------+--------+-----------+--------+---------+------+-------+------------------+
| Id   | User   | Host      | db     | Command | Time | State | Info             |
+------+--------+-----------+--------+---------+------+-------+------------------+
| 2359 | radius | localhost | radius | Sleep   |   17 |       | NULL             |
| 2364 | radius | localhost | radius | Sleep   |    6 |       | NULL             |
| 2365 | radius | localhost | radius | Sleep   |    8 |       | NULL             |
| 2366 | radius | localhost | radius | Sleep   |    9 |       | NULL             |
| 2854 | root   | localhost | radius | Query   |    0 | NULL  | show processlist |
| 2931 | radius | localhost | radius | Sleep   |  177 |       | NULL             |
+------+--------+-----------+--------+---------+------+-------+------------------+
6 rows in set (0.00 sec)

Finaly after another few hours all threads die in similar way and freeradius can't connect to DB:
>>DEBUG
rlm_sql (sql): There are no DB handles to use! skipped 0, tried to connect 0
++[sql] returns fail
>>DEBUG

There is no attempt from freeradius to re-create DB connections and as a
result it stops rejecting users since it does not query the DB...

I've enabled slow queries logging in mysql but there is no slow query
logged. Database server is up and I can connect to it. Anyone has observed
similar behaviour? Any ideas what can be the cause?

Currently the only thing which helps is to restart freeradius. It
creates the DB handles again and works fine for another several hours up to
days...

Please advise.


Milan Holub
holub (at) thenet (dot) ch

--------------------------------------
 TheNet-Internet Services AG,
 im Bernertechnopark, Morgenstr. 129
 CH-3018, Bern, Switzerland
 031 998 4333, Fax 031 998 4330
 http://www.thenet.ch
 http://wlan.thenet.ch
--------------------------------------