I'm having the exact same problem as described below, with Freeradius 1.7 hanging at 99 percent. Also using PEAP, MSCHAPV2, and eDir, and running 1.7 on a SLES 10 SP1. I have been using the same configuration since 1.3 without any problems problems, but since upgrading from 1.6 to 1.7 it's "crashed" 3 times within a month. This is the last line of my log files each time it hangs at 99 percent: usr/local/var/log/radius/radius.log-20070928.bz2:Thu Sep 27 16:32:23 2007 : Error: Discarding duplicate request from client 3WXM-2:20006 - ID: 247 due to unfinished request 23061 /usr/local/var/log/radius/radius.log-20071010.bz2:Sun Oct 7 21:19:47 2007 : Error: Discarding duplicate request from client 3WXM-1:20002 - ID: 188 due to unfinished request 60866 /usr/local/var/log/radius/radius.log-20071024.bz2:Wed Oct 24 08:10:05 2007 : Error: Discarding duplicate request from client 3WXM-2:20008 - ID: 211 due to unfinished request 94412 As per Phil Mayers request, I recompiled with the developer option (and --edir as I am using that). The following is the output: Attaching to program: /usr/local/sbin/radiusd, process 23141 Loaded symbols for /usr/local/sbin/radiusd Reading symbols from /lib/libnsl.so.1...done. Loaded symbols for /lib/libnsl.so.1 Reading symbols from /lib/libresolv.so.2...done. Loaded symbols for /lib/libresolv.so.2 Reading symbols from /lib/libpthread.so.0...done. [Thread debugging using libthread_db enabled] [New Thread -1212410192 (LWP 23141)] [New Thread -1272144992 (LWP 3414)] [New Thread -1263752288 (LWP 1784)] [New Thread -1255359584 (LWP 1757)] [New Thread -1246966880 (LWP 23146)] [New Thread -1238574176 (LWP 23145)] [New Thread -1230181472 (LWP 23144)] [New Thread -1221788768 (LWP 23143)] [New Thread -1213396064 (LWP 23142)] Loaded symbols for /lib/libpthread.so.0 Reading symbols from /usr/local/lib/libradius-1.1.7.so...done. Loaded symbols for /usr/local/lib/libradius-1.1.7.so Reading symbols from /lib/libcrypt.so.1...done. Loaded symbols for /lib/libcrypt.so.1 Reading symbols from /usr/lib/libltdl.so.3...done. Loaded symbols for /usr/lib/libltdl.so.3 Reading symbols from /lib/libdl.so.2...done. Loaded symbols for /lib/libdl.so.2 Reading symbols from /usr/lib/libssl.so.0.9.8...done. Loaded symbols for /usr/lib/libssl.so.0.9.8 Reading symbols from /usr/lib/libcrypto.so.0.9.8...done. Loaded symbols for /usr/lib/libcrypto.so.0.9.8 Reading symbols from /lib/libc.so.6...done. Loaded symbols for /lib/libc.so.6 Reading symbols from /lib/ld-linux.so.2...done. Loaded symbols for /lib/ld-linux.so.2 Reading symbols from /lib/libnss_files.so.2...done. Loaded symbols for /lib/libnss_files.so.2 Reading symbols from /usr/local/lib/rlm_exec-1.1.7.so...done. Loaded symbols for /usr/local/lib/rlm_exec-1.1.7.so Reading symbols from /usr/local/lib/rlm_expr-1.1.7.so...done. Loaded symbols for /usr/local/lib/rlm_expr-1.1.7.so Reading symbols from /usr/local/lib/rlm_pap-1.1.7.so...done. Loaded symbols for /usr/local/lib/rlm_pap-1.1.7.so Reading symbols from /usr/local/lib/rlm_mschap-1.1.7.so...done. Loaded symbols for /usr/local/lib/rlm_mschap-1.1.7.so Reading symbols from /usr/local/lib/rlm_ldap-1.1.7.so...done. Loaded symbols for /usr/local/lib/rlm_ldap-1.1.7.so Reading symbols from /usr/lib/libldap_r-2.3.so.0...done. Loaded symbols for /usr/lib/libldap_r-2.3.so.0 Reading symbols from /usr/lib/liblber-2.3.so.0...done. Loaded symbols for /usr/lib/liblber-2.3.so.0 Reading symbols from /usr/lib/libsasl2.so.2...done. Loaded symbols for /usr/lib/libsasl2.so.2 Reading symbols from /usr/local/lib/rlm_unix-1.1.7.so...done. Loaded symbols for /usr/local/lib/rlm_unix-1.1.7.so Reading symbols from /usr/local/lib/rlm_eap-1.1.7.so...done. Loaded symbols for /usr/local/lib/rlm_eap-1.1.7.so Reading symbols from /usr/local/lib/libeap-1.1.7.so...done. Loaded symbols for /usr/local/lib/libeap-1.1.7.so Reading symbols from /usr/local/lib/rlm_eap_md5-1.1.7.so...done. Loaded symbols for /usr/local/lib/rlm_eap_md5-1.1.7.so Reading symbols from /usr/local/lib/rlm_eap_leap-1.1.7.so...done. Loaded symbols for /usr/local/lib/rlm_eap_leap-1.1.7.so Reading symbols from /usr/local/lib/rlm_eap_gtc-1.1.7.so...done. Loaded symbols for /usr/local/lib/rlm_eap_gtc-1.1.7.so Reading symbols from /usr/local/lib/rlm_eap_tls-1.1.7.so...done. Loaded symbols for /usr/local/lib/rlm_eap_tls-1.1.7.so Reading symbols from /usr/local/lib/rlm_eap_ttls-1.1.7.so...done. Loaded symbols for /usr/local/lib/rlm_eap_ttls-1.1.7.so Reading symbols from /usr/local/lib/rlm_eap_peap-1.1.7.so...done. Loaded symbols for /usr/local/lib/rlm_eap_peap-1.1.7.so Reading symbols from /usr/local/lib/rlm_eap_mschapv2-1.1.7.so...done. Loaded symbols for /usr/local/lib/rlm_eap_mschapv2-1.1.7.so Reading symbols from /usr/local/lib/rlm_realm-1.1.7.so...done. Loaded symbols for /usr/local/lib/rlm_realm-1.1.7.so Reading symbols from /usr/local/lib/rlm_preprocess-1.1.7.so...done. Loaded symbols for /usr/local/lib/rlm_preprocess-1.1.7.so Reading symbols from /usr/local/lib/rlm_files-1.1.7.so...done. Loaded symbols for /usr/local/lib/rlm_files-1.1.7.so Reading symbols from /usr/local/lib/rlm_acct_unique-1.1.7.so...done. Loaded symbols for /usr/local/lib/rlm_acct_unique-1.1.7.so Reading symbols from /usr/local/lib/rlm_detail-1.1.7.so...done. Loaded symbols for /usr/local/lib/rlm_detail-1.1.7.so Reading symbols from /usr/local/lib/rlm_radutmp-1.1.7.so...done. Loaded symbols for /usr/local/lib/rlm_radutmp-1.1.7.so 0xffffe410 in __kernel_vsyscall () Thread 9 (Thread -1213396064 (LWP 23142)): #0 0xffffe410 in __kernel_vsyscall () No symbol table info available. #1 0xb7ea9faf in sem_wait@GLIBC_2.0 () from /lib/libpthread.so.0 No symbol table info available. #2 0x800148ce in request_handler_thread (arg=0x80118b30) at threads.c:534 fun = (RAD_REQUEST_FUNP) 0x80005a30 <rad_authenticate> set = {__val = {16391, 0 <repeats 31 times>}} #3 0xb7ea42ab in start_thread () from /lib/libpthread.so.0 No symbol table info available. #4 0xb7c81a4e in clone () from /lib/libc.so.6 No symbol table info available. Thread 8 (Thread -1221788768 (LWP 23143)): #0 0xffffe410 in __kernel_vsyscall () No symbol table info available. #1 0xb7ea9faf in sem_wait@GLIBC_2.0 () from /lib/libpthread.so.0 No symbol table info available. #2 0x800148ce in request_handler_thread (arg=0x8011d080) at threads.c:534 fun = (RAD_REQUEST_FUNP) 0x80005a30 <rad_authenticate> set = {__val = {16391, 0 <repeats 31 times>}} #3 0xb7ea42ab in start_thread () from /lib/libpthread.so.0 No symbol table info available. #4 0xb7c81a4e in clone () from /lib/libc.so.6 No symbol table info available. Thread 7 (Thread -1230181472 (LWP 23144)): #0 0xffffe410 in __kernel_vsyscall () No symbol table info available. #1 0xb7ea9faf in sem_wait@GLIBC_2.0 () from /lib/libpthread.so.0 No symbol table info available. #2 0x800148ce in request_handler_thread (arg=0x8011d138) at threads.c:534 fun = (RAD_REQUEST_FUNP) 0x80005a30 <rad_authenticate> set = {__val = {16391, 0 <repeats 31 times>}} #3 0xb7ea42ab in start_thread () from /lib/libpthread.so.0 No symbol table info available. #4 0xb7c81a4e in clone () from /lib/libc.so.6 No symbol table info available. Thread 6 (Thread -1238574176 (LWP 23145)): #0 0xffffe410 in __kernel_vsyscall () No symbol table info available. #1 0xb7ea9faf in sem_wait@GLIBC_2.0 () from /lib/libpthread.so.0 No symbol table info available. #2 0x800148ce in request_handler_thread (arg=0x8011d1f0) at threads.c:534 fun = (RAD_REQUEST_FUNP) 0x80005a30 <rad_authenticate> set = {__val = {16391, 0 <repeats 31 times>}} #3 0xb7ea42ab in start_thread () from /lib/libpthread.so.0 No symbol table info available. #4 0xb7c81a4e in clone () from /lib/libc.so.6 No symbol table info available. Thread 5 (Thread -1246966880 (LWP 23146)): #0 0xffffe410 in __kernel_vsyscall () No symbol table info available. #1 0xb7ea9faf in sem_wait@GLIBC_2.0 () from /lib/libpthread.so.0 No symbol table info available. #2 0x800148ce in request_handler_thread (arg=0x8011d2a8) at threads.c:534 fun = (RAD_REQUEST_FUNP) 0x80005a30 <rad_authenticate> set = {__val = {16391, 0 <repeats 31 times>}} #3 0xb7ea42ab in start_thread () from /lib/libpthread.so.0 No symbol table info available. #4 0xb7c81a4e in clone () from /lib/libc.so.6 No symbol table info available. Thread 4 (Thread -1255359584 (LWP 1757)): #0 0xffffe410 in __kernel_vsyscall () No symbol table info available. #1 0xb7ea9faf in sem_wait@GLIBC_2.0 () from /lib/libpthread.so.0 No symbol table info available. #2 0x800148ce in request_handler_thread (arg=0x801a4d20) at threads.c:534 fun = (RAD_REQUEST_FUNP) 0x80005a30 <rad_authenticate> set = {__val = {16391, 0 <repeats 31 times>}} #3 0xb7ea42ab in start_thread () from /lib/libpthread.so.0 No symbol table info available. #4 0xb7c81a4e in clone () from /lib/libc.so.6 No symbol table info available. Thread 3 (Thread -1263752288 (LWP 1784)): #0 0xffffe410 in __kernel_vsyscall () No symbol table info available. #1 0xb7ea9faf in sem_wait@GLIBC_2.0 () from /lib/libpthread.so.0 No symbol table info available. #2 0x800148ce in request_handler_thread (arg=0x80153e70) at threads.c:534 fun = (RAD_REQUEST_FUNP) 0x80005a30 <rad_authenticate> set = {__val = {16391, 0 <repeats 31 times>}} #3 0xb7ea42ab in start_thread () from /lib/libpthread.so.0 No symbol table info available. #4 0xb7c81a4e in clone () from /lib/libc.so.6 No symbol table info available. Thread 2 (Thread -1272144992 (LWP 3414)): #0 0xb7c28b0d in _int_malloc () from /lib/libc.so.6 No symbol table info available. #1 0xb7c2a085 in calloc () from /lib/libc.so.6 No symbol table info available. #2 0xb7c5dd75 in re_acquire_state_context () from /lib/libc.so.6 No symbol table info available. #3 0xb7c63c01 in re_compile_internal () from /lib/libc.so.6 No symbol table info available. #4 0xb7c64cc4 in regcomp () from /lib/libc.so.6 No symbol table info available. #5 0x800161df in paircmp (req=0x80242e50, request=0xb391bf68, check=0x80118008, reply=0x80175368) at valuepair.c:365 i = <value optimized out> rxmatch = {{rm_so = 0, rm_eo = -1272151048}, {rm_so = -2147422548, rm_eo = 0}, {rm_so = -2146357296, rm_eo = -2145114136}, {rm_so = -2147359520, rm_eo = -2146357296}, {rm_so = 0, rm_eo = -1272150952}, {rm_so = -2147423649, rm_eo = -1272150972}, {rm_so = -1272150968, rm_eo = -1272151000}, {rm_so = -1209472631, rm_eo = -1272150920}, {rm_so = -2146465632, rm_eo = 1036177532}} check_item = (VALUE_PAIR *) 0x80118008 auth_item = (VALUE_PAIR *) 0xb3912ef8 compare = <value optimized out> other = 1 reg = {buffer = 0xb39248f0 "\220ã\221³*", allocated = 140, used = 140, syntax = 242428, fastmap = 0xb3911510 "H\001\220³H\001\220³", translate = 0x0, re_nsub = 0, can_be_null = 0, regs_allocated = 0, fastmap_accurate = 0, no_sub = 0, not_bol = 0, not_eol = 0, newline_anchor = 0} #6 0xb7adb092 in file_authorize (instance=0x801067f0, request=0x80242e50) at rlm_files.c:321 namepair = <value optimized out> request_pairs = (VALUE_PAIR *) 0xb391bf68 check_tmp = (VALUE_PAIR *) 0xb7ade2ab reply_tmp = (VALUE_PAIR *) 0x802427e8 pl = (PAIR_LIST *) 0x80118d68 found = 0 check_pairs = (VALUE_PAIR **) 0x80242e60 reply_pairs = (VALUE_PAIR **) 0x80175368 check_save = (VALUE_PAIR *) 0x6 #7 0x8000e85f in modcall (component=1, c=0x80117980, request=0x80242e50) at modcall.c:238 myresult = 6 #8 0x8000eeac in call_one (component=676979, p=0x0, request=0xffffffc0, priority=0xb42c8574, result=0xb42c8578) at modcall.c:272 r = <value optimized out> #9 0x8000ea5f in modcall (component=1, c=0x801155d8, request=0x80242e50) at modcall.c:327 g = (modgroup *) 0x801155d8 myresult = 6 #10 0x8000cade in indexed_modcall (comp=1, idx=0, request=0x80242e50) at modules.c:469 this = (indexed_modcallable *) 0x80115680 #11 0x80005b10 in rad_authenticate (request=0x80242e50) at auth.c:602 namepair = <value optimized out> check_item = <value optimized out> reply_item = <value optimized out> auth_item = (VALUE_PAIR *) 0x0 module_msg = <value optimized out> tmp = (VALUE_PAIR *) 0x0 result = <value optimized out> r = <value optimized out> umsg = "\221,´Ý´è·Ø\234\002\200h\221,´x\221,´\211éè·È\221,´('\221³\027f\220ÝX\237\002\200H\001\000\000à\nη\000\000\000\000£êè·ô\017η\020\000\220³\000\000\000\000¨\221,´P\000\000\000\020\000\220³D\001\000\000hÙé·\000\000\000\0000'\221³Ø\221,´m é· ©%\200\024\000\000\000D\001\000\000l\000\000\000\000\000\000\000\032\000\000\0000'\221³hÙé·\000\000\000\0000'\221³X\222,´ÊOé· ©%\200\024\000\000\000\020\000\000\000\\\221é·ô\017ηl'\221³`X \200\200ª%\200\000\000\000\000\020\000\000\000\000\000\000\000\001\000\000\000\001"... user_msg = <value optimized out> exec_program = <value optimized out> exec_wait = <value optimized out> seen_callback_id = <value optimized out> buf = '\0' <repeats 100 times>, "3T·\004rÁ·\000\000\000\000\000\000\000\0004\220,´ \233,´ô\017ηz²é·t\221,´Ä\220,´üè¿·à\220,´z²é·", '\0' <repeats 20 times>, " \233,´\227÷¿·\000\000\000\000\000\000\000\000 \220,´\000\000\000\000\000\000\000\0004\220,´\000\000\000\000\000\000\000\0003T·\004rÁ·\000\000\000\000\032\000\000\000¤\220,´t\221,´ô\017η\237\223\001\200ä\221,´4\221,´üè¿·P\221,´\000\000\000\000ÿÿÿÿ\v\000\000\000o²é·4\220,´\003\000\000\000\n", '\0' <repeats 15 times>, "\n\000\000\0002"... logstr = '\0' <repeats 1023 times> autz_retry = 0 '\0' autz_type = 676979 #12 0x80010087 in rad_respond (request=0x80242e50, fun=0x80005a30 <rad_authenticate>) at radiusd.c:1669 rcode = <value optimized out> packet = <value optimized out> original = <value optimized out> secret = 0x80242e70 "Troldhavelaage900#" finished = <value optimized out> reprocess = <value optimized out> #13 0x800149ec in request_handler_thread (arg=0x801bfb30) at threads.c:570 fun = (RAD_REQUEST_FUNP) 0x80005a30 <rad_authenticate> set = {__val = {16391, 0 <repeats 31 times>}} #14 0xb7ea42ab in start_thread () from /lib/libpthread.so.0 No symbol table info available. #15 0xb7c81a4e in clone () from /lib/libc.so.6 No symbol table info available. Thread 1 (Thread -1212410192 (LWP 23141)): #0 0xffffe410 in __kernel_vsyscall () No symbol table info available. #1 0xb7c8d57e in __lll_mutex_lock_wait () from /lib/libc.so.6 No symbol table info available. #2 0xb7c2b111 in _L_mutex_lock_4125 () from /lib/libc.so.6 No symbol table info available. #3 0xb7b5e598 in ?? () from /usr/lib/libldap_r-2.3.so.0 No symbol table info available. #4 0xb7ea735c in __pthread_mutex_unlock_usercnt () from /lib/libpthread.so.0 No symbol table info available. #5 0xb7b1e31a in ber_memfree_x () from /usr/lib/liblber-2.3.so.0 No symbol table info available. #6 0xb7b3b67a in ldap_ld_free () from /usr/lib/libldap_r-2.3.so.0 No symbol table info available. #7 0xb7b3b8a6 in ldap_unbind_ext () from /usr/lib/libldap_r-2.3.so.0 No symbol table info available. #8 0xb7b3b93d in ldap_unbind_s () from /usr/lib/libldap_r-2.3.so.0 No symbol table info available. #9 0xb7b75ecf in ldap_detach (instance=0x80104850) at rlm_ldap.c:2402 i = 0 pair = <value optimized out> nextpair = <value optimized out> #10 0x8000dc02 in detach_modules () at modules.c:130 ml = <value optimized out> next = <value optimized out> #11 0x80011d3a in main (argc=1, argv=0xbfd4c134) at radiusd.c:1191 fun = (RAD_REQUEST_FUNP) 0x80005a30 <rad_authenticate> request = (REQUEST *) 0x80242e50 packet = (RADIUS_PACKET *) 0x0 secret = (u_char *) 0x800fd6d0 "Troldhavelaage900#" buffer = "*", '\0' <repeats 831 times>, "¹ ï·²C½·ØÅî·ôoð· sð·\000\000\000\000ü´Ô¿°?ï·", '\0' <repeats 24 times>, "²C½·\000\000\000\000 pð·", '\0' <repeats 12 times>, "È|è·", '\0' <repeats 48 times>, "¹ ï· hз\020\177è·ôoð·È|è· hз\200µÔ¿°?ï· hзÎhз", '\0' <repeats 16 times>, " hз\000\000\000\000 pð·", '\0' <repeats 12 times>, "0zè·", '\0' <repeats 20 times>, "Îhз", '\0' <repeats 20 times>, "¹ ï·Ñ<á·\020\177è"... readfds = {fds_bits = {8, 0 <repeats 31 times>}} argval = <value optimized out> pid = <value optimized out> max_fd = 182868 status = <value optimized out> tv = (struct timeval *) 0x8001ece4 act = {__sigaction_handler = {sa_handler = 0x8000fe30 <sig_fatal>, sa_sigaction = 0x8000fe30 <sig_fatal>}, sa_mask = {__val = {0 <repeats 32 times>}}, sa_flags = 0, sa_restorer = 0} listener = (rad_listen_t *) 0x0 #0 0xffffe410 in __kernel_vsyscall () - Best regards - Nicolai On Mon, 2007-09-24 at 13:40 -0700, Phil Mayers wrote:
I am a newbie, running 3 (for redundancy) FreeRadius servers (1.1.7) on SUSE 10 SP1 (32-bit) to authenticate our wireless clients (PEAP MSCHAPv2) to our eDirectory via LDAP. We average 800-900 simultaneous wireless clients (need to support a potential 4K in the future).
The setup works well and authenticates users very quickly, but every couple days, the radiusd process will either blow up and start consuming 99% of the CPU or die altogether. More often it blows up. We had stability problems initially, even when the process was running, so I took everything out of the config that we didn't need and that seemed to help.
First question; are you HUPing the daemon? If so, don't - it won't work well.
Second question; if this happens reliably can you recompile from scratch:
./configure --enable-developer make make install
...and when it happens do this:
gdb /usr/local/sbin/radiusd set pagination off set logging file /root/radiusd-wireless.txt set logging on attach $PID thread apply all bt full
...that'll give some details as to what the server is doing when it pegs the CPU. Other options are strace or (if your Linux system has it) SystemTap. The aim being to determine what it's doing when it goes wrong.