Hi Guys, I am continuously having below ERRORs in my radius.log. I am using freeradius 3.0.4 with MySQL DB as backend. Please advise. Tue Oct 13 17:19:38 2020 : Error: (30192740) Ignoring duplicate packet from client BRAS port 43706 - ID: 246 due to unfinished request in component <core> module Tue Oct 13 17:19:38 2020 : Error: (30192747) Ignoring duplicate packet from client BRAS port 57012 - ID: 247 due to unfinished request in component <core> module Tue Oct 13 17:19:38 2020 : Error: (30192752) Ignoring duplicate packet from client BRAS port 45769 - ID: 168 due to unfinished request in component <core> module Tue Oct 13 17:19:38 2020 : Error: (30192771) Ignoring duplicate packet from client BRAS port 39617 - ID: 170 due to unfinished request in component <core> module Tue Oct 13 17:19:38 2020 : Error: (30192757) Ignoring duplicate packet from client BRAS port 59376 - ID: 169 due to unfinished request in component <core> module Tue Oct 13 17:19:38 2020 : Error: (30192774) Ignoring duplicate packet from client BRAS port 59596 - ID: 248 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Info: rlm_sql (sql): 0 of 37 connections in use. Need more spares Tue Oct 13 17:19:39 2020 : Info: rlm_sql (sql): Opening additional connection (189864) Tue Oct 13 17:19:39 2020 : Error: (30192791) Ignoring duplicate packet from client BRAS port 48742 - ID: 249 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192800) Ignoring duplicate packet from client BRAS port 52267 - ID: 250 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192771) Ignoring duplicate packet from client BRAS port 39617 - ID: 170 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192774) Ignoring duplicate packet from client BRAS port 59596 - ID: 248 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192791) Ignoring duplicate packet from client BRAS port 48742 - ID: 249 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192800) Ignoring duplicate packet from client BRAS port 52267 - ID: 250 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192825) Ignoring duplicate packet from client BRAS port 47240 - ID: 251 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192840) Ignoring duplicate packet from client BRAS port 33382 - ID: 72 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192825) Ignoring duplicate packet from client BRAS port 47240 - ID: 251 due to unfinished request in component <core> module Tue Oct 13 17:19:40 2020 : Error: (30192840) Ignoring duplicate packet from client BRAS port 33382 - ID: 72 due to unfinished request in component <core> module --
On Oct 13, 2020, at 8:28 AM, Ammad Ali <ammad.ali@rapidcompute.com> wrote:
I am continuously having below ERRORs in my radius.log. I am using freeradius 3.0.4 with MySQL DB as backend. Please advise.
Tue Oct 13 17:19:38 2020 : Error: (30192774) Ignoring duplicate packet from client BRAS port 59596 - ID: 248 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Info: rlm_sql (sql): 0 of 37 connections in use. Need more spares
Your database is down, or unresponsive. No amount of poking FreeRADIUS will make the database work. Go fix the database. Alan DeKok.
Hi, My database is working fine. I am running 4 radius servers using same database. But surprisingly the radius process running same node with the database I am getting the below errors alot ignoring duplicate errors. Tue Oct 13 17:19:38 2020 : Error: (30192774) Ignoring duplicate packet from client BRAS port 59596 - ID: 248 due to unfinished request in component <core> module The node is only being used for AUTH and accounting for some BRAS, but the other instances of radius which are only being used for accounting does not throw above errors. -Ammad On 10/13/2020 5:37 PM, Alan DeKok wrote:
On Oct 13, 2020, at 8:28 AM, Ammad Ali <ammad.ali@rapidcompute.com> wrote:
I am continuously having below ERRORs in my radius.log. I am using freeradius 3.0.4 with MySQL DB as backend. Please advise.
Tue Oct 13 17:19:38 2020 : Error: (30192774) Ignoring duplicate packet from client BRAS port 59596 - ID: 248 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Info: rlm_sql (sql): 0 of 37 connections in use. Need more spares Your database is down, or unresponsive.
No amount of poking FreeRADIUS will make the database work.
Go fix the database.
Alan DeKok.
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
On Oct 13, 2020, at 9:03 AM, Ammad Ali <ammad.ali@rapidcompute.com> wrote:
My database is working fine. I am running 4 radius servers using same database. But surprisingly the radius process running same node with the database I am getting the below errors alot ignoring duplicate errors.
*Something* is blocking the RADIUS server. And *something* is making it have *zero* connections to the database. It's really simple. I've been doing this for about 20 years. I've seen those errors well over a thousand times at this point. It's almost always something *external* blocking the RADIUS server. So you can believe me and fix the problem. Or, believe that your system is somehow unique, and you've run into an issue never seen before. Alan DeKok.
Hi Alan, I have below config in sql mod. pool { min = 50 max = ${thread[pool].max_servers} spare = 10 uses = 0 lifetime = 0 idle_timeout = 60 } I have below config in radiusd.conf max_request_time = 30 cleanup_delay = 10 max_requests = 81920 hostname_lookups = no thread pool { start_servers = 64 max_servers = 256 min_spare_servers = 50 max_spare_servers = 100 max_requests_per_server = 300 auto_limit_acct = yes } Sometime I get these messages. Wed Oct 14 04:30:00 2020 : Warning: rlm_sql (sql): 60 of 60 connections in use. You probably need to increase "spare" Wed Oct 14 04:30:00 2020 : Error: rlm_sql (sql): Cannot open new connection, connection spawning already in progress Wed Oct 14 04:30:00 2020 : Warning: rlm_sql (sql): 60 of 60 connections in use. You probably need to increase "spare" Wed Oct 14 04:30:00 2020 : Error: rlm_sql (sql): Cannot open new connection, connection spawning already in progress Wed Oct 14 04:30:00 2020 : Warning: rlm_sql (sql): 60 of 60 connections in use. You probably need to increase "spare" Wed Oct 14 04:30:00 2020 : Error: rlm_sql (sql): Cannot open new connection, connection spawning already in progress Wed Oct 14 04:30:00 2020 : Warning: rlm_sql (sql): 60 of 60 connections in use. You probably need to increase "spare" Wed Oct 14 04:30:00 2020 : Error: rlm_sql (sql): Cannot open new connection, connection spawning already in progress Wed Oct 14 04:30:00 2020 : Warning: rlm_sql (sql): 61 of 61 connections in use. You probably need to increase "spare" And these Wed Oct 14 04:29:53 2020 : Info: rlm_sql (sql): Opening additional connection (209059) Wed Oct 14 04:29:54 2020 : Info: rlm_sql (sql): 0 of 44 connections in use. Need more spares Wed Oct 14 04:29:54 2020 : Info: rlm_sql (sql): Opening additional connection (209060) Wed Oct 14 04:29:55 2020 : Info: rlm_sql (sql): 6 of 45 connections in use. Need more spares Wed Oct 14 04:29:55 2020 : Info: rlm_sql (sql): Opening additional connection (209061) Wed Oct 14 04:29:55 2020 : Info: rlm_sql (sql): Closing connection (209028): Hit idle_timeout, was idle for 61 seconds Wed Oct 14 04:29:55 2020 : Warning: rlm_sql (sql): You probably need to lower "min" Wed Oct 14 04:29:55 2020 : Info: rlm_sql (sql): Closing connection (209030): Hit idle_timeout, was idle for 61 seconds Wed Oct 14 04:29:55 2020 : Info: rlm_sql (sql): Closing connection (209022): Hit idle_timeout, was idle for 61 seconds Wed Oct 14 04:29:55 2020 : Info: rlm_sql (sql): Closing connection (209023): Hit idle_timeout, was idle for 61 seconds I can see at DB that connections are connected from freeradius. zero connection might means that its currently no connection is being used. But below errors are continuous. Wed Oct 14 14:00:23 2020 : Error: (34868042) Ignoring duplicate packet from client BRAS port 50044 - ID: 9 due to unfinished request in component <core> module Wed Oct 14 14:00:23 2020 : Error: (34868065) Ignoring duplicate packet from client BRAS port 56885 - ID: 56 due to unfinished request in component <core> module I have added below tweaking in sysctl.conf for TCP and UDP tweaking. # allow testing with buffers up to 128MB net.core.rmem_max = 134217728 net.core.wmem_max = 134217728 # increase the length of the processor input queue net.core.netdev_max_backlog = 250000 # increase Linux autotuning TCP buffer limit to 64MB net.ipv4.tcp_rmem = 4096 87380 67108864 net.ipv4.tcp_wmem = 4096 65536 67108864 # recommended default congestion control is htcp net.ipv4.tcp_congestion_control=htcp net.ipv4.udp_rmem_min=131072 net.ipv4.udp_wmem_min=131072 I have checked by turning off the firewall on host. I have checked by tcpdump for 10mins. Approx 75% of auth request and 78% of accounting requests are being responded by freeradius. I have tuned mysql to its optimal level as well but didn't fixed the problem. The system have 200k connected users with 30mins of interm update. Need your advise how to troubleshoot this problem further as the DB and freeradius are on same node (duel 2640v4 processors + 256GB RAM + 800GB SSD) Ammad Ali On 10/13/2020 6:21 PM, Alan DeKok wrote:
On Oct 13, 2020, at 9:03 AM, Ammad Ali <ammad.ali@rapidcompute.com> wrote:
My database is working fine. I am running 4 radius servers using same database. But surprisingly the radius process running same node with the database I am getting the below errors alot ignoring duplicate errors. *Something* is blocking the RADIUS server. And *something* is making it have *zero* connections to the database.
It's really simple. I've been doing this for about 20 years. I've seen those errors well over a thousand times at this point. It's almost always something *external* blocking the RADIUS server.
So you can believe me and fix the problem. Or, believe that your system is somehow unique, and you've run into an issue never seen before.
Alan DeKok.
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
On Oct 14, 2020, at 5:05 AM, Ammad Ali <ammad.ali@rapidcompute.com> wrote:
I have below config in sql mod. ... I have below config in radiusd.conf
None of that matters.
Sometime I get these messages.
Wed Oct 14 04:30:00 2020 : Warning: rlm_sql (sql): 60 of 60 connections in use. You probably need to increase "spare"
The database is slow.
I can see at DB that connections are connected from freeradius. zero connection might means that its currently no connection is being used.
Yes.
But below errors are continuous.
Wed Oct 14 14:00:23 2020 : Error: (34868042) Ignoring duplicate packet from client BRAS port 50044 - ID: 9 due to unfinished request in component <core> module Wed Oct 14 14:00:23 2020 : Error: (34868065) Ignoring duplicate packet from client BRAS port 56885 - ID: 56 due to unfinished request in component <core> module
Yes. Because the database is slow. FreeRADIUS is waiting for a response from the database, and the database is taking forever to respond. There are still packets arriving at FreeRADIUS while the database is slow. Eventually, FreeRADIUS can't make progress. And the NAS retransmits.
I have added below tweaking in sysctl.conf for TCP and UDP tweaking.
That's nice, but it may or may not help.
I have checked by tcpdump for 10mins. Approx 75% of auth request and 78% of accounting requests are being responded by freeradius.
Because the database is slow, and is blocking the server.
I have tuned mysql to its optimal level as well but didn't fixed the problem.
It's clearly not optimal if it can't reply to FreeRADIUS in a timely manner.
The system have 200k connected users with 30mins of interm update.
That should be about ~100 accounting packets per second. Any reasonable MySQL system should be able to keep up. And if you configure FreeRADIUS to just "ack" all accounting packets, it can do 40K+ packets per second. So FreeRADIUS isn't the issue.
Need your advise how to troubleshoot this problem further as the DB and freeradius are on same node (duel 2640v4 processors + 256GB RAM + 800GB SSD)
This isn't a FreeRADIUS issue. It's a database issue. We can give only limited advice for databases, because we didn't write them, and we're not responsible for them. The issue here is that you're stuck on the logs coming from FreeRADIUS. Those logs are not the *cause* of the problem. They're the *side effect* of the problem. You need to track down *why* the database is slow, and fix it. Look at the slow query log for MySQL. There's likely queries which take 5-10s to finish. Alan DeKok.
Just one final thing... in many cases the issue is that the DB has millions to tens of millions of rows. Even SSDs and fast systems will get overwhelmed by large amounts of data. I suspect that if you delete the old rows, the DB will be fast enough. Alan DeKok.
Ammad, I solved this issue tunning my Server TCP/IP Settings Aurélio Em 13/10/2020 09:28, Ammad Ali escreveu:
Hi Guys,
I am continuously having below ERRORs in my radius.log. I am using freeradius 3.0.4 with MySQL DB as backend. Please advise.
Tue Oct 13 17:19:38 2020 : Error: (30192740) Ignoring duplicate packet from client BRAS port 43706 - ID: 246 due to unfinished request in component <core> module Tue Oct 13 17:19:38 2020 : Error: (30192747) Ignoring duplicate packet from client BRAS port 57012 - ID: 247 due to unfinished request in component <core> module Tue Oct 13 17:19:38 2020 : Error: (30192752) Ignoring duplicate packet from client BRAS port 45769 - ID: 168 due to unfinished request in component <core> module Tue Oct 13 17:19:38 2020 : Error: (30192771) Ignoring duplicate packet from client BRAS port 39617 - ID: 170 due to unfinished request in component <core> module Tue Oct 13 17:19:38 2020 : Error: (30192757) Ignoring duplicate packet from client BRAS port 59376 - ID: 169 due to unfinished request in component <core> module Tue Oct 13 17:19:38 2020 : Error: (30192774) Ignoring duplicate packet from client BRAS port 59596 - ID: 248 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Info: rlm_sql (sql): 0 of 37 connections in use. Need more spares Tue Oct 13 17:19:39 2020 : Info: rlm_sql (sql): Opening additional connection (189864) Tue Oct 13 17:19:39 2020 : Error: (30192791) Ignoring duplicate packet from client BRAS port 48742 - ID: 249 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192800) Ignoring duplicate packet from client BRAS port 52267 - ID: 250 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192771) Ignoring duplicate packet from client BRAS port 39617 - ID: 170 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192774) Ignoring duplicate packet from client BRAS port 59596 - ID: 248 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192791) Ignoring duplicate packet from client BRAS port 48742 - ID: 249 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192800) Ignoring duplicate packet from client BRAS port 52267 - ID: 250 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192825) Ignoring duplicate packet from client BRAS port 47240 - ID: 251 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192840) Ignoring duplicate packet from client BRAS port 33382 - ID: 72 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192825) Ignoring duplicate packet from client BRAS port 47240 - ID: 251 due to unfinished request in component <core> module Tue Oct 13 17:19:40 2020 : Error: (30192840) Ignoring duplicate packet from client BRAS port 33382 - ID: 72 due to unfinished request in component <core> module
Hi Aurelio, Can you please advise the settings. - Ammad Ali On 10/13/2020 6:45 PM, Aurélio de Souza Ribeiro Neto wrote:
Ammad,
I solved this issue tunning my Server TCP/IP Settings
Aurélio
Em 13/10/2020 09:28, Ammad Ali escreveu:
Hi Guys,
I am continuously having below ERRORs in my radius.log. I am using freeradius 3.0.4 with MySQL DB as backend. Please advise.
Tue Oct 13 17:19:38 2020 : Error: (30192740) Ignoring duplicate packet from client BRAS port 43706 - ID: 246 due to unfinished request in component <core> module Tue Oct 13 17:19:38 2020 : Error: (30192747) Ignoring duplicate packet from client BRAS port 57012 - ID: 247 due to unfinished request in component <core> module Tue Oct 13 17:19:38 2020 : Error: (30192752) Ignoring duplicate packet from client BRAS port 45769 - ID: 168 due to unfinished request in component <core> module Tue Oct 13 17:19:38 2020 : Error: (30192771) Ignoring duplicate packet from client BRAS port 39617 - ID: 170 due to unfinished request in component <core> module Tue Oct 13 17:19:38 2020 : Error: (30192757) Ignoring duplicate packet from client BRAS port 59376 - ID: 169 due to unfinished request in component <core> module Tue Oct 13 17:19:38 2020 : Error: (30192774) Ignoring duplicate packet from client BRAS port 59596 - ID: 248 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Info: rlm_sql (sql): 0 of 37 connections in use. Need more spares Tue Oct 13 17:19:39 2020 : Info: rlm_sql (sql): Opening additional connection (189864) Tue Oct 13 17:19:39 2020 : Error: (30192791) Ignoring duplicate packet from client BRAS port 48742 - ID: 249 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192800) Ignoring duplicate packet from client BRAS port 52267 - ID: 250 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192771) Ignoring duplicate packet from client BRAS port 39617 - ID: 170 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192774) Ignoring duplicate packet from client BRAS port 59596 - ID: 248 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192791) Ignoring duplicate packet from client BRAS port 48742 - ID: 249 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192800) Ignoring duplicate packet from client BRAS port 52267 - ID: 250 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192825) Ignoring duplicate packet from client BRAS port 47240 - ID: 251 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192840) Ignoring duplicate packet from client BRAS port 33382 - ID: 72 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192825) Ignoring duplicate packet from client BRAS port 47240 - ID: 251 due to unfinished request in component <core> module Tue Oct 13 17:19:40 2020 : Error: (30192840) Ignoring duplicate packet from client BRAS port 33382 - ID: 72 due to unfinished request in component <core> module
Ammad, Depends on your OS. Google for example "Ubuntu TCP/IP tunning" Aurélio Em 13/10/2020 10:49, Ammad Ali escreveu:
Hi Aurelio,
Can you please advise the settings.
- Ammad Ali
On 10/13/2020 6:45 PM, Aurélio de Souza Ribeiro Neto wrote:
Ammad,
I solved this issue tunning my Server TCP/IP Settings
Aurélio
Em 13/10/2020 09:28, Ammad Ali escreveu:
Hi Guys,
I am continuously having below ERRORs in my radius.log. I am using freeradius 3.0.4 with MySQL DB as backend. Please advise.
Tue Oct 13 17:19:38 2020 : Error: (30192740) Ignoring duplicate packet from client BRAS port 43706 - ID: 246 due to unfinished request in component <core> module Tue Oct 13 17:19:38 2020 : Error: (30192747) Ignoring duplicate packet from client BRAS port 57012 - ID: 247 due to unfinished request in component <core> module Tue Oct 13 17:19:38 2020 : Error: (30192752) Ignoring duplicate packet from client BRAS port 45769 - ID: 168 due to unfinished request in component <core> module Tue Oct 13 17:19:38 2020 : Error: (30192771) Ignoring duplicate packet from client BRAS port 39617 - ID: 170 due to unfinished request in component <core> module Tue Oct 13 17:19:38 2020 : Error: (30192757) Ignoring duplicate packet from client BRAS port 59376 - ID: 169 due to unfinished request in component <core> module Tue Oct 13 17:19:38 2020 : Error: (30192774) Ignoring duplicate packet from client BRAS port 59596 - ID: 248 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Info: rlm_sql (sql): 0 of 37 connections in use. Need more spares Tue Oct 13 17:19:39 2020 : Info: rlm_sql (sql): Opening additional connection (189864) Tue Oct 13 17:19:39 2020 : Error: (30192791) Ignoring duplicate packet from client BRAS port 48742 - ID: 249 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192800) Ignoring duplicate packet from client BRAS port 52267 - ID: 250 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192771) Ignoring duplicate packet from client BRAS port 39617 - ID: 170 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192774) Ignoring duplicate packet from client BRAS port 59596 - ID: 248 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192791) Ignoring duplicate packet from client BRAS port 48742 - ID: 249 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192800) Ignoring duplicate packet from client BRAS port 52267 - ID: 250 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192825) Ignoring duplicate packet from client BRAS port 47240 - ID: 251 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192840) Ignoring duplicate packet from client BRAS port 33382 - ID: 72 due to unfinished request in component <core> module Tue Oct 13 17:19:39 2020 : Error: (30192825) Ignoring duplicate packet from client BRAS port 47240 - ID: 251 due to unfinished request in component <core> module Tue Oct 13 17:19:40 2020 : Error: (30192840) Ignoring duplicate packet from client BRAS port 33382 - ID: 72 due to unfinished request in component <core> module
participants (3)
-
Alan DeKok -
Ammad Ali -
Aurélio de Souza Ribeiro Neto