Freeradius 3.0.17 seems to have deadlocked on me.

[Matthew Schumacher]

List,

Anyone see this before?

My radius server is plugging away doing it's job, then suddenly I get this:

Sun Jul  7 10:37:47 2019 : Error: Received conflicting packet from 
client 2.3.23.90 port 53874 - ID: 119 due to unfinished request. Giving 
up on old request.
Sun Jul  7 10:37:50 2019 : Error: Received conflicting packet from 
client 2.3.23.90 port 53874 - ID: 119 due to unfinished request. Giving 
up on old request.
Sun Jul  7 10:37:53 2019 : Error: Received conflicting packet from 
client 2.3.22.14 port 39039 - ID: 36 due to unfinished request. Giving 
up on old request.
Sun Jul  7 10:37:56 2019 : Error: Received conflicting packet from 
client 2.3.22.14 port 39039 - ID: 36 due to unfinished request. Giving 
up on old request.
Sun Jul  7 10:37:56 2019 : Error: Received conflicting packet from 
client 2.3.22.9 port 46417 - ID: 203 due to unfinished request. Giving 
up on old request.
Sun Jul  7 10:37:57 2019 : Error: Received conflicting packet from 
client 2.3.23.75 port 57383 - ID: 228 due to unfinished request. Giving 
up on old request.

Now, I know that's normally because my underlying stack isn't returning 
fast enough, but in this case I never again see a working radius request 
until a restart, and my secondary radius server which relies on the same 
stack works just fine.   The primary continued for a few hours recording 
nothing but logs like above, until it hit the max queue then 
transitioned to:

Sun Jul  7 12:52:26 2019 : Error: Something is blocking the server. 
There are 65536 packets in the queue, waiting to be processed. Ignoring 
the new request.
Sun Jul  7 12:52:26 2019 : Error: (18606025) Ignoring duplicate packet 
from client 2.3.9.250 port 59296 - ID: 120 due to unfinished request in 
component <core> module <queue>
Sun Jul  7 12:52:27 2019 : Error: Something is blocking the server. 
There are 65536 packets in the queue, waiting to be processed. Ignoring 
the new request.
Sun Jul  7 12:52:28 2019 : Error: Something is blocking the server. 
There are 65536 packets in the queue, waiting to be processed. Ignoring 
the new request.
Sun Jul  7 12:52:29 2019 : Error: Something is blocking the server. 
There are 65536 packets in the queue, waiting to be processed. Ignoring 
the new request.
Sun Jul  7 12:52:30 2019 : Error: Something is blocking the server. 
There are 65536 packets in the queue, waiting to be processed. Ignoring 
the new request.
Sun Jul  7 12:52:30 2019 : Error: (18606051) Ignoring duplicate packet 
from client 2.3.9.241 port 32851 - ID: 126 due to unfinished request in 
component <core> module <queue>
Sun Jul  7 12:52:30 2019 : Error: (18606052) Ignoring duplicate packet 
from client 2.3.9.236 port 44942 - ID: 179 due to unfinished request in 
component <core> module <queue>
Sun Jul  7 12:52:30 2019 : Error: (18606053) Ignoring duplicate packet 
from client 2.3.9.236 port 42423 - ID: 180 due to unfinished request in 
component <core> module <queue>
Sun Jul  7 12:52:31 2019 : Error: Something is blocking the server. 
There are 65536 packets in the queue, waiting to be processed. Ignoring 
the new request.
Sun Jul  7 12:52:32 2019 : Error: Something is blocking the server. 
There are 65536 packets in the queue, waiting to be processed. Ignoring 
the new request.
Sun Jul  7 12:52:33 2019 : Error: Something is blocking the server. 
There are 65536 packets in the queue, waiting to be processed. Ignoring 
the new request.
Sun Jul  7 12:52:34 2019 : Error: Something is blocking the server. 
There are 65536 packets in the queue, waiting to be processed. Ignoring 
the new request.
Sun Jul  7 12:52:35 2019 : Error: Something is blocking the server. 
There are 65536 packets in the queue, waiting to be processed. Ignoring 
the new request.
Sun Jul  7 12:52:36 2019 : Error: Something is blocking the server. 
There are 65536 packets in the queue, waiting to be processed. Ignoring 
the new request.
Sun Jul  7 12:52:37 2019 : Error: Something is blocking the server. 
There are 65536 packets in the queue, waiting to be processed. Ignoring 
the new request.

Then nothing but this until I had to kill -9 the process.

The underlying stack is an ldap and sql lookup.  Both of those systems 
are well indexed with care taken to make sure they return quickly.  In 
fact, once I restarted the radiusd daemon, I was able to immediately 
authenticate very quickly:

$ time radtest user password localhost:1645 1 naspassword
Sent Access-Request Id 187 from 0.0.0.0:47859 to 127.0.0.1:1645 length 76
     User-Name = "user"
     User-Password = "password"
     NAS-IP-Address = 192.168.103.7
     NAS-Port = 1
     Message-Authenticator = 0x00
     Cleartext-Password = "password"
Received Access-Accept Id 187 from 127.0.0.1:1645 to 127.0.0.1:47859 
length 57
     Service-Type = Framed-User
     Framed-Protocol = PPP
     Framed-MTU = 1492

real    0m0.035s
user    0m0.017s
sys    0m0.009s

Seems that starting up radtest, making a connection, asking, 
authenticating, and closing out in 35ms is fast enough.

I'm about to upgrade to 3.0.19, but generally don't like the guess and 
check method.  Any reason to believe that this is a bug and if it's been 
fixed?

schu