Pre-release of Version 2.1.8
I've put a pre-release of version 2.1.8 on the web site: http://git.freeradius.org/pre/ Please do some sanity checks, and see if it works for you. This version is from the new "v2.1.x" branch, which is Version 2.1.7, plus *only* bug fixes. The "stable" branch is now planned to become version 2.2.0 in January. It will include TCP transport, among other new features. If there are no major issues, we can release 2.1.8 next week. Alan DeKok.
Alan DeKok <aland@deployingradius.com> writes:
I've put a pre-release of version 2.1.8 on the web site:
Hmm, they were both a bit small. I see 14 and 20 bytes. Something probably went wrong with the packacking script? Bjørn
Bjørn Mork <bjorn@mork.no> writes:
Alan DeKok <aland@deployingradius.com> writes:
I've put a pre-release of version 2.1.8 on the web site:
Hmm, they were both a bit small. I see 14 and 20 bytes. Something probably went wrong with the packacking script?
No problem, I thought. I can just go and checkout the "v2.1.x" branch. But there seems to be no such branch: bjorn@canardo:/usr/local/src/git/freeradius$ git branch -v -r origin/HEAD 85ec4a8 Sign client certs with CA rather than server cert origin/aland e9afde3 Initial revision origin/branch_0_7_0 40391e4 Added notes for 0.7.1 origin/branch_0_9 3a4bda3 Pull patch from the head. origin/branch_1_1 205140d Allow lines at EOF to not have LF. Patch from colubris origin/branch_1_1_7 5f715db Make it easier to do a release origin/master 85ec4a8 Sign client certs with CA rather than server cert origin/release_0_8_0 0a23493 Branch is now 0.8.1 origin/release_1_0 3a81954 Pull from CVS head: Fix the comments about MySQL case sensitive queries. origin/stable 8c32094 Sign client certs with CA rather than server cert bjorn@canardo:/usr/local/src/git/freeradius$ which might explain the empty arhives as well, I guess.. Bjørn
Bjørn Mork wrote:
Alan DeKok <aland@deployingradius.com> writes:
I've put a pre-release of version 2.1.8 on the web site:
Hmm, they were both a bit small. I see 14 and 20 bytes. Something probably went wrong with the packacking script?
Yup. Let me fix that in a bit... Alan DeKok.
Building an rpm on Suse10.3 fails with: Processing files: freeradius-server-dialupadmin-2.1.8-0 Processing files: freeradius-server-devel-2.1.8-0 Processing files: freeradius-server-debuginfo-2.1.8-0 Checking for unpackaged file(s): /usr/lib/rpm/check-files /var/tmp/freeradius-server-2.1.8-build error: Installed (but unpackaged) file(s) found: /etc/raddb/sql/ndb/README RPM build errors: File listed twice: /usr/sbin/rcfreeradius File listed twice: /usr/sbin/rcfreeradius-relay Installed (but unpackaged) file(s) found: /etc/raddb/sql/ndb/README diff -Nru ../SOURCES/freeradius-server-2.1.8/suse/freeradius.spec freeradius-mod.spec --- ../SOURCES/freeradius-server-2.1.8/suse/freeradius.spec 2009-12-04 18:56:04.000000000 +0100 +++ freeradius-mod.spec 2009-12-04 20:20:58.000000000 +0100 @@ -304,8 +304,6 @@ /etc/init.d/freeradius-relay %config /etc/pam.d/radiusd %config /etc/logrotate.d/radiusd -/usr/sbin/rcfreeradius -/usr/sbin/rcfreeradius-relay %dir %attr(755,radiusd,radiusd) /var/lib/radiusd # configs %dir %attr(750,-,radiusd) /etc/raddb @@ -333,6 +331,7 @@ %attr(640,-,radiusd) %config(noreplace) /etc/raddb/users %attr(640,-,radiusd) %config(noreplace) /etc/raddb/experimental.conf %dir %attr(750,-,radiusd) /etc/raddb/certs +/etc/raddb/sql/ndb/README /etc/raddb/certs/Makefile /etc/raddb/certs/README /etc/raddb/certs/xpextensions solves this. With best regards, Norbert Wegener Siemens AG Siemens IT Solutions and Services SIS GO NW PSU SDC AS&INS Bruchstraße 5 45883 Gelsenkirchen, Germany Tel.: +49 (209) 94565716 Fax: +49 (201) 8165581284 mailto:norbert.wegener@siemens.com Siemens Aktiengesellschaft: Chairman of the Supervisory Board: Gerhard Cromme; Managing Board: Peter Loescher, Chairman, President and Chief Executive Officer; Wolfgang Dehen, Heinrich Hiesinger, Joe Kaeser, Barbara Kux, Hermann Requardt, Siegfried Russwurm, Peter Y. Solmssen; Registered offices: Berlin and Munich, Germany; Commercial registries: Berlin Charlottenburg, HRB 12300, Munich, HRB 6684; WEEE-Reg.-No. DE 23691322 ________________________________________ Von: freeradius-users-bounces+norbert.wegener=siemens.com@lists.freeradius.org [freeradius-users-bounces+norbert.wegener=siemens.com@lists.freeradius.org] im Auftrag von Alan DeKok [aland@deployingradius.com] Gesendet: Freitag, 4. Dezember 2009 18:54 An: FreeRadius users mailing list Betreff: Re: Pre-release of Version 2.1.8 Bjørn Mork wrote:
Alan DeKok <aland@deployingradius.com> writes:
I've put a pre-release of version 2.1.8 on the web site:
Hmm, they were both a bit small. I see 14 and 20 bytes. Something probably went wrong with the packacking script?
Yup. Let me fix that in a bit... Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Alan DeKok <aland@deployingradius.com> writes:
Bjørn Mork wrote:
Alan DeKok <aland@deployingradius.com> writes:
I've put a pre-release of version 2.1.8 on the web site:
Hmm, they were both a bit small. I see 14 and 20 bytes. Something probably went wrong with the packacking script?
Yup. Let me fix that in a bit...
Looks very promising so far. I've not seen any problems yet. I'd vote for this as the best FreeRADIUS release ever :-) Bjørn
i guess this version also solved "ASSERT FAILED event.c[2682]: request->ev != NULL" issue? ----- Original Message ---- From: Bjørn Mork <bjorn@mork.no> To: FreeRadius users mailing list <freeradius-users@lists.freeradius.org> Sent: Sun, December 6, 2009 9:46:38 PM Subject: Re: Pre-release of Version 2.1.8 Alan DeKok <aland@deployingradius.com> writes:
Bjørn Mork wrote:
Alan DeKok <aland@deployingradius.com> writes:
I've put a pre-release of version 2.1.8 on the web site:
Hmm, they were both a bit small. I see 14 and 20 bytes. Something probably went wrong with the packacking script?
Yup. Let me fix that in a bit...
Looks very promising so far. I've not seen any problems yet. I'd vote for this as the best FreeRADIUS release ever :-) Bjørn - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Did you check the XLAT fixes in? I saw commits for a couple of fixes but not the modified code in xlat.c...
i guess this version also solved "ASSERT FAILED event.c[2682]: request->ev != NULL" issue?
----- Original Message ---- From: Bjørn Mork <bjorn@mork.no> To: FreeRadius users mailing list <freeradius-users@lists.freeradius.org> Sent: Sun, December 6, 2009 9:46:38 PM Subject: Re: Pre-release of Version 2.1.8
Alan DeKok <aland@deployingradius.com> writes:
Bjørn Mork wrote:
Alan DeKok <aland@deployingradius.com> writes:
I've put a pre-release of version 2.1.8 on the web site:
Hmm, they were both a bit small. I see 14 and 20 bytes. Something probably went wrong with the packacking script?
Yup. Let me fix that in a bit...
Looks very promising so far. I've not seen any problems yet. I'd vote for this as the best FreeRADIUS release ever :-)
Bjørn
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Bjørn Mork <bjorn@mork.no> writes:
Looks very promising so far. I've not seen any problems yet.
Famous Last Words candidate... It took two more hours, then I got: Sun Dec 6 16:23:33 2009 : Proxy: Marking home server 10.10.10.132 port 1645 as dead. Sun Dec 6 16:23:33 2009 : Error: Failed binding to proxy address * port 2727: Address already in use and the server stopped answering requests. It did not exit, and it did not hang (at least it responeded to SIGTERM). It just stopped answering. The server had been running for 45 hours when this happened. I haven't got the faintest idea where to start looking for the bug. Bjørn
Bjørn Mork <bjorn@mork.no> writes:
Bjørn Mork <bjorn@mork.no> writes:
Looks very promising so far. I've not seen any problems yet.
Famous Last Words candidate...
It took two more hours, then I got:
Sun Dec 6 16:23:33 2009 : Proxy: Marking home server 10.10.10.132 port 1645 as dead. Sun Dec 6 16:23:33 2009 : Error: Failed binding to proxy address * port 2727: Address already in use
and the server stopped answering requests. It did not exit, and it did not hang (at least it responeded to SIGTERM). It just stopped answering.
The server had been running for 45 hours when this happened. I haven't got the faintest idea where to start looking for the bug.
I have to correct myself after looking over the logs: The server stopped answering authentication requsts, but it continued to answer accounting requests. Bjørn
Bjørn Mork wrote:
Bjørn Mork <bjorn@mork.no> writes:
The server had been running for 45 hours when this happened. I haven't got the faintest idea where to start looking for the bug.
I have to correct myself after looking over the logs: The server stopped answering authentication requsts, but it continued to answer accounting requests.
Found, fixed, pushed to "v2.1.x" on github. Alan DeKok.
Alan DeKok <aland@deployingradius.com> writes:
Bjørn Mork wrote:
Bjørn Mork <bjorn@mork.no> writes:
The server had been running for 45 hours when this happened. I haven't got the faintest idea where to start looking for the bug.
I have to correct myself after looking over the logs: The server stopped answering authentication requsts, but it continued to answer accounting requests.
Found, fixed, pushed to "v2.1.x" on github.
Yes, now it continues to answer both authentication and accounting requests, but it still stops proxying after a while (where "a while" might be something like 20+ hours and 1+ million auth requests - I have no indication that these values are fixed). The symptoms are that all home servers are marked dead/zombie. Typical obfuscated home_server list in this state: server(bjorn) ~ 71$ radmin -e "show home_server list" 192.168.8.120 1812 auth alive 0 192.168.8.120 1813 acct alive 0 192.168.8.246 1812 auth alive 0 192.168.8.246 1813 acct alive 0 192.168.8.132 1645 auth dead 0 192.168.8.132 1646 acct alive 0 192.168.8.132 1645 auth dead 3 192.168.8.132 1646 acct alive 0 192.168.8.14 1812 auth alive 0 192.168.8.14 1813 acct zombie 0 192.168.8.10 1812 auth alive 0 192.168.8.10 1813 acct zombie 0 192.168.8.210 1812 auth alive 0 192.168.8.210 1813 acct alive 0 192.168.8.50 1812 auth zombie 0 192.168.8.50 1813 acct alive 0 192.168.8.20 1812 auth zombie 0 192.168.8.20 1813 acct alive 0 192.168.8.40 1812 auth zombie 0 192.168.8.40 1813 acct alive 0 192.168.8.44 1812 auth alive 0 192.168.8.44 1813 acct alive 0 192.168.8.216 1812 auth zombie 0 192.168.8.216 1813 acct zombie 0 192.168.8.218 1812 auth alive 0 192.168.8.218 1813 acct zombie 0 192.168.8.1 1645 auth zombie 0 192.168.8.1 1646 acct zombie 4 192.168.8.137 1645 auth alive 1 192.168.8.137 1646 acct dead 0 192.168.8.150 1812 auth zombie 0 192.168.8.150 1813 acct alive 0 192.168.8.158 1812 auth zombie 0 192.168.8.158 1813 acct zombie 0 192.168.8.222 1812 auth zombie 0 192.168.8.222 1813 acct zombie 0 192.168.8.6 1812 auth zombie 6 192.168.8.6 1813 acct alive 0 192.168.8.27 1812 auth zombie 2 192.168.8.27 1813 acct zombie 0 192.168.8.158 1812 auth zombie 0 192.168.8.158 1813 acct zombie 0 192.168.8.4 1812 auth alive 0 192.168.8.4 1813 acct zombie 0 192.168.9.6 1812 auth zombie 4 192.168.9.6 1813 acct zombie 0 There are a number of servers marked "alive", but these are all servers which have been revived after the fixed period. When used, they will be marked dead/zombie again. I'm running the v2.1.x branch from github, with cbbcb5232261c5b28093c3a97d6da2a16c9e06af being the last commit. Now, I wish I could say than I was sure that some other version did not have the same problem, but I'm not. I'm afraid I haven't been running any of them continuously for a long enough period to be completely sure. But I will test that now, starting with the stable branch from git.freeradius.org, commit d7b4f003477644978f3fefa694305dce9b5dc8bf, which was the last point where things seemed to work Bjørn
On Tue, Dec 08, 2009 at 10:10:11AM +0100, Bj??rn Mork wrote:
The symptoms are that all home servers are marked dead/zombie. Typical obfuscated home_server list in this state:
server(bjorn) ~ 71$ radmin -e "show home_server list" 192.168.8.120 1812 auth alive 0 192.168.8.246 1812 auth alive 0 192.168.8.132 1645 auth dead 0 192.168.8.132 1645 auth dead 3 192.168.8.14 1812 auth alive 0 192.168.8.10 1812 auth alive 0 192.168.8.210 1812 auth alive 0 192.168.8.50 1812 auth zombie 0 192.168.8.20 1812 auth zombie 0
There are a number of servers marked "alive", but these are all servers which have been revived after the fixed period. When used, they will be marked dead/zombie again.
What does the log file say? There should be many messages marked 'Proxy' in the v2.1.x branch since a couple of weeks ago, and definitely in your case if they keep changing state so often.
But I will test that now, starting with the stable branch from git.freeradius.org, commit d7b4f003477644978f3fefa694305dce9b5dc8bf, which was the last point where things seemed to work
BTW you could probably do a git bisect. -- 2. That which causes joy or happiness.
Josip Rodin <joy@entuzijast.net> writes:
On Tue, Dec 08, 2009 at 10:10:11AM +0100, Bj??rn Mork wrote:
The symptoms are that all home servers are marked dead/zombie. Typical obfuscated home_server list in this state:
server(bjorn) ~ 71$ radmin -e "show home_server list" 192.168.8.120 1812 auth alive 0 192.168.8.246 1812 auth alive 0 192.168.8.132 1645 auth dead 0 192.168.8.132 1645 auth dead 3 192.168.8.14 1812 auth alive 0 192.168.8.10 1812 auth alive 0 192.168.8.210 1812 auth alive 0 192.168.8.50 1812 auth zombie 0 192.168.8.20 1812 auth zombie 0
There are a number of servers marked "alive", but these are all servers which have been revived after the fixed period. When used, they will be marked dead/zombie again.
What does the log file say? There should be many messages marked 'Proxy' in the v2.1.x branch since a couple of weeks ago, and definitely in your case if they keep changing state so often.
Sure. You'll find all "Proxy:" prefixed messages sinc log rotation at midnight here: http://www.mork.no/~bjorn/fr-218-prerelease-proxying.log (It's 300 kB, so it was a little over the limit for this list) The addresses have been replaced using the same pattern as for the "home_server list", so they are directly comparable. You'll notice that some of the home servers are truly unavailable. This is unfortunately something we have to live with. There are also some servers which are unavailable at certain times, but mostly available. At approximately 08:40 something happens, and a lot of servers are flagged as dead or zombie. This could of course have been caused by network problems, but there was no such problem at this time. Proxying goes over the same interface as the rest of the traffic, and non-proxied authentication and accounting continued to work without problems. The home servers are in a number of different networks, and any network incident taking them all out would be very visible. The server was restarted at 09:35 and you'll see that only the usual suspects are logged as zombies after this.
But I will test that now, starting with the stable branch from git.freeradius.org, commit d7b4f003477644978f3fefa694305dce9b5dc8bf, which was the last point where things seemed to work
BTW you could probably do a git bisect.
Yes, if I can verify the good versions... As I said, I'm not entirely sure that there actually was a good version. And it looks like each positive test will have to take 3+ days. Unless I can find out what triggers this. Bjørn
At approximately 08:40 something happens, and a lot of servers are flagged as dead or zombie.
This could of course have been caused by network problems, but there was no such problem at this time. Proxying goes over the same interface as
When it fails, is it always at night? If so, could it be related to network load - perhaps backups that are running? You could try capturing the output from a continuous ping to see if you start getting timeouts or really long response times between FR and one of the proxy servers that are having problems (obviously you'd want to check before, during and after the problem occurs). Said differently, maybe this isn't a FreeRadius problem..
Garber, Neal wrote:
When it fails, is it always at night? If so, could it be related to network load - perhaps backups that are running? You could try capturing the output from a continuous ping to see if you start getting timeouts or really long response times between FR and one of the proxy servers that are having problems (obviously you'd want to check before, during and after the problem occurs).
Said differently, maybe this isn't a FreeRadius problem..
The log messages show a lot of: No outstanding request was found for reply ... This indicates that the home server responded MANY seconds after the request. This indicates one (or more of) a) extremely bad network connection b) a home server on a *very* slow box c) an overloaded home server (1000's of packets/s) There is *nothing* you can do to the proxy that will solve those issues. Get the upstream home servers to run properly. Poking at FreeRADIUS should be a lower priority. Alan DeKok.
Alan DeKok <aland@deployingradius.com> writes:
Garber, Neal wrote:
When it fails, is it always at night? If so, could it be related to network load - perhaps backups that are running? You could try capturing the output from a continuous ping to see if you start getting timeouts or really long response times between FR and one of the proxy servers that are having problems (obviously you'd want to check before, during and after the problem occurs).
Said differently, maybe this isn't a FreeRadius problem..
Backups and other management activity is done on a separate network (separate NIC, separate switch etc), so it won't affect operation.
The log messages show a lot of:
No outstanding request was found for reply ...
This indicates that the home server responded MANY seconds after the request. This indicates one (or more of)
a) extremely bad network connection
b) a home server on a *very* slow box
c) an overloaded home server (1000's of packets/s)
There is *nothing* you can do to the proxy that will solve those issues.
Yes, these are (all?) true for some of the home servers, and there is of course nothing my servers can do about those. I realize that FreeRADIUS can't do magic :-) That's not a problem. You provide a bad/buggy/lousy home radius server for your users, then you get bad/buggy/lousy radius service. My problem is that this affects *all* proxied realms, including those with perfect radius servers. I know, because one of those realms is our own, running FreeRADIUS on another set of servers. You'll notice that all the "No outstanding request was found " messages were caused by only 2 slow servers in 2 different realms. That shouldn't bring down proxying for the other 20 realms.
Get the upstream home servers to run properly. Poking at FreeRADIUS should be a lower priority.
I have to agree. But that's the ideal world. In real life, I need FreeRADIUS to survive anything a home server does without any effect on other realms than the one served by the bad home server. Bjørn
Hi,
My problem is that this affects *all* proxied realms, including those with perfect radius servers. I know, because one of those realms is our own, running FreeRADIUS on another set of servers.
oh - thats a perfect system for doing the status server queries on. it would be good to show that there are no issues on that server (as part of the bigger picture) when you have the status server stuff enabled on it.... that still wont fix the bigger picture but might get you some leverage.
You'll notice that all the "No outstanding request was found " messages were caused by only 2 slow servers in 2 different realms. That shouldn't bring down proxying for the other 20 realms.
hmmm, true. alan
Bjørn Mork wrote:
My problem is that this affects *all* proxied realms, including those with perfect radius servers. I know, because one of those realms is our own, running FreeRADIUS on another set of servers.
You'll notice that all the "No outstanding request was found " messages were caused by only 2 slow servers in 2 different realms. That shouldn't bring down proxying for the other 20 realms.
Quite possibly, yes. The issue is that FreeRADIUS has a limited amount of packets it can proxy without receiving a response. Once that limit is reached, proxying starts having issues. This limit is around 8K packets in 2.1.x, and will be 64K packets in 2.2.x. So if you're getting 500 packets/s for a home server, 16s after it goes down, all 8k "slots" will be used.
In real life, I need FreeRADIUS to survive anything a home server does without any effect on other realms than the one served by the bad home server.
If you can verify that commit d7b4f003477 works, then that should help track down the issue. Until then, configuring status-checks && local detail files will definitely help. I would recommend doing that *anyways* for network stability. Alan DeKok.
This limit is around 8K packets in 2.1.x, and will be 64K packets in 2.2.x. So if you're getting 500 packets/s for a home server, 16s after it goes down, all 8k "slots" will be used.
I'm not sure if this is feasible and/or easy to implement, but I thought I'd ask.. As a suggestion, can there be a separate pool for each home server? It seems like increasing the limit of a shared pool just lengthens the time before the same problem can occur. If each home server had a separate pool, then one home server could not affect the others, regardless of the size of the pool.
Garber, Neal wrote:
This limit is around 8K packets in 2.1.x, and will be 64K packets in 2.2.x. So if you're getting 500 packets/s for a home server, 16s after it goes down, all 8k "slots" will be used.
I'm not sure if this is feasible and/or easy to implement, but I thought I'd ask.. As a suggestion, can there be a separate pool for each home server? It seems like increasing the limit of a shared pool just lengthens the time before the same problem can occur. If each home server had a separate pool, then one home server could not affect the others, regardless of the size of the pool.
Yes and no. Let me explain in more detail. In 2.1.x, there are a limited number of UDP sockets that can be used for proxied traffic. This number is limited to 32, in src/lib/packet.c, macro MAX_SOCKETS. Due to the "unconnected" nature of UDP, each socket can be used to send packets to *multiple* home servers at the same time. So this means that the limitation isn't really 32 sockets *total*, but (semantically) 32 sockets for every home server. Due to RADIUS limitations, it can only have 256 packets outstanding for any combination of (src/ds IP/port). So each socket can send 256 packets to every home server. Since there are 32 sockets and 256 packets/s, a proxy can handle 8192 packets sent to *each* home server. If you have 13 home servers, then the proxy can send 13*8192 = ~100K packets. Packets are added to the "outstanding" list when proxied, and removed a short time after a response is received from the home server. If no response is received from the home server, the packets are removed 30s after they were received. Once a packet has been removed from the "outstanding" list, its place can be used by a new packet that is proxied using the same socket/id to the same home server. To answer your question: Yes, there is a separate pool for each home server. However, they share a global set of sockets. The *intent* is for the pools to not affect each other. i.e. "filling up" all 8K slots for one home server should have no affect on other home servers. Alan DeKok.
On Tue, Dec 08, 2009 at 03:43:14PM +0100, Alan DeKok wrote:
Garber, Neal wrote:
This limit is around 8K packets in 2.1.x, and will be 64K packets in 2.2.x. So if you're getting 500 packets/s for a home server, 16s after it goes down, all 8k "slots" will be used.
In 2.1.x, there are a limited number of UDP sockets that can be used for proxied traffic. This number is limited to 32, in src/lib/packet.c, macro MAX_SOCKETS.
Due to RADIUS limitations, it can only have 256 packets outstanding for any combination of (src/ds IP/port). So each socket can send 256 packets to every home server.
Packets are added to the "outstanding" list when proxied, and removed a short time after a response is received from the home server. If no response is received from the home server, the packets are removed 30s after they were received.
Once a packet has been removed from the "outstanding" list, its place can be used by a new packet that is proxied using the same socket/id to the same home server.
Which reminds me - the other day I had a situation where a NAS was rebooted and ~300 users immediately tried to reconnect and authenticated over a FreeRADIUS 2.0.4 server, which in turn tried to authenticate them over its two home_servers set up as fail-over, but neither of them with status_check. Sadly, this started failing horribly - it seemed to overload the primary home_server, entering a peculiar pattern - condensed for readability and some private info obfuscation: 1 Auth: Login OK: 10 Error: Rejecting request <number> due to lack of any response from home server home_server_ip_5 port 1812 1 Auth: Login OK: 2 Error: Rejecting request <number> due to lack of any response from home server home_server_ip_5 port 1812 1 Auth: Login incorrect (Home Server says so): 4 Error: Rejecting request <number> due to lack of any response from home server home_server_ip_5 port 1812 1 Auth: Login OK: 4 Error: Rejecting request <number> due to lack of any response from home server home_server_ip_5 port 1812 1 Auth: Login OK: 2 Error: Rejecting request <number> due to lack of any response from home server home_server_ip_5 port 1812 2 Auth: Login OK: 2 Error: Rejecting request <number> due to lack of any response from home server home_server_ip_5 port 1812 1 Auth: Login OK: 11 Error: Rejecting request <number> due to lack of any response from home server home_server_ip_5 port 1812 1 Auth: Login OK: 86 Error: Rejecting request <number> due to lack of any response from home server home_server_ip_5 port 1812 1 Proxy: No outstanding request was found for proxy reply from home server home_server_ip_5 port 1812 - ID 87 19 Error: Rejecting request <number> due to lack of any response from home server home_server_ip_5 port 1812 1 Proxy: No outstanding request was found for proxy reply from home server home_server_ip_5 port 1812 - ID 252 7 Error: Rejecting request <number> due to lack of any response from home server home_server_ip_5 port 1812 1 Error: Received Access-Accept packet from client home_server_ip_5 port 1812 with invalid signature (err=2)! (Shared secret is incorrect.) Dropping packet without response. 5 Error: Rejecting request <number> due to lack of any response from home server home_server_ip_5 port 1812 1 Error: Received Access-Accept packet from client home_server_ip_5 port 1812 with invalid signature (err=2)! (Shared secret is incorrect.) Dropping packet without response. 33 Error: Rejecting request <number> due to lack of any response from home server home_server_ip_5 port 1812 1 Proxy: No outstanding request was found for proxy reply from home server home_server_ip_5 port 1812 - ID 61 7 Error: Rejecting request <number> due to lack of any response from home server home_server_ip_5 port 1812 1 Proxy: No outstanding request was found for proxy reply from home server home_server_ip_5 port 1812 - ID 120 4 Error: Rejecting request <number> due to lack of any response from home server home_server_ip_5 port 1812 1 Proxy: No outstanding request was found for proxy reply from home server home_server_ip_5 port 1812 - ID 112 6 Error: Rejecting request <number> due to lack of any response from home server home_server_ip_5 port 1812 1 Error: Received Access-Accept packet from client home_server_ip_5 port 1812 with invalid signature (err=2)! (Shared secret is incorrect.) Dropping packet without response. 2 Error: Rejecting request <number> due to lack of any response from home server home_server_ip_5 port 1812 1 Error: Received Access-Accept packet from client home_server_ip_5 port 1812 with invalid signature (err=2)! (Shared secret is incorrect.) Dropping packet without response. 20 Error: Rejecting request <number> due to lack of any response from home server home_server_ip_5 port 1812 1 Proxy: No outstanding request was found for proxy reply from home server home_server_ip_5 port 1812 - ID 161 12 Error: Rejecting request <number> due to lack of any response from home server home_server_ip_5 port 1812 1 Error: Received Access-Accept packet from client home_server_ip_5 port 1812 with invalid signature (err=2)! (Shared secret is incorrect.) Dropping packet without response. 4 Error: Rejecting request <number> due to lack of any response from home server home_server_ip_5 port 1812 1 Proxy: No outstanding request was found for proxy reply from home server home_server_ip_5 port 1812 - ID 243 11 Error: Rejecting request <number> due to lack of any response from home server home_server_ip_5 port 1812 1 Proxy: No outstanding request was found for proxy reply from home server home_server_ip_5 port 1812 - ID 203 1 Proxy: No outstanding request was found for proxy reply from home server home_server_ip_5 port 1812 - ID 176 1 Error: Rejecting request <number> due to lack of any response from home server home_server_ip_5 port 1812 1 Proxy: No outstanding request was found for proxy reply from home server home_server_ip_5 port 1812 - ID 6 10 Error: Rejecting request <number> due to lack of any response from home server home_server_ip_5 port 1812 1 Error: Received Access-Accept packet from client home_server_ip_5 port 1812 with invalid signature (err=2)! (Shared secret is incorrect.) Dropping packet without response. 3 Error: Rejecting request <number> due to lack of any response from home server home_server_ip_5 port 1812 1 Proxy: No outstanding request was found for proxy reply from home server home_server_ip_5 port 1812 - ID 248 2 Error: Rejecting request <number> due to lack of any response from home server home_server_ip_5 port 1812 1 Proxy: No outstanding request was found for proxy reply from home server home_server_ip_5 port 1812 - ID 69 [...] This went on for a while, before I was alerted about the outage, came in and started checking what is going on - using radtest showed that the primary home_server was indeed ignoring my requests, but the secondary one was replying as if there was nothing going on. So I tried the poor man's solution - I shuffled them manually, restarted FreeRADIUS, and then it started authenticating them, before it seemingly DoSed that one and entered a very similar pattern of brokenness. I did the manual shuffle a few more times, by which time most users were connected, and the problem worked itself out. Can any conclusions be drawn from this? I send over the detailed logs if necessary. -- 2. That which causes joy or happiness.
Hi,
1 Error: Received Access-Accept packet from client home_server_ip_5 port 1812 with invalid signature (err=2)! (Shared secret is incorrect.) Dropping packet without response.
well, theres a problem with shared secret there that needs to be ironed out
Can any conclusions be drawn from this? I send over the detailed logs if necessary.
in the main it looks like the remote RADIUS server was sloooooow to respond to authentications...and the other one likewise after you flipped them across. but just 300 users caused this? alan
Josip Rodin wrote:
Which reminds me - the other day I had a situation where a NAS was rebooted and ~300 users immediately tried to reconnect and authenticated over a FreeRADIUS 2.0.4 server, which in turn tried to authenticate them over its two home_servers set up as fail-over, but neither of them with status_check.
Sadly, this started failing horribly - it seemed to overload the primary home_server, entering a peculiar pattern - condensed for readability and some private info obfuscation:
Then the home servers are *extremely* slow. Sending 300 packets over the course of a second or two wouldn't overload a 486.
1 Proxy: No outstanding request was found for proxy reply from home server home_server_ip_5 port 1812 - ID 87
Look at the messages *before* that one. The proxy: a) proxies packet 1 b) gives up on it after a time c) proxies a new packet 2 d) receives a reply for packet 1 e) logs this message as "Huh?"
So I tried the poor man's solution - I shuffled them manually, restarted FreeRADIUS, and then it started authenticating them, before it seemingly DoSed that one and entered a very similar pattern of brokenness.
300 packets is a DoS for a RADIUS server? Wow... that's a *bad* server.
Can any conclusions be drawn from this? I send over the detailed logs if necessary.
The home servers are pathetic. Also, the proxy && fail-over algorithms in 2.1.x are much better than 2.0.4. Alan DeKok.
On Wed, Dec 09, 2009 at 07:50:05AM +0100, Alan DeKok wrote:
Then the home servers are *extremely* slow. Sending 300 packets over the course of a second or two wouldn't overload a 486.
AFAIK they are not 486s :) but we're still investigating what made them so.
Can any conclusions be drawn from this? I send over the detailed logs if necessary.
The home servers are pathetic.
Also, the proxy && fail-over algorithms in 2.1.x are much better than 2.0.4.
Yes, I plan to upgrade. 2.1.x did need some ironing out first, as you know :) -- 2. That which causes joy or happiness.
Bjørn Mork wrote:
Yes, now it continues to answer both authentication and accounting requests, but it still stops proxying after a while (where "a while" might be something like 20+ hours and 1+ million auth requests - I have no indication that these values are fixed).
Look for the message: Failed creating new proxy socket: server is too busy and home servers appear to be down It *should* continue to proxy after that, but it *won't* create new outgoing sockets. And it *won't* proxy any more requests until the current requests have timed out. If the upstream servers really are that bad, I suggest configuring local detail files, as in raddb/sites-available/robust-proxy-accounting. This should make the server log packets locally, and *not* track them in memory (which appears to be the problem).
There are a number of servers marked "alive", but these are all servers which have been revived after the fixed period. When used, they will be marked dead/zombie again.
Configure "status_check". Really. Get the upstream servers to permit status-checks for a "test" user. It will make your network *much* more robust. And why are the upstream servers dying so consistently? You're really in a corner case where you're testing FreeRADIUS in situations where the network Just Doesn't Work. The suggestions above should help work around most of those issues.
But I will test that now, starting with the stable branch from git.freeradius.org, commit d7b4f003477644978f3fefa694305dce9b5dc8bf, which was the last point where things seemed to work
If that works, we could do a "git bisect" to find the issue. There are only 26 commits since them, and many of those don't have code changes. It shouldn't be too hard to track down the offending commit. Alan DeKok.
Alan DeKok <aland@deployingradius.com> writes:
Bjørn Mork wrote:
Yes, now it continues to answer both authentication and accounting requests, but it still stops proxying after a while (where "a while" might be something like 20+ hours and 1+ million auth requests - I have no indication that these values are fixed).
Look for the message:
Failed creating new proxy socket: server is too busy and home servers appear to be down
Yes, I got one of those: Tue Dec 8 08:49:22 2009 : Proxy: Marking home server 192.168.8.216 port 1812 as dead. Tue Dec 8 08:49:22 2009 : Error: Failed creating new proxy socket: server is too busy and home servers appear to be down
It *should* continue to proxy after that, but it *won't* create new outgoing sockets. And it *won't* proxy any more requests until the current requests have timed out.
So it's possible that a few failing home servers end up tying up all sockets available for proxying? Or am I misunderstanding this? For how long? The server was not responding to requests going to a proxy at all between 08:43:27 and 09:35:46. That's a very long time to sit waiting for available resources... What's the actual limit here? The number of open files left after the sql module and others have taken their share? Then increasing it, and trying to tune the timeouts might help I geuss. But I still believe sharing these resources in a way which let a few bad servers steal them all, is wrong. It should be possible to isolate two independent realms from each other, even if they use the same proxy radius.
If the upstream servers really are that bad, I suggest configuring local detail files, as in raddb/sites-available/robust-proxy-accounting. This should make the server log packets locally, and *not* track them in memory (which appears to be the problem).
Thanks, I'll look into that. I do have to live with failing proxy authentication as well, but I guess removing the accounting might take some load off this.
There are a number of servers marked "alive", but these are all servers which have been revived after the fixed period. When used, they will be marked dead/zombie again.
Configure "status_check". Really. Get the upstream servers to permit status-checks for a "test" user. It will make your network *much* more robust.
On my TODO list. Thanks.
And why are the upstream servers dying so consistently? You're really in a corner case where you're testing FreeRADIUS in situations where the network Just Doesn't Work. The suggestions above should help work around most of those issues.
Some of the upstream servers are just not very well mangaged, if managed at all. I wish I could ignore them, but I can't.
But I will test that now, starting with the stable branch from git.freeradius.org, commit d7b4f003477644978f3fefa694305dce9b5dc8bf, which was the last point where things seemed to work
If that works, we could do a "git bisect" to find the issue. There are only 26 commits since them, and many of those don't have code changes. It shouldn't be too hard to track down the offending commit.
Given that I can actually trigger the problem in a test enviroment. I don't think I can. Bjørn
Bjørn Mork wrote:
Yes, I got one of those:
Tue Dec 8 08:49:22 2009 : Proxy: Marking home server 192.168.8.216 port 1812 as dead. Tue Dec 8 08:49:22 2009 : Error: Failed creating new proxy socket: server is too busy and home servers appear to be down
OK. That indicates that all 32 sockets have been allocated. All this means is that no *new* sockets will be allocated from now on.
So it's possible that a few failing home servers end up tying up all sockets available for proxying?
No. See my other post for a detailed explanation.
Or am I misunderstanding this? For how long? The server was not responding to requests going to a proxy at all between 08:43:27 and 09:35:46. That's a very long time to sit waiting for available resources...
I agree. You should use radmin to look at the server stats, to see what it's doing.
But I still believe sharing these resources in a way which let a few bad servers steal them all, is wrong. It should be possible to isolate two independent realms from each other, even if they use the same proxy radius.
See my other post. They are isolated, unless they both proxy to the same home server. When that happens, they share the home server state.
If that works, we could do a "git bisect" to find the issue. There are only 26 commits since them, and many of those don't have code changes. It shouldn't be too hard to track down the offending commit.
Given that I can actually trigger the problem in a test enviroment. I don't think I can.
? You can reproduce it, but can't find the offending commit? Alan DeKok.
Bjørn Mork wrote:
It took two more hours, then I got:
Sun Dec 6 16:23:33 2009 : Proxy: Marking home server 10.10.10.132 port 1645 as dead. Sun Dec 6 16:23:33 2009 : Error: Failed binding to proxy address * port 2727: Address already in use
and the server stopped answering requests. It did not exit, and it did not hang (at least it responeded to SIGTERM). It just stopped answering.
The server had been running for 45 hours when this happened. I haven't got the faintest idea where to start looking for the bug.
It's likely in a busy loop. I'll do some local tests and see. Alan DeKok.
I'm probably stupid as I never learn, but I'm going to take my chances reporting succcess again.... The v2.1.x branch from github up to and including commit 1d80707880c1bf94ad1e87be74221a6c7b4cb4c7 has now been running stable for more than 5 days for me. All the previously reported problems seem to be gone. So I'd say it makes a good 2.1.8 release for Christmas. Bjørn
Hi,
The v2.1.x branch from github up to and including commit 1d80707880c1bf94ad1e87be74221a6c7b4cb4c7 has now been running stable for more than 5 days for me. All the previously reported problems seem to be gone. So I'd say it makes a good 2.1.8 release for Christmas.
aye - there were some questions relating to getting some of the older requested patches put into 2.1.8 too - has that been addressed? alan
Hi,
Alan Buxey wrote:
aye - there were some questions relating to getting some of the older requested patches put into 2.1.8 too - has that been addressed?
Which patches?
there were a couple cant remember exactly - i know one was '17' - the CHAP one. I applied it locally to my pre 2.1.8 - it didnt go in 100% clean because it was written some time back....things appear to be okay after it went in. wasnt there also an SQL one and a proxy one? alan
Bjørn Mork wrote:
The v2.1.x branch from github up to and including commit 1d80707880c1bf94ad1e87be74221a6c7b4cb4c7 has now been running stable for more than 5 days for me. All the previously reported problems seem to be gone. So I'd say it makes a good 2.1.8 release for Christmas.
Thanks. I've added a bunch more minor changes (docs, checks from static analysis tools, etc.) But no more code changes. It should be good to go... Alan DeKok.
Alan DeKok <aland@deployingradius.com> wrote:
I've put a pre-release of version 2.1.8 on the web site:
http://git.freeradius.org/pre/
Please do some sanity checks, and see if it works for you.
This version is from the new "v2.1.x" branch, which is Version 2.1.7, plus *only* bug fixes. The "stable" branch is now planned to become version 2.2.0 in January. It will include TCP transport, among other new features.
If there are no major issues, we can release 2.1.8 next week.
Not quite on the pre-release but running f691b0ec7d4c92919bdd4dc81e8a86b211c00832 from the stable branch I got these after a 'hiccup' this morning on the network: ---- Program received signal SIGPIPE, Broken pipe. [Switching to Thread 0x411b9950 (LWP 18045)] 0x00007fa8a156b75b in write () from /lib/libpthread.so.0 (gdb) bt #0 0x00007fa8a156b75b in write () from /lib/libpthread.so.0 #1 0x00007fa89e51c1a9 in ?? () from /usr/lib/liblber-2.4.so.2 #2 0x00007fa89e06f4b9 in _gnutls_io_write_buffered () from /usr/lib/libgnutls.so.26 #3 0x00007fa89e06c601 in _gnutls_send_int () from /usr/lib/libgnutls.so.26 #4 0x00007fa89e08a6e0 in gnutls_alert_send () from /usr/lib/libgnutls.so.26 #5 0x00007fa89e06c90f in gnutls_bye () from /usr/lib/libgnutls.so.26 #6 0x00007fa89e754c30 in ?? () from /usr/lib/libldap_r-2.4.so.2 #7 0x00007fa89e51c6ec in ber_int_sb_close () from /usr/lib/liblber-2.4.so.2 #8 0x00007fa89e745f5d in ldap_free_connection () from /usr/lib/libldap_r-2.4.so.2 #9 0x00007fa89e73c8cf in ldap_ld_free () from /usr/lib/libldap_r-2.4.so.2 #10 0x00007fa89e96e1c1 in perform_search (instance=0x1f2a0e0, conn=0x1f2a5b0, search_basedn=0x260b3e0 "ou=Networks,ou=LanWarden,o=soas", scope=1, filter=0x27f6fc0 "(&(objectClass=lanwardenNetwork)(member=cn=001e4fe171de,ou=users-staff,ou=imported,ou=Hosts,ou=LanWarden,o=soas))", attrs=0x2676c70, result=0x411b7050) at rlm_ldap.c:811 #11 0x00007fa89e96f6ab in ldap_xlat (instance=0x1f2a0e0, request=0x7fa894002530, fmt=0x2de8ae0 "ldap:///ou=Networks,ou=LanWarden,o=soas?cn?one?(&(objectClass=lanwardenNetwork)(member=%{control:MAC-Address-LdapDn}))", out=0x411b7840 "", freespace=254, func=0x42ba4c <xlat_copy>) at rlm_ldap.c:1199 #12 0x000000000042b89b in decode_attribute (from=0x411b76d0, to=0x411b76c8, freespace=254, open_p=0x411b765c, request=0x7fa894002530, func=0x42ba4c <xlat_copy>) at xlat.c:911 #13 0x000000000042bd4f in radius_xlat (out=0x411b7840 "", outlen=254, fmt=0x2288d30 "%{ldap_autz_soasauth-nd1:ldap:///ou=Networks,ou=LanWarden,o=soas?cn?one?(&(objectClass=lanwardenNetwork)(member=%{control:MAC-Address-LdapDn}))}", request=0x7fa894002530, func=0x42ba4c <xlat_copy>) at xlat.c:1086 #14 0x00007fa89be8b4bb in do_attr_rewrite (instance=0x2288680, request=0x7fa894002530) at rlm_attr_rewrite.c:179 #15 0x00007fa89be8c0c8 in attr_rewrite_postauth (instance=0x2288680, request=0x7fa894002530) at rlm_attr_rewrite.c:453 #16 0x0000000000420655 in call_modsingle (component=7, sp=0x2288540, request=0x7fa894002530) at modcall.c:297 #17 0x00000000004214ac in modcall (component=7, c=0x2287f50, request=0x7fa894002530) at modcall.c:669 #18 0x000000000041ec68 in indexed_modcall (comp=7, idx=0, request=0x7fa894002530) at modules.c:691 #19 0x00000000004200ff in module_post_auth (postauth_type=0, request=0x7fa894002530) at modules.c:1533 #20 0x000000000040a148 in rad_postauth (request=0x7fa894002530) at auth.c:421 #21 0x000000000040ac45 in rad_authenticate (request=0x7fa894002530) at auth.c:811 #22 0x0000000000434ef7 in radius_handle_request (request=0x7fa894002530, fun=0x40a194 <rad_authenticate>) at event.c:4097 #23 0x0000000000426cb3 in request_handler_thread (arg=0x7fa8940023d0) at threads.c:492 #24 0x00007fa8a1564fc7 in start_thread () from /lib/libpthread.so.0 #25 0x00007fa8a08af5ad in clone () from /lib/libc.so.6 #26 0x0000000000000000 in ?? () (gdb) ---- Then shortly after restarting it: ---- Program received signal SIGABRT, Aborted. [Switching to Thread 0x4f492950 (LWP 23808)] 0x00007f0060554ed5 in raise () from /lib/libc.so.6 (gdb) wher #0 0x00007f0060554ed5 in raise () from /lib/libc.so.6 #1 0x00007f00605563f3 in abort () from /lib/libc.so.6 #2 0x00000000004281f2 in rad_assert_fail (file=0x4455ef "threads.c", line=406, expr=0x445628 "(*request)->magic == REQUEST_MAGIC") at util.c:363 #3 0x0000000000426adf in request_dequeue (request=0x7f004c006f30, fun=0x4f491d30) at threads.c:406 #4 0x0000000000426c3d in request_handler_thread (arg=0x7f004c006f00) at threads.c:483 #5 0x00007f00612a7fc7 in start_thread () from /lib/libpthread.so.0 #6 0x00007f00605f25ad in clone () from /lib/libc.so.6 #7 0x0000000000000000 in ?? () (gdb) ---- The former one I have seen before and assuemd it was a bug in libldap, however I guess maybe freeradius should be catching the SIGPIPE there? As for the latter one, that's new to me. Alas it is going to be difficult to repeat this 'experiment' as I would have to turn power off to one of our server rooms...tends to annoy the yokels. Cheers -- Alexander Clouter .sigmonster says: BOFH excuse #276: U.S. Postal Service
Alexander Clouter wrote:
Not quite on the pre-release but running f691b0ec7d4c92919bdd4dc81e8a86b211c00832 from the stable branch I got these after a 'hiccup' this morning on the network: ---- Program received signal SIGPIPE, Broken pipe. [Switching to Thread 0x411b9950 (LWP 18045)] 0x00007fa8a156b75b in write () from /lib/libpthread.so.0 (gdb) bt #0 0x00007fa8a156b75b in write () from /lib/libpthread.so.0 #1 0x00007fa89e51c1a9 in ?? () from /usr/lib/liblber-2.4.so.2 #2 0x00007fa89e06f4b9 in _gnutls_io_write_buffered () from /usr/lib/libgnutls.so.26
Ugh.
Then shortly after restarting it: ---- Program received signal SIGABRT, Aborted. [Switching to Thread 0x4f492950 (LWP 23808)] 0x00007f0060554ed5 in raise () from /lib/libc.so.6 (gdb) wher #0 0x00007f0060554ed5 in raise () from /lib/libc.so.6 #1 0x00007f00605563f3 in abort () from /lib/libc.so.6 #2 0x00000000004281f2 in rad_assert_fail (file=0x4455ef "threads.c", line=406, expr=0x445628 "(*request)->magic == REQUEST_MAGIC") at util.c:363 #3 0x0000000000426adf in request_dequeue (request=0x7f004c006f30, fun=0x4f491d30) at threads.c:406
That shouldn't happen... ever! In fact, I've never seen it happen. It can occur only when memory is free'd, and still used.
The former one I have seen before and assuemd it was a bug in libldap, however I guess maybe freeradius should be catching the SIGPIPE there?
Nope. The libraries usually re-set the signal handlers.
As for the latter one, that's new to me. Alas it is going to be difficult to repeat this 'experiment' as I would have to turn power off to one of our server rooms...tends to annoy the yokels.
It should either happen a lot, or not at all. Alan DeKok.
Alan DeKok <aland@deployingradius.com> wrote:
Then shortly after restarting it: ---- Program received signal SIGABRT, Aborted. [Switching to Thread 0x4f492950 (LWP 23808)] 0x00007f0060554ed5 in raise () from /lib/libc.so.6 (gdb) wher #0 0x00007f0060554ed5 in raise () from /lib/libc.so.6 #1 0x00007f00605563f3 in abort () from /lib/libc.so.6 #2 0x00000000004281f2 in rad_assert_fail (file=0x4455ef "threads.c", line=406, expr=0x445628 "(*request)->magic == REQUEST_MAGIC") at util.c:363 #3 0x0000000000426adf in request_dequeue (request=0x7f004c006f30, fun=0x4f491d30) at threads.c:406
That shouldn't happen... ever!
In fact, I've never seen it happen. It can occur only when memory is free'd, and still used.
[snipped]
As for the latter one, that's new to me. Alas it is going to be difficult to repeat this 'experiment' as I would have to turn power off to one of our server rooms...tends to annoy the yokels.
It should either happen a lot, or not at all.
Well as I said it is the first time I have seen it and I have been running this code straight since that commit came out on the 5th. So we cannot say 'not at all'. Want to put it down to a neutrino burst? :) Cheers -- Alexander Clouter .sigmonster says: Shut off engine before fueling.
Alexander Clouter wrote:
Want to put it down to a neutrino burst? :)
Been there. Done that. http://www.sno.phy.queensu.ca/sno/papers/nim_paper_99.pdf 9th author, on the first page. Alan DeKok.
participants (9)
-
Alan Buxey -
Alan DeKok -
Alexander Clouter -
Arran Cudbard-Bell -
Bjørn Mork -
Garber, Neal -
Josip Rodin -
piston -
Wegener, Norbert