unavailable database makes freeradius 3.0.9 server unresponsive

[Michal Tomaszewski]

Hello,

We found a problem in freeradius 3.0.9 when database (mysql as well as redis) is not working for a while.

Server: Ubuntu 14.04, fresh install of freeradius 3.0.9 compiled from sources using default settings.

When database is going down server hangs on first processed request and stops processing any further requests.
There is no connection timeout nor any other timeout to database request.
In freeradius 2.x when database was not available server responded with Reject until database was on.
In freeradius 3.0.9 server stops responding to any requests, even when database comes up.

Below there is an example with redis module. The same problem we have when mysql server goes down.

After redis is stopped:

Fri Jul 24 17:44:34 2015 : Debug: (1)     policy usercache.authorize {

Fri Jul 24 17:44:34 2015 : Debug: (1)       update request {

Fri Jul 24 17:44:34 2015 : Debug: rlm_redis (redis): Reserved connection (3)

Fri Jul 24 17:44:34 2015 : Debug: rlm_redis (redis): executing the query: "exists map/usercache/id/"

Fri Jul 24 17:44:34 2015 : ERROR: (1)         Server closed the connection

Fri Jul 24 17:44:34 2015 : Debug: rlm_redis (redis): Reconnecting (3)

Fri Jul 24 17:44:34 2015 : Error: rlm_redis (redis): Problems with redisConnect('10.113.13.245', 6379), Connection refused

There are no other messages on screen when in radius -XXX mode.

There is no timeout for such operation thus server stops processing any requests.
When redis goes up few seconds later it does not enable processing requests.


When radiusd works as a service in the log we have:



Fri Jul 24 17:50:00 2015 : Info: Ready to process requests
****** First radiusclient requests

Fri Jul 24 17:50:21 2015 : Info: rlm_redis (redis): 0 of 5 connections in use.  Need more spares

Fri Jul 24 17:50:21 2015 : Info: rlm_redis (redis): Opening additional connection (5), 1 of 27 pending slots used

Fri Jul 24 17:50:21 2015 : Info: rlm_sql (sql): 0 of 5 connections in use.  Need more spares

Fri Jul 24 17:50:21 2015 : Info: rlm_sql (sql): Opening additional connection (5), 1 of 27 pending slots used

Fri Jul 24 17:50:21 2015 : Auth: (0) Login incorrect (No Auth-Type found: rejecting the user via Post-Auth-Type = Reject): [test8/test] (from client stage-client port 0)

Fri Jul 24 17:50:33 2015 : Info: rlm_redis (redis): Closing connection (3): Hit idle_timeout, was idle for 34 seconds

Fri Jul 24 17:50:33 2015 : Info: rlm_redis (redis): Closing connection (4): Hit idle_timeout, was idle for 33 seconds
****** REDIS STOP + 2 radiusclient requests

Fri Jul 24 17:50:33 2015 : ERROR: (1)         ERROR: Server closed the connection

Fri Jul 24 17:50:33 2015 : Error: rlm_redis (redis): Problems with redisConnect('10.113.13.245', 6379), Connection refused

Fri Jul 24 17:50:38 2015 : Error: (1) Ignoring duplicate packet from client stage-client port 57494 - ID: 197 due to unfinished request in component authorize module

Fri Jul 24 17:50:43 2015 : Error: (1) Ignoring duplicate packet from client stage-client port 57494 - ID: 197 due to unfinished request in component authorize module

Fri Jul 24 17:50:57 2015 : Error: (2) Ignoring duplicate packet from client stage-client port 42331 - ID: 188 due to unfinished request in component authorize module

Fri Jul 24 17:51:02 2015 : Error: (2) Ignoring duplicate packet from client stage-client port 42331 - ID: 188 due to unfinished request in component authorize module

Fri Jul 24 17:51:11 2015 : Error: Unresponsive child for request 1, in component authorize module

Fri Jul 24 17:51:30 2015 : Error: Unresponsive child for request 2, in component authorize module
****** REDIS START + 1 radiusclient request

Fri Jul 24 17:52:24 2015 : Error: (3) Ignoring duplicate packet from client stage-client port 51752 - ID: 89 due to unfinished request in component authorize module

Fri Jul 24 17:52:29 2015 : Error: (3) Ignoring duplicate packet from client stage-client port 51752 - ID: 89 due to unfinished request in component authorize module

Fri Jul 24 17:52:57 2015 : Error: Unresponsive child for request 3, in component authorize module


How to reproduce the issue:


1.       Make a request to the freeradius server using radiusclient.

2.       Stop the database server.

3.       Make another connection to the freeradius server using radiusclient. (the client request will time-out...)

4.       Start the database server.

5.       All following radiusclient requests will time out.

Can anybody suggest what shall be reconfigured in order to keep freeradius responding and properly get Access-reject response when database is unavailable?

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. ________________________________