freeradius server module unresponsive
This morning our freeradius server that is doing authentication for our wireless network suddenly started generating the following messages. Our users hare having trouble authenticating to the wireless. It would appear to me that something is stalling and possibly causing authentication to time out. Radius is configured to use our LDAP (389ds) servers as the back end database. Initially I thought that the radius server was having trouble talking to the LDAP servers but I'm able query the LDAP servers from the command line using ldapsearch. In addition we have 4 load balanced servers and from what I can tell it is not stalling on the LDAP queries and neither are any of the other services that use LDAP. The log messages seem to suggest that the rlm_radutmp module is the one blocking. I've deleted and the radius server has recreated the radutmp file as well as the radwtmp and radacct directories. The radius server is supporting about 650 Wireless access points serving about 2000-3000 end user devices. So I though perhaps we were simply overloading the server resources. So I doubled the CPU cores and quadrupled the available memory with no change. The system has been functioning correctly for several months but we are a school and the students came back this week so the load would have increased. Any ideas what might be happening? We are running version 3.0.15 under RHEL 7.5. Fri Aug 24 15:07:16 2018 : Error: (20216) Ignoring duplicate packet from client wireless-aps port 60569 - ID: 138 due to unfinished request in component <core> module <queue> Fri Aug 24 15:07:16 2018 : Error: (20348) Ignoring duplicate packet from client wireless-aps port 51625 - ID: 95 due to unfinished request in component <core> module <queue> Fri Aug 24 15:07:16 2018 : Error: (19987) Ignoring duplicate packet from client wireless-aps port 54077 - ID: 27 due to unfinished request in component <core> module <queue> Fri Aug 24 15:07:17 2018 : Error: (20021) Ignoring duplicate packet from client wireless-aps port 39735 - ID: 166 due to unfinished request in component <core> module <queue> Fri Aug 24 15:07:17 2018 : Error: (20263) Ignoring duplicate packet from client wireless-aps port 58905 - ID: 220 due to unfinished request in component <core> module <queue> Fri Aug 24 15:07:17 2018 : Error: (20335) Ignoring duplicate packet from client wireless-aps port 40611 - ID: 127 due to unfinished request in component <core> module <queue> Fri Aug 24 15:07:17 2018 : Error: (19948) Ignoring duplicate packet from client wireless-aps port 43357 - ID: 117 due to unfinished request in component <core> module <queue> Fri Aug 24 15:07:17 2018 : WARNING: (19230) WARNING: Module rlm_radutmp became unblocked Fri Aug 24 15:07:17 2018 : Error: 1 requests have been waiting in the processing queue for 38 seconds. Check that all databases are running properly! Fri Aug 24 15:07:17 2018 : Error: Unresponsive child for request 19655, in component accounting module radutmp Fri Aug 24 15:07:17 2018 : Error: (20000) Ignoring duplicate packet from client wireless-aps port 36295 - ID: 3 due to unfinished request in component <core> module <queue> Fri Aug 24 15:07:17 2018 : Error: (20381) Ignoring duplicate packet from client wireless-aps port 60114 - ID: 148 due to unfinished request in component <core> module <queue> Fri Aug 24 15:07:17 2018 : Error: (20368) Ignoring duplicate packet from client wireless-aps port 59333 - ID: 200 due to unfinished request in component <core> module <queue> Fri Aug 24 15:07:17 2018 : Error: (20009) Ignoring duplicate packet from client wireless-aps port 60569 - ID: 130 due to unfinished request in component <core> module <queue> Fri Aug 24 15:07:17 2018 : Error: (19950) Ignoring duplicate packet from client wireless-aps port 58285 - ID: 64 due to unfinished request in component <core> module <queue> Fri Aug 24 15:07:17 2018 : Error: (20023) Ignoring duplicate packet from client wireless-aps port 46555 - ID: 152 due to unfinished request in component <core> module <queue> Fri Aug 24 15:07:17 2018 : Error: (20251) Ignoring duplicate packet from client wireless-aps port 60702 - ID: 100 due to unfinished request in component <core> module <queue> Fri Aug 24 15:07:17 2018 : Error: (20020) Ignoring duplicate packet from client wireless-aps port 38080 - ID: 212 due to unfinished request in component <core> module <queue> Fri Aug 24 15:07:18 2018 : Error: (20273) Ignoring duplicate packet from client wireless-aps port 36571 - ID: 4 due to unfinished request in component <core> module <queue> Fri Aug 24 15:07:18 2018 : WARNING: (19247) WARNING: Module rlm_radutmp became unblocked Fri Aug 24 15:07:18 2018 : WARNING: (19248) WARNING: Module rlm_radutmp became unblocked Fri Aug 24 15:07:18 2018 : Error: 1 requests have been waiting in the processing queue for 37 seconds. Check that all databases are running properly! Fri Aug 24 15:07:18 2018 : Error: (20011) Ignoring duplicate packet from client wireless-aps port 50376 - ID: 249 due to unfinished request in component <core> module <queue> Fri Aug 24 15:07:18 2018 : Error: (20405) Ignoring duplicate packet from client wireless-aps port 41224 - ID: 88 due to unfinished request in component <core> module <queue> Fri Aug 24 15:07:18 2018 : Error: Unresponsive child for request 19684, in component accounting module radutmp Fri Aug 24 15:07:18 2018 : Error: Unresponsive child for request 19686, in component accounting module radutmp
On Aug 24, 2018, at 5:05 PM, Timothy A. Holtzen <tah@NebrWesleyan.edu> wrote: This morning our freeradius server that is doing authentication for our wireless network suddenly started generating the following messages. Our users hare having trouble authenticating to the wireless. It would appear to me that something is stalling and possibly causing authentication to time out.
It's usually the database.
Radius is configured to use our LDAP (389ds) servers as the back end database. Initially I thought that the radius server was having trouble talking to the LDAP servers but I'm able query the LDAP servers from the command line using ldapsearch. In addition we have 4 load balanced servers and from what I can tell it is not stalling on the LDAP queries and neither are any of the other services that use LDAP. The log messages seem to suggest that the rlm_radutmp module is the one blocking. I've deleted and the radius server has recreated the radutmp file as well as the radwtmp and radacct directories.
If you're not using those files, just comment out the modules.
The radius server is supporting about 650 Wireless access points serving about 2000-3000 end user devices. So I though perhaps we were simply overloading the server resources. So I doubled the CPU cores and quadrupled the available memory with no change.
This kind of problem is usually lock contention, or maybe waiting for an external resource.
The system has been functioning correctly for several months but we are a school and the students came back this week so the load would have increased.
Sounds like lock contention,
We are running version 3.0.15 under RHEL 7.5.
Fri Aug 24 15:07:16 2018 : Error: (20216) Ignoring duplicate packet from client wireless-aps port 60569 - ID: 138 due to unfinished request in component <core> module <queue>
The server isn't making progress. Input packets are stuck in the input queue, and aren't being serviced.
Fri Aug 24 15:07:17 2018 : WARNING: (19230) WARNING: Module rlm_radutmp became unblocked
Likely because of lock issues. If the radutmp file is large, it can cause problems. To be honest, you should just comment it out, and not use the module. Alan DeKok.
participants (2)
-
Alan DeKok -
Timothy A. Holtzen