Last week I reported an issue I had with FreeRadius 1.0.5 on Red Hat Enterprise Linux ES release 3. It had to do with dropped MySQL connections. We continue experience severe problems with FreeRadius. The server will run for upwards to 8 hours, sometimes more, before getting into some unknown state where it stops responding to requests. At this time FreeRadius consumes all the system's cpu cycles and won't stop without a kill -9. We are also running radrelay which relays to another port on the same server. The mysql database (version 4.0.26) is local to the server where FreeRadius resides. Please if you have any ideas or suggestions please pass them along. Otherwise we may be forced to fall back on another approach. I can happily send more detail if needed but there's potentially a lot and I didn't want to overwhelm the list... Thanks in advance for your ideas. From the log, here is the basic pattern: Many of these... Wed May 3 08:02:25 2006 : Info: rlm_sql (sql): There are no DB handles to use! skipped 0, tried to connect 0 then... Wed May 3 08:02:52 2006 : Error: rlm_sql_mysql: MYSQL Error: Cannot get result Wed May 3 08:02:52 2006 : Error: rlm_sql_mysql: MYSQL Error: Wed May 3 08:02:52 2006 : Error: rlm_sql_mysql: MYSQL Error: No Fields Wed May 3 08:02:52 2006 : Error: rlm_sql_mysql: MYSQL error: Wed May 3 08:02:52 2006 : Info: rlm_sql_mysql: Starting connect to MySQL server for #0 Wed May 3 08:02:52 2006 : Error: rlm_sql (sql): failed after re-connect or: Wed May 3 17:50:05 2006 : Info: rlm_sql_mysql: Starting connect to MySQL server for #4 Wed May 3 17:50:05 2006 : Error: rlm_sql_mysql: Couldn't connect socket to MySQL server radius@localhost:radius Wed May 3 17:50:05 2006 : Error: rlm_sql_mysql: Mysql error '' Wed May 3 17:50:05 2006 : Error: rlm_sql (sql): Failed to connect DB handle #4 Wed May 3 17:50:05 2006 : Error: rlm_sql (sql): reconnect failed, database down? Wed May 3 17:50:05 2006 : Error: rlm_sql (sql): Couldn't insert SQL accounting STOP record - rlm_sql_mysql: no connection to db or: Sat May 6 12:40:04 2006 : Error: rlm_sql (sql): failed after re-connect Sat May 6 12:40:04 2006 : Error: rlm_sql (sql): Couldn't update SQL accounting STOP record - Lost connection to MySQL server during query or: Sun May 7 18:20:41 2006 : Error: rlm_sql_mysql: MYSQL Error: Cannot get result Sun May 7 18:20:42 2006 : Error: rlm_sql_mysql: MYSQL Error: Sun May 7 18:20:42 2006 : Error: rlm_sql_mysql: MYSQL Error: No Fields Sun May 7 18:20:42 2006 : Error: rlm_sql_mysql: MYSQL error: Sun May 7 18:20:42 2006 : Info: rlm_sql_mysql: Starting connect to MySQL server for #8 Sun May 7 18:20:42 2006 : Error: rlm_sql (sql): failed after re-connect
Bill Schoolfield wrote:
Wed May 3 08:02:52 2006 : Error: rlm_sql_mysql: MYSQL Error: Cannot get result Wed May 3 08:02:52 2006 : Error: rlm_sql_mysql: MYSQL Error: Wed May 3 08:02:52 2006 : Error: rlm_sql_mysql: MYSQL Error: No Fields Wed May 3 08:02:52 2006 : Error: rlm_sql_mysql: MYSQL error: Wed May 3 08:02:52 2006 : Info: rlm_sql_mysql: Starting connect to MySQL server for #0 Wed May 3 08:02:52 2006 : Error: rlm_sql (sql): failed after re-connect
All of those look like MySQL problems. Do you have mytop installed? What does it look like (you can also look at "show process list", but mytop is nicer)? What happens when you restart MySQL when radius does that (you may need to HUP radiusd, not sure)? I found that accounting requests would get very sluggish on large MyISAM tables causing "no DB handles" errors. Archiving data and switching to InnoDB completely alleviated those problems (note that it may take several hours to change the engine on large tables). Also, the current release is 1.1.1, you should probably use that. -- Dennis Skinner Systems Administrator BlueFrog Internet http://www.bluefrog.com
Bill Schoolfield wrote:
Last week I reported an issue I had with FreeRadius 1.0.5 on Red Hat Enterprise Linux ES release 3. It had to do with dropped MySQL connections.
We continue experience severe problems with FreeRadius. The server will run for upwards to 8 hours, sometimes more, before getting into some unknown state where it stops responding to requests. At this time FreeRadius consumes all the system's cpu cycles and won't stop without a kill -9.
I can't speak to the MySQL problems, but we've observed the same lock-up behavior of the daemon: unresponsive to RADIUS requests, 98% CPU usage, only a 'kill -9' will break it loose. (We're running FR 1.0.5 on FreeBSD 5.5). In our case, the daemon appears to get wedged only if a signal (HUP, e.g.) arrives just as it's handling a kerberos authentication request. If I can speculate, perhaps the signal-handling bug is not just in the rlm_krb5 module, but a more general problem that can also affect rlm_sql. When I asked about our problem back in March, it was suggested that we upgade to 1.1.0 (now 1.1.1), as that release has some signal handling bug fixes. We're finally ready to upgrade (tomorrow), so we'll see if that helps. -- George C. Kaplan gckaplan@ack.berkeley.edu Communication & Network Services 510-643-0496 University of California at Berkeley
George C. Kaplan wrote:
I can't speak to the MySQL problems, but we've observed the same lock-up behavior of the daemon: unresponsive to RADIUS requests, 98% CPU usage, only a 'kill -9' will break it loose. (We're running FR 1.0.5 on FreeBSD 5.5).
In our case, the daemon appears to get wedged only if a signal (HUP, e.g.) arrives just as it's handling a kerberos authentication request. If I can speculate, perhaps the signal-handling bug is not just in the rlm_krb5 module, but a more general problem that can also affect rlm_sql.
When I asked about our problem back in March, it was suggested that we upgrade to 1.1.0 (now 1.1.1), as that release has some signal handling bug fixes. We're finally ready to upgrade (tomorrow), so we'll see if that helps.
Apparently 1.1.1 has the same problem, but at least I've found a way to trigger the lockup at will: - Configure freeradius to authenticate to a kerberos server - Set up a dummy kerberos server that just accepts TCP connections on port 88 but doesn't send anything back. (I just used 'nc -l 88'). - Change /etc/krb5.conf on the freeradius server to point to the dummy kerberos server. - Use 'radtest' to send an authentication request to freeradius. If you just leave it alone, radiusd will timeout after several seconds, sending an Access-Reject, and logging a "Cannot contact any KDC..." message. - Before it times out, send a HUP to the radiusd process. After a few seconds, the CPU utilization will start to climb, eventually reaching about 98%. At this point the daemon will not respond to any RADIUS requests, even for huntgroups that don't use kerberos. The only way out is to kill the daemon and restart it. (Under 1.0.5 I generally had to do 'kill -9', but now a 'kill -TERM' seems to work). This appears to be related to threaded operation, since the daemon does *not* get wedged if it's running with -s or -X options. I haven't tried this with any other authentication modules. My current system: freeradius 1.1.1, compiled from ports with MIT kerberos support FreeBSD 5.5-PRERELEASE I'll file a bug report once my bugzilla password comes through. In the meantime, suggestions for more detailed troubleshooting here are welcome. -- George C. Kaplan gckaplan@ack.berkeley.edu Communication & Network Services 510-643-0496 University of California at Berkeley
"George C. Kaplan" <gckaplan@ack.berkeley.edu> wrote:
freeradius 1.1.1, compiled from ports with MIT kerberos support FreeBSD 5.5-PRERELEASE
I'll file a bug report once my bugzilla password comes through. In the meantime, suggestions for more detailed troubleshooting here are welcome.
I don't run kerberos myself, so I'm unsure as to how to reproduce it. Could you attach example krb.conf files, and the "krb5{}" section from radiusd.conf? Or, you could use gdb to attach to the running process. e.g. $ radiusd ... $ ps -ef | grep radiusd $ nice +15 <radiusd-pid> <reproduce the problem> $ gdb `which radiusd` <radiusd-pid> $ thread apply all bt full $ cont You may have to do the last two steps a few times to see where the server is locked. Alan DeKok.
Alan DeKok wrote:
"George C. Kaplan" <gckaplan@ack.berkeley.edu> wrote:
freeradius 1.1.1, compiled from ports with MIT kerberos support FreeBSD 5.5-PRERELEASE
I'll file a bug report once my bugzilla password comes through. In the meantime, suggestions for more detailed troubleshooting here are welcome.
I don't run kerberos myself, so I'm unsure as to how to reproduce it. Could you attach example krb.conf files, and the "krb5{}" section from radiusd.conf?
I put some notes on a minimal radius config in bug report #365. A bare-bones version of our krb5.conf is attached. Substitute the FQHN of your system running a dummy kerberos server ('nc -l 88' works) in the 'kdc' line. If you've got it set up right, a 'radtest' will time out after several seconds with a "Cannot contact any KDC..." message in radius.log. If you HUP the radiusd before it times out, that should trigger the lockup.
Or, you could use gdb to attach to the running process. e.g.
$ radiusd ... $ ps -ef | grep radiusd $ nice +15 <radiusd-pid> <reproduce the problem> $ gdb `which radiusd` <radiusd-pid>
$ thread apply all bt full $ cont
You may have to do the last two steps a few times to see where the server is locked.
OK, I'll try to do this in the next day or so. -- George C. Kaplan gckaplan@ack.berkeley.edu Communication & Network Services 510-643-0496 University of California at Berkeley [libdefaults] default_realm = BERKELEY.EDU [realms] BERKELEY.EDU = { kdc = kerberos.berkeley.edu:88 }
"George C. Kaplan" <gckaplan@ack.berkeley.edu> wrote:
If you've got it set up right, a 'radtest' will time out after several seconds with a "Cannot contact any KDC..." message in radius.log. If you HUP the radiusd before it times out, that should trigger the lockup.
I think I know what's happening. The HUP triggers a tear-down & re-start of all modules. If a module is blocked, the data structures pointing to it will be destroyed... One solution would be to go to src/main/modules.c, function setup_modules(). Comment out or delete the call to detach modules(). That will work, but ONLY if the "radiusd.conf" file doesn't change. If you're HUing the server to get it to re-read the "users" file, that's OK. If that change fixes it for you, we should look into a better approach to HUPing the server... Alan DeKok.
participants (4)
-
Alan DeKok -
Bill Schoolfield -
Dennis Skinner -
George C. Kaplan