I posted this to the list back in September, but was unable to chase it then. http://www.mail-archive.com/freeradius-users@lists.freeradius.org/msg294 52.html
But it has returned with a vengeance. It only seems to affect the 1.1.3 server. I have not tried any other versions, other than the 1.0.4 I've listed below, which seems to work fine I think it's load related, since when I test with a few clients, it worked fine. When I dumped 1000 of clients, with over 50 auths/sec, things went horrible wrong. I found this on the net with the same error string: http://www.mail-archive.com/modssl-users@modssl.org/msg16180.html > There is definately something wrong in openssl 0.9.7a, or, mod_ssl 2.8.14 is trying > to call 0.9.6 functions which are different/don't exist in 0.9.7 And I found this: http://lists.alioth.debian.org/pipermail/pkg-openssl-devel/2005-November /000418.html Which has a link to: http://www.aet.tu-cottbus.de/rt2/Ticket/Display.html?id=1204 (OpenSSL's BugTracker?) >Use of SSL_OP_TLS_BLOCK_PADDING_BUG, which is included in SSL_OP_ALL, >triggers a bug in OpenSSL if both the client and server is using version 0.9.8. Unfortunately, I'm using 0.9.7 Here's my status I've built a new radius server. FreeRADIUS 1.1.3 Windbind using ntlm_auth to talk to ActiveDirectory. Mostly XP clients using the Built-in XP supplicant. (PEAP) Running on RedHat RHEL 4 Server has a trusted root Cert from Equifax. (I do NOT have a self-signed Cert) Server name is brand new, it has never been used in my network before OpenSSL is openssl-0.9.7a-43.11 via Up2date I got it all setup and operating correctly (based on my 1.0.4 config that's been in production for 1.5 years). Tested it with a few clients, everything looks fine. I put some major traffic on it, and everything goes downhill. :-( The logs read this (per user) Wed Oct 11 17:57:58 2006 : Error: TLS_accept:error in SSLv3 read client certificate A Wed Oct 11 17:57:58 2006 : Error: rlm_eap: SSL error error:00000000:lib(0):func(0):reason(0) Wed Oct 11 17:57:58 2006 : Error: TLS Alert write:fatal:bad record mac Wed Oct 11 17:57:58 2006 : Error: TLS_accept:error in SSLv3 read certificate verify A Wed Oct 11 17:57:58 2006 : Error: rlm_eap: SSL error error:1408F455:SSL routines:SSL3_GET_RECORD:decryption failed or bad record mac Wed Oct 11 17:57:58 2006 : Error: rlm_eap_tls: SSL_read failed in a system call (-1), TLS session fails. Wed Oct 11 17:57:58 2006 : Auth: Login incorrect: [BSC\\mking] (from client BUWiSM-1-2 port 29 cli 00-90-96-F4-2A-BB) For every single user. At the very beginning, a few users authenticate fine, nobody gets on after that. (All this in the first second of starting the server) So I move everyone back to my working server (version 1.0.4, OpenSSL is 0.9.7e-3 via debian) Now, it's still in this state. If I stop and start the server, it'll be normal again. Is there anykind of debugging info I can get you right now without killing the running process? I moved traffic to the server at: 17:54:03 I moved traffic off at: 17:54:36 As you can see above, I tried it with a test station at 17:57:58, and it was still busted. (Test station worked fine at 17:50) Also, I checked out the /var/log/messages file, it had this weirdness in it. I tried restarting winbindd a few seconds before these time stamps, so that's may be what threw all the error messages. Oct 11 17:02:42 radius1 kernel: audit(1160600562.652:20): avc: denied { search } for pid=2831 comm="winbindd" name="lib" dev=dm-0 ino=589826 scontext=user _u:system_r:winbind_t tcontext=system_u:object_r:var_lib_t tclass=dir Oct 11 17:02:42 radius1 kernel: audit(1160600562.652:21): avc: denied { getattr } for pid=2831 comm="winbindd" name="samba" dev=dm-0 ino=589961 scontext=u ser_u:system_r:winbind_t tcontext=system_u:object_r:var_lib_t tclass=dir Oct 11 17:57:44 radius1 winbind: winbindd shutdown succeeded Oct 11 17:57:46 radius1 kernel: audit(1160603866.541:22): avc: denied { setattr } for pid=4000 comm="winbindd" name="winbindd" dev=dm-0 ino=590836 scontex t=root:system_r:winbind_t tcontext=root:object_r:samba_log_t tclass=dir Oct 11 17:57:46 radius1 kernel: audit(1160603866.566:23): avc: denied { write } for pid=4000 comm="winbindd" name="secrets.tdb" dev=dm-0 ino=937186 sconte xt=root:system_r:winbind_t tcontext=root:object_r:samba_etc_t tclass=file Oct 11 17:57:46 radius1 kernel: audit(1160603866.566:24): avc: denied { search } for pid=4000 comm="winbindd" name="lib" dev=dm-0 ino=589826 scontext=root :system_r:winbind_t tcontext=system_u:object_r:var_lib_t tclass=dir Oct 11 17:57:46 radius1 kernel: audit(1160603866.566:25): avc: denied { read write } for pid=4000 comm="winbindd" name="gencache.tdb" dev=dm-0 ino=590838 scontext=root:system_r:winbind_t tcontext=root:object_r:var_lib_t tclass=file Oct 11 17:57:46 radius1 kernel: audit(1160603866.566:26): avc: denied { lock } for pid=4000 comm="winbindd" name="gencache.tdb" dev=dm-0 ino=590838 sconte xt=root:system_r:winbind_t tcontext=root:object_r:var_lib_t tclass=file Oct 11 17:57:46 radius1 kernel: audit(1160603866.566:27): avc: denied { getattr } for pid=4000 comm="winbindd" name="gencache.tdb" dev=dm-0 ino=590838 sco ntext=root:system_r:winbind_t tcontext=root:object_r:var_lib_t tclass=file Oct 11 17:57:46 radius1 kernel: audit(1160603866.566:28): avc: denied { getattr } for pid=4000 comm="winbindd" name="samba" dev=dm-0 ino=589961 scontext=r oot:system_r:winbind_t tcontext=system_u:object_r:var_lib_t tclass=dir Oct 11 17:57:46 radius1 kernel: audit(1160603866.568:29): avc: denied { getattr } for pid=4001 comm="winbindd" name="winbindd_privileged" dev=dm-0 ino=590 759 scontext=root:system_r:winbind_t tcontext=user_u:object_r:var_lib_t tclass=dir Oct 11 17:57:46 radius1 kernel: audit(1160603866.568:30): avc: denied { search } for pid=4001 comm="winbindd" name="winbindd_privileged" dev=dm-0 ino=5907 59 scontext=root:system_r:winbind_t tcontext=user_u:object_r:var_lib_t tclass=dir Oct 11 17:57:46 radius1 kernel: audit(1160603866.568:31): avc: denied { write } for pid=4001 comm="winbindd" name="winbindd_privileged" dev=dm-0 ino=59075 9 scontext=root:system_r:winbind_t tcontext=user_u:object_r:var_lib_t tclass=dir Oct 11 17:57:46 radius1 kernel: audit(1160603866.568:32): avc: denied { remove_name } for pid=4001 comm="winbindd" name="pipe" dev=dm-0 ino=590760 scontex t=root:system_r:winbind_t tcontext=user_u:object_r:var_lib_t tclass=dir Oct 11 17:57:46 radius1 kernel: audit(1160603866.568:33): avc: denied { unlink } for pid=4001 comm="winbindd" name="pipe" dev=dm-0 ino=590760 scontext=roo t:system_r:winbind_t tcontext=user_u:object_r:var_lib_t tclass=sock_file Oct 11 17:57:46 radius1 kernel: audit(1160603866.568:34): avc: denied { add_name } for pid=4001 comm="winbindd" name="pipe" scontext=root:system_r:winbind _t tcontext=user_u:object_r:var_lib_t tclass=dir Oct 11 17:57:46 radius1 kernel: audit(1160603866.568:35): avc: denied { create } for pid=4001 comm="winbindd" name="pipe" scontext=root:system_r:winbind_t tcontext=root:object_r:var_lib_t tclass=sock_file Oct 11 17:57:46 radius1 winbind: winbindd startup succeeded Oct 11 17:57:46 radius1 kernel: audit(1160603866.572:36): avc: denied { write } for pid=4002 comm="winbindd" name="krb5.conf" dev=dm-0 ino=934018 scontext =root:system_r:winbind_t tcontext=root:object_r:etc_t tclass=file Oct 11 17:57:46 radius1 kernel: audit(1160603866.600:37): avc: denied { read write } for pid=4002 comm="winbindd" name="winbindd_cache.tdb" dev=dm-0 ino=5 90761 scontext=root:system_r:winbind_t tcontext=user_u:object_r:var_lib_t tclass=file Oct 11 17:57:46 radius1 kernel: audit(1160603866.600:38): avc: denied { lock } for pid=4002 comm="winbindd" name="winbindd_cache.tdb" dev=dm-0 ino=590761 scontext=root:system_r:winbind_t tcontext=user_u:object_r:var_lib_t tclass=file Oct 11 17:57:46 radius1 kernel: audit(1160603866.600:39): avc: denied { getattr } for pid=4002 comm="winbindd" name="winbindd_cache.tdb" dev=dm-0 ino=5907 61 scontext=root:system_r:winbind_t tcontext=user_u:object_r:var_lib_t tclass=file - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html