No EAP session matching the State variable (and other various messages)
What exactly do error messages like: Sep 30 12:56:36 newdvlanb radiusd[10152]: rlm_eap: No EAP session matching the State variable. Sep 30 12:00:21 dvlanc radiusd[16053]: WARNING: Child is hung for request 782076 in component authenticate module peap. Sep 30 12:57:08 newdvlanb radiusd[10152]: Discarding duplicate request from client resnet1-WiSM-A port 32770 - ID: 126 due to unfinished request 187554 Sep 30 12:58:24 newdvlanb radiusd[10152]: Discarding conflicting packet from client Rich-core-WiSM-E port 32769 - ID: 155 due to recent request 207181. mean? I have attmpted to rectify by seeing if modifying the following configuration options within eap.conf get rid of these. # A list is maintained to correlate EAP-Response # packets with EAP-Request packets. After a # configurable length of time, entries in the list # expire, and are deleted. # timer_expire = 120 # # Help prevent DoS attacks by limiting the number of # sessions that the server is tracking. Most systems # can handle ~30 EAP sessions/s, so the default limit # of 4096 should be OK. max_sessions = 16384 I have even gotten EAP caching (using the Cached-Session-Policy) to two hours now. These error messages especially appear to occur en masse at or near the hour and then seem to abruptly stop: Sep 30 12:59:30 newdvlana radiusd[18407]: rlm_eap: No EAP session matching the State variable. Sep 30 12:59:30 newdvlana radiusd[18407]: rlm_eap: No EAP session matching the State variable. Sep 30 12:59:30 newdvlana radiusd[18407]: rlm_eap: No EAP session matching the State variable. Sep 30 12:59:30 newdvlana radiusd[18407]: rlm_eap: No EAP session matching the State variable. Sep 30 12:59:30 newdvlana radiusd[18407]: rlm_eap: No EAP session matching the State variable. Sep 30 12:59:30 newdvlana radiusd[18407]: rlm_eap: No EAP session matching the State variable. Sep 30 12:59:30 newdvlana radiusd[18407]: rlm_eap: No EAP session matching the State variable. Sep 30 12:59:30 newdvlana radiusd[18407]: rlm_eap: No EAP session matching the State variable. Sep 30 12:59:30 newdvlana radiusd[18407]: rlm_eap: No EAP session matching the State variable. [ SNIPPED ] Sep 30 13:01:37 newdvlana radiusd[18407]: rlm_eap: No EAP session matching the State variable. Sep 30 13:01:37 newdvlana radiusd[18407]: rlm_eap: No EAP session matching the State variable. Sep 30 13:01:37 newdvlana radiusd[18407]: rlm_eap: No EAP session matching the State variable. Sep 30 13:01:38 newdvlana radiusd[18407]: rlm_eap: No EAP session matching the State variable. Sep 30 13:01:38 newdvlana radiusd[18407]: rlm_eap: No EAP session matching the State variable. Sep 30 13:01:38 newdvlana radiusd[18407]: rlm_eap: No EAP session matching the State variable. Sep 30 13:01:38 newdvlana radiusd[18407]: rlm_eap: No EAP session matching the State variable. Which appear in conjunction with: Sep 30 12:57:08 newdvlanb radiusd[10152]: Discarding duplicate request from client resnet1-WiSM-A port 32770 - ID: 126 due to unfinished request 187554 Sep 30 12:58:24 newdvlanb radiusd[10152]: Discarding conflicting packet from client Rich-core-WiSM-E port 32769 - ID: 155 due to recent request 207181. Sep 30 12:58:52 newdvlanb radiusd[10152]: Discarding conflicting packet from client Rich-core-WiSM-E port 32769 - ID: 234 due to recent request 213661. As well as sometimes: Sep 30 12:00:21 dvlanc radiusd[16053]: WARNING: Child is hung for request 782076 in component authenticate module peap. Sep 30 12:01:04 dvlanc radiusd[16053]: WARNING: Child is hung for request 789836 in component authenticate module peap. Sep 30 12:01:07 dvlanc radiusd[16053]: WARNING: Child is hung for request 789836 in component authenticate module peap. An oddity is that the issues appear cross server at about the same times: Sep 30 11:57:25 dvlanc radiusd[16053]: WARNING: Child is hung for request 754502 in component authenticate module peap. Sep 30 11:57:36 newdvlanb radiusd[11924]: WARNING: Child is hung for request 828962 in component authenticate module peap. Any one have any similar battle scars that I can learn from (server performance tweaks, optimizations, etc?). I've optimized as best I can the SQL component. This all seems related to the samba/winbind/ntlm_auth. - John Douglass, Sr. Systems IT/Architect, Georgia Institute of Technology
On 30 Sep 2013, at 18:17, John Douglass <john.douglass@oit.gatech.edu> wrote:
What exactly do error messages like:
Sep 30 12:56:36 newdvlanb radiusd[10152]: rlm_eap: No EAP session matching the State variable.
The State attribute is returned in Access-Challenges by the RADIUS server and is included in subsequent Access-Requests by the NAS. It links up all the rounds of Access-Requests/Access-Challenges required for EAP authentication to complete. That error message is usually displayed when the NAS has corrupted the State attribute contents (unlikely). Or the EAP session associated with the state has expired/or been lost (due to restart). This can also happen if you have a load balancer which is spraying packets over multiple RADIUS servers. All packets for one EAP session need to go to the same EAP server. I believe this also happens where you have EAP packets following a different path through a proxy network, and the final node before your home server changes.
Sep 30 12:00:21 dvlanc radiusd[16053]: WARNING: Child is hung for request 782076 in component authenticate module peap.
peap module is taking a very long time to complete.
Sep 30 12:57:08 newdvlanb radiusd[10152]: Discarding duplicate request from client resnet1-WiSM-A port 32770 - ID: 126 due to unfinished request 187554
The server thread dealing with the original request is blocked (probably in the peap module), the NAS has timed out the original request, and is retransmitting. The server is being smart and discarding the retransmitted request.
Sep 30 12:58:24 newdvlanb radiusd[10152]: Discarding conflicting packet from client Rich-core-WiSM-E port 32769 - ID: 155 due to recent request 207181.
That's like the above message, but probably means a new packet with src ip, src port, dst ip, dst port, id that match an existing packet in the queue has been received, but with a different authenticator.
Sep 30 12:00:21 dvlanc radiusd[16053]: WARNING: Child is hung for request 782076 in component authenticate module peap. Sep 30 12:01:04 dvlanc radiusd[16053]: WARNING: Child is hung for request 789836 in component authenticate module peap. Sep 30 12:01:07 dvlanc radiusd[16053]: WARNING: Child is hung for request 789836 in component authenticate module peap.
An oddity is that the issues appear cross server at about the same times:
Sep 30 11:57:25 dvlanc radiusd[16053]: WARNING: Child is hung for request 754502 in component authenticate module peap. Sep 30 11:57:36 newdvlanb radiusd[11924]: WARNING: Child is hung for request 828962 in component authenticate module peap.
Any one have any similar battle scars that I can learn from (server performance tweaks, optimizations, etc?). I've optimized as best I can the SQL component. This all seems related to the samba/winbind/ntlm_auth.
I'll let someone else answer that one :) Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS Development Team
Hi,
Sep 30 12:56:36 newdvlanb radiusd[10152]: rlm_eap: No EAP session matching the State variable. Sep 30 12:00:21 dvlanc radiusd[16053]: WARNING: Child is hung for request 782076 in component authenticate module peap. Sep 30 12:57:08 newdvlanb radiusd[10152]: Discarding duplicate request from client resnet1-WiSM-A port 32770 - ID: 126 due to unfinished request 187554 Sep 30 12:58:24 newdvlanb radiusd[10152]: Discarding conflicting packet from client Rich-core-WiSM-E port 32769 - ID: 155 due to recent request 207181.
Any one have any similar battle scars that I can learn from (server performance tweaks, optimizations, etc?). I've optimized as best I can the SQL component. This all seems related to the samba/winbind/ntlm_auth.
we are always in a battle with performance and load. you've already had a pretty good description of what the messages mean but I can offer another possible cause - in the PEAP module hang - I would suspect that you have the MSCHAP retry password option set? if so, you're waiting for the user to get around to typing in their details again...and again and again as they get it wrong or typo-fixed by their smartphone or tablet. we see similar messages at busy times of new devices (like start of year) alan
John Douglass wrote:
Any one have any similar battle scars that I can learn from (server performance tweaks, optimizations, etc?). I've optimized as best I can the SQL component. This all seems related to the samba/winbind/ntlm_auth.
FreeRADIUS is dependent on other systems. So if Samba or AD block for 30 seconds, so does FreeRADIUS. In many cases, these errors are the result of something *else* going wrong. FreeRADIUS is complaining, because it noticed the problem, and told you. But there's nothing wrong with FreeRADIUS. You've got to fix the *other* problem to correct the issue. Alan DeKok.
participants (4)
-
A.L.M.Buxey＠lboro.ac.uk -
Alan DeKok -
Arran Cudbard-Bell -
John Douglass