Hi John, We were one of the UK universities seeing high load between lectures resulting in large numbers of 'Discarding duplicate request' errors. Alan Buxey (and others) suggested the errors were due to a back-end process, and not FR (also 2.2.0 authenticating with AD). This proved the case as we were able to dramatically reduce the number of these errors by using the IPs of our AD servers and not using DNS. Our initial tests were with a single IP but we now have amended a perl module within our FR build to randomly select the IP of one of our 6 AD servers; not an ideal solution, but as much as we're prepared to do at the moment. Martin.
-----Original Message----- From: freeradius-users- bounces+martin.ubank=uwe.ac.uk@lists.freeradius.org [mailto:freeradius- users-bounces+martin.ubank=uwe.ac.uk@lists.freeradius.org] On Behalf Of John Douglass Sent: 11 November 2013 23:09 To: FreeRadius users mailing list Subject: Question about how to find unfinished requests
I am trying to debug an issue on my servers with the following configuration:
freeradius 2.2.0 -> proxy to AD server running radius for auth -> return auth (yes/no) then my server appends the necessary vlan attributes from its local DB
I am seeing a number of these messages:
Nov 11 17:57:31 dvlanc radiusd[17781]: Received conflicting packet from client resnet4-WiSM-A port 32770 - ID: 18 due to unfinished request 928878. Giving up on old request. Nov 11 17:57:35 dvlanc radiusd[17781]: Received conflicting packet from client Rich-core-WiSM-B port 32770 - ID: 205 due to unfinished request 929613. Giving up on old request. Nov 11 17:57:37 dvlanc radiusd[17781]: Received conflicting packet from client Rich-core-WiSM-B port 32770 - ID: 36 due to unfinished request 929843. Giving up on old request. Nov 11 17:57:41 dvlanc radiusd[17781]: Received conflicting packet from client Rich-core-WiSM-B port 32770 - ID: 205 due to unfinished request 930139. Giving up on old request. Nov 11 17:57:41 dvlanc radiusd[17781]: Received conflicting packet from client Rich-core-WiSM-B port 32770 - ID: 216 due to unfinished request 929934. Giving up on old request. Nov 11 17:57:44 dvlanc radiusd[17781]: Received conflicting packet from client resnet4-WiSM-A port 32770 - ID: 253 due to unfinished request 929666. Giving up on old request. Nov 11 17:57:44 dvlanc radiusd[17781]: Received conflicting packet from client Rich-core-WiSM-B port 32770 - ID: 36 due to unfinished request 930099. Giving up on old request.
How do I view "into the beast" to find the start of these requests? For example, I see no way to locate the stream of events for request 928878 so that I can narrow down where the problem is. My gut says it's located down the chain at the AD server (accessed via the radius protocol) taking too long but I have to prove it before I can get some action.
Would tcpdump/tshark/etc be the way to attempt to follow these authentications or is there a better way with some enhanced logging parameters? If we know the request numbers, how do you pair those with any internal logging (via maybe radmin). It would be useful if, say, all log messages like
Nov 11 17:57:21 dvlanc radiusd[17781]: Login OK: [mbaker66] (from client Rich-core-WiSM-B port 13 cli e0-c9-7a-55-9b-f5) Nov 11 17:57:21 dvlanc radiusd[17781]: Login OK: [fpeterson99] (from client resnet4-WiSM-A port 13 cli a8-96-8a-f3-5f-5b) Nov 11 17:57:21 dvlanc radiusd[17781]: Login OK: [gabriwal3] (from client resnet4-WiSM-A port 13 cli 3c-d0-f8-61-f3-27)
included the request numbers in their logging output (or actually ANY log messages should include the request number it is involved in).
We are having some major problems as the freeradius server gets hit with load between classes and starts losing auth. We are attempting to remove the dependence upon samba by going with configuring a proxy to AD over radius for authentication rather than rely upon an ntlm_auth.
Thanks for any input/advice. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html