Proxy issue - Failing proxied request for user error
Dear Group, We have a proxy-based setup but need advice on dropped proxy requests. We were running on 3.0.12 and upgraded to 3.0.19 but not change in behaviour. It's a simple one to one proxy, so packets come in to an external RADIUS server (public IP) and traffic is proxied to an internal one. We are seeing random errors for accounting packets but I can't figure out why. I ran a tcpdump on both sides and can see the traffic is being sent from the master and received on the internal server. But, the internal server must not be handling it nicely it as the master server says: Fri Jul 12 07:38:01 2019 : ERROR: (259008189) ERROR: Failing proxied request for user "689c3148b5a04d73a931534f0dd46f35", due to lack of any response from home server 10.0.0.1 port 1813 Fri Jul 12 07:38:01 2019 : ERROR: (259008191) ERROR: Failing proxied request for user "f1680ea08fff4773b415a4a4a34b9365", due to lack of any response from home server 10.0.0.1 port 1813 Fri Jul 12 07:38:01 2019 : ERROR: (259008193) ERROR: Failing proxied request for user "3b710ab2b4b0497baadd543582b7afc6", due to lack of any response from home server 10.0.0.1 port 1813 Fri Jul 12 07:38:01 2019 : ERROR: (259008194) ERROR: Failing proxied request for user "0f2eec41a0b7488a88d6dc131913538d", due to lack of any response from home server 10.0.0.1 port 1813 Fri Jul 12 07:38:01 2019 : ERROR: (259008195) ERROR: Failing proxied request for user "0c02bd6c5fb2426ea981fa62c51099eb", due to lack of any response from home server 10.0.0.1 port 1813 Fri Jul 12 07:38:01 2019 : ERROR: (259008196) ERROR: Failing proxied request for user "6d6749a71aaf49ec97c472f85af18158", due to lack of any response from home server 10.0.0.1 port 1813 Fri Jul 12 07:38:01 2019 : ERROR: (259008197) ERROR: Failing proxied request for user "39fd72831dbd4236abc055f01bea0d5b", due to lack of any response from home server 10.0.0.1 port 1813 Fri Jul 12 07:38:01 2019 : ERROR: (259008198) ERROR: Failing proxied request for user "1c4c86da12054a099af44d4f0780b666", due to lack of any response from home server 10.0.0.1 port 1813 Notes: 1) The server handles around 50-100 auths/acct packets per second, so nothing major. The majority of requests are proxied without error and the failed ones are not from the same NAS client, spread out across many. 2) This only happens on accounting packets, never auths 3) It happens on Start, Stop and Interim packets 4) It seems to happen in chunks, i.e. i'll get a big block of 30 or so of these errors appear in the lock Any help on how to debug would be much appreciated. Thanks J
The target server or the network is broken between the proxy and the home server. You'll have to go through a process of elimination: Eg... Run home server RADIUS in debug and look to see if its telling you about problems ... Check for lost packets by comparing sent to received (you might have done this already) Check for processing time at the home server (from a packet capture you can trivially get the latency graphed which is the first thing) If you see spikes in latency corresponding to the errors then .... Depending upon what the accounting is doing you might have database issues or filesystem/disks getting overloaded. If the traffic is very bursty you might find you need a larger amount of memory on the home servers socket queues.(This is often a balancing act between loss and latency). Is the home server doing something else that uses up disk/cpu/memory resources periodically Basically its network and server diagnostics and tuning 101s. Find what is slow / dropping the requests fix that and only that and check again. Alister On 12/07/2019, 09:29, "Freeradius-Users on behalf of James Wood" <freeradius-users-bounces+alister.winfield=sky.uk@lists.freeradius.org on behalf of james.wood@purplewifi.com> wrote: Dear Group, We have a proxy-based setup but need advice on dropped proxy requests. We were running on 3.0.12 and upgraded to 3.0.19 but not change in behaviour. It's a simple one to one proxy, so packets come in to an external RADIUS server (public IP) and traffic is proxied to an internal one. We are seeing random errors for accounting packets but I can't figure out why. I ran a tcpdump on both sides and can see the traffic is being sent from the master and received on the internal server. But, the internal server must not be handling it nicely it as the master server says: Fri Jul 12 07:38:01 2019 : ERROR: (259008189) ERROR: Failing proxied request for user "689c3148b5a04d73a931534f0dd46f35", due to lack of any response from home server 10.0.0.1 port 1813 Fri Jul 12 07:38:01 2019 : ERROR: (259008191) ERROR: Failing proxied request for user "f1680ea08fff4773b415a4a4a34b9365", due to lack of any response from home server 10.0.0.1 port 1813 Fri Jul 12 07:38:01 2019 : ERROR: (259008193) ERROR: Failing proxied request for user "3b710ab2b4b0497baadd543582b7afc6", due to lack of any response from home server 10.0.0.1 port 1813 Fri Jul 12 07:38:01 2019 : ERROR: (259008194) ERROR: Failing proxied request for user "0f2eec41a0b7488a88d6dc131913538d", due to lack of any response from home server 10.0.0.1 port 1813 Fri Jul 12 07:38:01 2019 : ERROR: (259008195) ERROR: Failing proxied request for user "0c02bd6c5fb2426ea981fa62c51099eb", due to lack of any response from home server 10.0.0.1 port 1813 Fri Jul 12 07:38:01 2019 : ERROR: (259008196) ERROR: Failing proxied request for user "6d6749a71aaf49ec97c472f85af18158", due to lack of any response from home server 10.0.0.1 port 1813 Fri Jul 12 07:38:01 2019 : ERROR: (259008197) ERROR: Failing proxied request for user "39fd72831dbd4236abc055f01bea0d5b", due to lack of any response from home server 10.0.0.1 port 1813 Fri Jul 12 07:38:01 2019 : ERROR: (259008198) ERROR: Failing proxied request for user "1c4c86da12054a099af44d4f0780b666", due to lack of any response from home server 10.0.0.1 port 1813 Notes: 1) The server handles around 50-100 auths/acct packets per second, so nothing major. The majority of requests are proxied without error and the failed ones are not from the same NAS client, spread out across many. 2) This only happens on accounting packets, never auths 3) It happens on Start, Stop and Interim packets 4) It seems to happen in chunks, i.e. i'll get a big block of 30 or so of these errors appear in the lock Any help on how to debug would be much appreciated. Thanks J - List info/subscribe/unsubscribe? See https://eur01.safelinks.protection.outlook.com/?url=http%3A%2F%2Fwww.freeradius.org%2Flist%2Fusers.html&data=02%7C01%7Calister.winfield%40sky.uk%7C7c3cc8df2e2d4b16c45e08d706a312df%7C68b865d5cf184b2b82a4a4eddb9c5237%7C0%7C1%7C636985169790169002&sdata=BtQkh6EbXUwcI88M06CGaQSscPXblUnD5mLrlDa5K0E%3D&reserved=0 -------------------------------------------------------------------- This email is from an external source. Please do not open attachments or click links from an unknown or suspicious origin. Phishing attempts can be reported by sending them to phishing@sky.uk as attachments. Thank you -------------------------------------------------------------------- Information in this email including any attachments may be privileged, confidential and is intended exclusively for the addressee. The views expressed may not be official policy, but the personal views of the originator. If you have received it in error, please notify the sender by return e-mail and delete it from your system. You should not reproduce, distribute, store, retransmit, use or disclose its contents to anyone. Please note we reserve the right to monitor all e-mail communication through our internal and external networks. SKY and the SKY marks are trademarks of Sky Limited and Sky International AG and are used under licence. Sky UK Limited (Registration No. 2906991), Sky-In-Home Service Limited (Registration No. 2067075), Sky Subscribers Services Limited (Registration No. 2340150) and Sky CP Limited (Registration No. 9513259) are direct or indirect subsidiaries of Sky Limited (Registration No. 2247735). All of the companies mentioned in this paragraph are incorporated in England and Wales and share the same registered office at Grant Way, Isleworth, Middlesex TW7 5QD
Hi Alister I initially thought it was the sql module as we write accounting updates to SQL, but I disabled that for a while and still the same. So, moving forward, I decided to rule out the master server and just test by sending traffic direct to the public IP of the home server directly. I ran a tcpdump against a customer IP sending us accounting packets. When reviewing in Wireshark I can see a (small) percentage of packets that do not show any Accounting-Response reply, and then a few seconds later the NAS re-sends and then we reply as expected. So something on the home server itself is not right, it seems to 'miss' incoming packets. I ran the server in debug mode at the same time as the capture and the first packet did not even show up at all, as if the server never received it. But, the packet was received by the server as per the wireshark capture file. Any thoughts on this? Thanks J
The target server or the network is broken between the proxy and the home server.
You'll have to go through a process of elimination: Eg... Run home server RADIUS in debug and look to see if its telling you about problems ... Check for lost packets by comparing sent to received (you might have done this already) Check for processing time at the home server (from a packet capture you can trivially get the latency graphed which is the first thing) If you see spikes in latency corresponding to the errors then .... Depending upon what the accounting is doing you might have database issues or filesystem/disks getting overloaded. If the traffic is very bursty you might find you need a larger amount of memory on the home servers socket queues.(This is often a balancing act between loss and latency). Is the home server doing something else that uses up disk/cpu/memory resources periodically
Basically its network and server diagnostics and tuning 101s. Find what is slow / dropping the requests fix that and only that and check again.
Alister
And using the radmin stats debug command I can see 8645 dropped in the last few hours, but of course the issue is why :/ radmin> stats client acct requests 221292 responses 212820 dup 8465 invalid 0 malformed 0 bad_authenticator 0 dropped 8465 unknown_types 0 last_packet 1563314693 elapsed.1us 0 elapsed.10us 0 elapsed.100us 18592 elapsed.1ms 166913 elapsed.10ms 26743 elapsed.100ms 553 elapsed.1s 19 elapsed.10s 0 Thanks J
On Jul 16, 2019, at 6:06 PM, James Wood <james.wood@purplewifi.com> wrote:
And using the radmin stats debug command I can see 8645 dropped in the last few hours, but of course the issue is why :/
Because they're duplicates>
radmin> stats client acct requests 221292 responses 212820 dup 8465 ... dropped 8465
When the server doesn't respond to a packet, the NAS retransmits it. If the server is still processing the original packet, the duplicate will be marked as "dup", and then "dropped". FreeRADIUS can handle many 10's of 1000's of packets/s. So if it's slow, it's almost always a database. Alan DeKok.
On Jul 16, 2019, at 5:53 PM, James Wood <james.wood@purplewifi.com> wrote:
I ran a tcpdump against a customer IP sending us accounting packets. When reviewing in Wireshark I can see a (small) percentage of packets that do not show any Accounting-Response reply, and then a few seconds later the NAS re-sends and then we reply as expected. So something on the home server itself is not right, it seems to 'miss' incoming packets.
It's usually a slow database.
I ran the server in debug mode at the same time as the capture and the first packet did not even show up at all, as if the server never received it. But, the packet was received by the server as per the wireshark capture file.
If the OS doesn't deliver packets to FreeRADIUS, then there's little you can change in FreeRADIUS to fix the problem. Alan DeKok.
Is freeradius listening on that interface? Do you have a firewall running on the machine? If so, tcpdump reads the interface before the firewall application, so you will see it there but freeradius will not. -----Original Message----- From: Freeradius-Users <freeradius-users-bounces+paul.root=centurylink.com@lists.freeradius.org> On Behalf Of Alan DeKok Sent: Wednesday, July 17, 2019 5:36 AM To: FreeRadius users mailing list <freeradius-users@lists.freeradius.org> Subject: Re: Proxy issue - Failing proxied request for user error On Jul 16, 2019, at 5:53 PM, James Wood <james.wood@purplewifi.com> wrote:
I ran a tcpdump against a customer IP sending us accounting packets. When reviewing in Wireshark I can see a (small) percentage of packets that do not show any Accounting-Response reply, and then a few seconds later the NAS re-sends and then we reply as expected. So something on the home server itself is not right, it seems to 'miss' incoming packets.
It's usually a slow database.
I ran the server in debug mode at the same time as the capture and the first packet did not even show up at all, as if the server never received it. But, the packet was received by the server as per the wireshark capture file.
If the OS doesn't deliver packets to FreeRADIUS, then there's little you can change in FreeRADIUS to fix the problem. Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html This communication is the property of CenturyLink and may contain confidential or privileged information. Unauthorized use of this communication is strictly prohibited and may be unlawful. If you have received this communication in error, please immediately notify the sender by reply e-mail and destroy all copies of the communication and any attachments.
participants (4)
-
Alan DeKok -
James Wood -
Root, Paul T -
Winfield, Alister