I have been having some major problems trying to secure pop3 and imap with stunnel. I am running a RHEL3 box with Cpanel. I first started off by installing a clean copy of stunnel 4.10 but it was causing numerous bizarre problems. 1) it would crash after a few hours of the daemon operating, 2) before it would crash I would be getting tons of 'mailbox locked' errors and 3) the occasional timeout connecting. I eventually gave up with 4.10 and decided to try to use the stunnel 4.04 that was already doing https for cpanel/whm. I created a separate config file and ran a separate daemon just for pop/imap (I did this because I want them to be using different SSL certs). This seemed to be working perfectly as there were no timeouts, no locked mailbox errors and it didn't seem to be crashing. After about 24 hours however, the process had shut down. I tried a few more times and again after about 12-24 hours of running my pop/imap only stunnel daemon crashes. I should also mention 2 other things: 1) prior to having set up 4.10 on my box, stunnel 4.04 was listening for pop/imap without crashing (it just wasn't being used however). 2) The other daemon running https for cpanel/whm hasn't crashed at all.
I've included the log (level 7) for everything that happened in the 1-2 seconds before it crashed. If anyone could offer any advice, it would be greatly appreciated!
Thanks! David
Info needed:
1) Running stunnel by executing "/usr/bin/stunnel-4.04local /usr/local/cpanel/etc/stunnel/my/stunnel2.conf"
2) Output of "stunnel -version": stunnel 4.04 on i386-redhat-linux-gnu PTHREAD+LIBWRAP with OpenSSL 0.9.7a Feb 19 2003
Global options cert = /etc/stunnel/stunnel.pem ciphers = ALL:!ADH:+RC4:@STRENGTH debug = 5 key = /etc/stunnel/stunnel.pem pid = /var/run/stunnel.pid RNDbytes = 64 RNDfile = /dev/urandom RNDoverwrite = yes session = 300 seconds verify = none
Service-level options TIMEOUTbusy = 300 seconds TIMEOUTclose = 60 seconds TIMEOUTidle = 43200 seconds
3) Output of "uname -a":
Linux MY.HOSTNAME.COM 2.4.21-15.0.3.EL #1 Tue Jun 29 18:17:52 EDT 2004 i686 i686 i386 GNU/Linux
4) Your libc version:
Version 6
5) Output of "gcc -v":
Reading specs from /usr/lib/gcc-lib/i386-redhat-linux/3.2.3/specs Configured with: ../configure --prefix=/usr --mandir=/usr/share/man --infodir=/usr/share/info --enable-shared --enable-threads=posix --disable-checking --with-system-zlib --enable-__cxa_atexit --host=i386-redhat-linux Thread model: posix gcc version 3.2.3 20030502 (Red Hat Linux 3.2.3-52)
6) Output of "openssl version":
OpenSSL 0.9.7a Feb 19 2003
7) Log before crash:
2005.06.19 05:10:30 LOG7[7052:3209298656]: pop3s accepted FD=8 from 82.123.194.23:63627 2005.06.19 05:10:30 LOG7[7052:3209298656]: FD 8 in non-blocking mode 2005.06.19 05:10:30 LOG7[7052:3200814000]: pop3s started 2005.06.19 05:10:30 LOG5[7052:3200814000]: pop3s connected from 82.123.194.23:63627 2005.06.19 05:10:30 LOG7[7052:3200814000]: SSL state (accept): before/accept initialization 2005.06.19 05:10:30 LOG7[7052:3200814000]: waitforsocket: FD=8, DIR=read 2005.06.19 05:10:30 LOG7[7052:3200814000]: waitforsocket: ok 2005.06.19 05:10:30 LOG7[7052:3200814000]: SSL state (accept): SSLv3 read client hello A 2005.06.19 05:10:30 LOG7[7052:3200814000]: SSL state (accept): SSLv3 write server hello A 2005.06.19 05:10:30 LOG7[7052:3200814000]: SSL state (accept): SSLv3 write certificate A 2005.06.19 05:10:30 LOG7[7052:3200814000]: SSL state (accept): SSLv3 write server done A 2005.06.19 05:10:30 LOG7[7052:3200814000]: SSL state (accept): SSLv3 flush data 2005.06.19 05:10:30 LOG7[7052:3200814000]: waitforsocket: FD=8, DIR=read 2005.06.19 05:10:30 LOG7[7052:3209298656]: pop3s accepted FD=9 from 82.123.194.23:63628 2005.06.19 05:10:30 LOG7[7052:3209298656]: FD 9 in non-blocking mode 2005.06.19 05:10:30 LOG7[7052:3209206704]: pop3s started 2005.06.19 05:10:30 LOG5[7052:3209206704]: pop3s connected from 82.123.194.23:63628 2005.06.19 05:10:30 LOG7[7052:3209206704]: SSL state (accept): before/accept initialization 2005.06.19 05:10:30 LOG7[7052:3209206704]: waitforsocket: FD=9, DIR=read 2005.06.19 05:10:30 LOG7[7052:3200814000]: waitforsocket: ok 2005.06.19 05:10:30 LOG7[7052:3200814000]: SSL state (accept): SSLv3 read client key exchange A 2005.06.19 05:10:30 LOG7[7052:3200814000]: waitforsocket: FD=8, DIR=read 2005.06.19 05:10:30 LOG7[7052:3209206704]: waitforsocket: ok 2005.06.19 05:10:30 LOG7[7052:3209206704]: SSL state (accept): SSLv3 read client hello A 2005.06.19 05:10:30 LOG7[7052:3209206704]: SSL state (accept): SSLv3 write server hello A 2005.06.19 05:10:30 LOG7[7052:3209206704]: SSL state (accept): SSLv3 write certificate A 2005.06.19 05:10:30 LOG7[7052:3209206704]: SSL state (accept): SSLv3 write server done A 2005.06.19 05:10:30 LOG7[7052:3209206704]: SSL state (accept): SSLv3 flush data 2005.06.19 05:10:30 LOG7[7052:3209206704]: waitforsocket: FD=9, DIR=read 2005.06.19 05:10:30 LOG7[7052:3200814000]: waitforsocket: ok 2005.06.19 05:10:30 LOG7[7052:3200814000]: waitforsocket: FD=8, DIR=read 2005.06.19 05:10:30 LOG7[7052:3209206704]: waitforsocket: ok 2005.06.19 05:10:30 LOG7[7052:3209206704]: SSL state (accept): SSLv3 read client key exchange A 2005.06.19 05:10:30 LOG7[7052:3209206704]: waitforsocket: FD=9, DIR=read 2005.06.19 05:10:30 LOG7[7052:3200814000]: waitforsocket: ok 2005.06.19 05:10:30 LOG7[7052:3200814000]: SSL state (accept): SSLv3 read finished A 2005.06.19 05:10:30 LOG7[7052:3200814000]: SSL state (accept): SSLv3 write change cipher spec A 2005.06.19 05:10:30 LOG7[7052:3200814000]: SSL state (accept): SSLv3 write finished A 2005.06.19 05:10:30 LOG7[7052:3200814000]: SSL state (accept): SSLv3 flush data 2005.06.19 05:10:30 LOG7[7052:3200814000]: 113 items in the session cache 2005.06.19 05:10:30 LOG7[7052:3200814000]: 0 client connects (SSL_connect()) 2005.06.19 05:10:30 LOG7[7052:3200814000]: 0 client connects that finished 2005.06.19 05:10:30 LOG7[7052:3200814000]: 0 client renegotiatations requested 2005.06.19 05:10:30 LOG7[7052:3200814000]: 622 server connects (SSL_accept()) 2005.06.19 05:10:30 LOG7[7052:3200814000]: 621 server connects that finished 2005.06.19 05:10:30 LOG7[7052:3200814000]: 0 server renegotiatiations requested 2005.06.19 05:10:30 LOG7[7052:3200814000]: 0 session cache hits 2005.06.19 05:10:30 LOG7[7052:3200814000]: 0 session cache misses 2005.06.19 05:10:30 LOG7[7052:3200814000]: 0 session cache timeouts 2005.06.19 05:10:30 LOG6[7052:3200814000]: Negotiated ciphers: DES-CBC3-SHA SSLv3 Kx=RSA Au=RSA Enc=3DES(168) Mac=SHA1 2005.06.19 05:10:30 LOG7[7052:3200814000]: FD 10 in non-blocking mode 2005.06.19 05:10:30 LOG7[7052:3200814000]: pop3s connecting 127.0.0.1:110 2005.06.19 05:10:30 LOG7[7052:3200814000]: remote connect #1: EINPROGRESS: retrying 2005.06.19 05:10:30 LOG7[7052:3200814000]: waitforsocket: FD=10, DIR=write 2005.06.19 05:10:30 LOG7[7052:3200814000]: waitforsocket: ok 2005.06.19 05:10:30 LOG7[7052:3200814000]: Remote FD=10 initialized 2005.06.19 05:10:30 LOG7[7052:3209298656]: pop3s accepted FD=11 from 82.123.194.23:63631 2005.06.19 05:10:30 LOG7[7052:3209298656]: FD 11 in non-blocking mode 2005.06.19 05:10:30 LOG7[7052:3192421296]: pop3s started 2005.06.19 05:10:30 LOG5[7052:3192421296]: pop3s connected from 82.123.194.23:63631 2005.06.19 05:10:30 LOG7[7052:3192421296]: SSL state (accept): before/accept initialization 2005.06.19 05:10:30 LOG7[7052:3192421296]: waitforsocket: FD=11, DIR=read 2005.06.19 05:10:31 LOG7[7052:3192421296]: waitforsocket: ok 2005.06.19 05:10:31 LOG7[7052:3192421296]: SSL state (accept): SSLv3 read client hello A 2005.06.19 05:10:31 LOG7[7052:3192421296]: SSL state (accept): SSLv3 write server hello A 2005.06.19 05:10:31 LOG7[7052:3192421296]: SSL state (accept): SSLv3 write certificate A 2005.06.19 05:10:31 LOG7[7052:3192421296]: SSL state (accept): SSLv3 write server done A 2005.06.19 05:10:31 LOG7[7052:3192421296]: SSL state (accept): SSLv3 flush data 2005.06.19 05:10:31 LOG7[7052:3192421296]: waitforsocket: FD=11, DIR=read 2005.06.19 05:10:31 LOG7[7052:3209206704]: waitforsocket: ok 2005.06.19 05:10:31 LOG7[7052:3209206704]: waitforsocket: FD=9, DIR=read 2005.06.19 05:10:31 LOG7[7052:3209298656]: pop3s accepted FD=12 from 82.123.194.23:63632 2005.06.19 05:10:31 LOG7[7052:3209298656]: FD 12 in non-blocking mode 2005.06.19 05:10:31 LOG7[7052:3184028592]: pop3s started 2005.06.19 05:10:31 LOG5[7052:3184028592]: pop3s connected from 82.123.194.23:63632 2005.06.19 05:10:31 LOG7[7052:3184028592]: SSL state (accept): before/accept initialization 2005.06.19 05:10:31 LOG7[7052:3184028592]: waitforsocket: FD=12, DIR=read 2005.06.19 05:10:31 LOG7[7052:3209206704]: waitforsocket: ok 2005.06.19 05:10:31 LOG7[7052:3209206704]: SSL state (accept): SSLv3 read finished A 2005.06.19 05:10:31 LOG7[7052:3209206704]: SSL state (accept): SSLv3 write change cipher spec A 2005.06.19 05:10:31 LOG7[7052:3209206704]: SSL state (accept): SSLv3 write finished A 2005.06.19 05:10:31 LOG7[7052:3209206704]: SSL state (accept): SSLv3 flush data 2005.06.19 05:10:31 LOG7[7052:3209206704]: 114 items in the session cache 2005.06.19 05:10:31 LOG7[7052:3209206704]: 0 client connects (SSL_connect()) 2005.06.19 05:10:31 LOG7[7052:3209206704]: 0 client connects that finished 2005.06.19 05:10:31 LOG7[7052:3209206704]: 0 client renegotiatations requested 2005.06.19 05:10:31 LOG7[7052:3209206704]: 624 server connects (SSL_accept()) 2005.06.19 05:10:31 LOG7[7052:3209206704]: 622 server connects that finished 2005.06.19 05:10:31 LOG7[7052:3209206704]: 0 server renegotiatiations requested 2005.06.19 05:10:31 LOG7[7052:3209206704]: 0 session cache hits 2005.06.19 05:10:31 LOG7[7052:3209206704]: 0 session cache misses 2005.06.19 05:10:31 LOG7[7052:3209206704]: 0 session cache timeouts 2005.06.19 05:10:31 LOG6[7052:3209206704]: Negotiated ciphers: DES-CBC3-SHA SSLv3 Kx=RSA Au=RSA Enc=3DES(168) Mac=SHA1 2005.06.19 05:10:31 LOG7[7052:3209206704]: FD 13 in non-blocking mode 2005.06.19 05:10:31 LOG7[7052:3209206704]: pop3s connecting 127.0.0.1:110 2005.06.19 05:10:31 LOG7[7052:3209206704]: remote connect #1: EINPROGRESS: retrying 2005.06.19 05:10:31 LOG7[7052:3209206704]: waitforsocket: FD=13, DIR=write 2005.06.19 05:10:31 LOG7[7052:3209206704]: waitforsocket: ok 2005.06.19 05:10:31 LOG7[7052:3209206704]: Remote FD=13 initialized 2005.06.19 05:10:31 LOG7[7052:3192421296]: waitforsocket: ok 2005.06.19 05:10:31 LOG7[7052:3192421296]: SSL state (accept): SSLv3 read client key exchange A 2005.06.19 05:10:31 LOG7[7052:3192421296]: waitforsocket: FD=11, DIR=read 2005.06.19 05:10:31 LOG7[7052:3184028592]: waitforsocket: ok 2005.06.19 05:10:31 LOG7[7052:3184028592]: SSL state (accept): SSLv3 read client hello A 2005.06.19 05:10:31 LOG7[7052:3184028592]: SSL state (accept): SSLv3 write server hello A 2005.06.19 05:10:31 LOG7[7052:3184028592]: SSL state (accept): SSLv3 write certificate A 2005.06.19 05:10:31 LOG7[7052:3184028592]: SSL state (accept): SSLv3 write server done A 2005.06.19 05:10:31 LOG7[7052:3184028592]: SSL state (accept): SSLv3 flush data 2005.06.19 05:10:31 LOG7[7052:3184028592]: waitforsocket: FD=12, DIR=read 2005.06.19 05:10:31 LOG7[7052:3192421296]: waitforsocket: ok 2005.06.19 05:10:31 LOG7[7052:3192421296]: SSL state (accept): SSLv3 read finished A 2005.06.19 05:10:31 LOG7[7052:3192421296]: SSL state (accept): SSLv3 write change cipher spec A 2005.06.19 05:10:31 LOG7[7052:3192421296]: SSL state (accept): SSLv3 write finished A 2005.06.19 05:10:31 LOG7[7052:3192421296]: SSL state (accept): SSLv3 flush data 2005.06.19 05:10:31 LOG7[7052:3192421296]: 115 items in the session cache 2005.06.19 05:10:31 LOG7[7052:3192421296]: 0 client connects (SSL_connect()) 2005.06.19 05:10:31 LOG7[7052:3192421296]: 0 client connects that finished 2005.06.19 05:10:31 LOG7[7052:3192421296]: 0 client renegotiatations requested 2005.06.19 05:10:31 LOG7[7052:3192421296]: 624 server connects (SSL_accept()) 2005.06.19 05:10:31 LOG7[7052:3192421296]: 623 server connects that finished 2005.06.19 05:10:31 LOG7[7052:3192421296]: 0 server renegotiatiations requested 2005.06.19 05:10:31 LOG7[7052:3192421296]: 0 session cache hits 2005.06.19 05:10:31 LOG7[7052:3192421296]: 0 session cache misses 2005.06.19 05:10:31 LOG7[7052:3192421296]: 0 session cache timeouts 2005.06.19 05:10:31 LOG6[7052:3192421296]: Negotiated ciphers: DES-CBC3-SHA SSLv3 Kx=RSA Au=RSA Enc=3DES(168) Mac=SHA1 2005.06.19 05:10:31 LOG7[7052:3192421296]: FD 14 in non-blocking mode 2005.06.19 05:10:31 LOG7[7052:3192421296]: pop3s connecting 127.0.0.1:110 2005.06.19 05:10:31 LOG7[7052:3192421296]: remote connect #1: EINPROGRESS: retrying 2005.06.19 05:10:31 LOG7[7052:3192421296]: waitforsocket: FD=14, DIR=write 2005.06.19 05:10:31 LOG7[7052:3192421296]: waitforsocket: ok 2005.06.19 05:10:31 LOG7[7052:3192421296]: Remote FD=14 initialized 2005.06.19 05:10:31 LOG7[7052:3184028592]: waitforsocket: ok 2005.06.19 05:10:31 LOG7[7052:3184028592]: SSL state (accept): SSLv3 read client key exchange A 2005.06.19 05:10:31 LOG7[7052:3184028592]: waitforsocket: FD=12, DIR=read 2005.06.19 05:10:31 LOG7[7052:3184028592]: waitforsocket: ok 2005.06.19 05:10:31 LOG7[7052:3184028592]: SSL state (accept): SSLv3 read finished A 2005.06.19 05:10:31 LOG7[7052:3184028592]: SSL state (accept): SSLv3 write change cipher spec A 2005.06.19 05:10:31 LOG7[7052:3184028592]: SSL state (accept): SSLv3 write finished A 2005.06.19 05:10:31 LOG7[7052:3184028592]: SSL state (accept): SSLv3 flush data 2005.06.19 05:10:31 LOG7[7052:3184028592]: 116 items in the session cache 2005.06.19 05:10:31 LOG7[7052:3184028592]: 0 client connects (SSL_connect()) 2005.06.19 05:10:31 LOG7[7052:3184028592]: 0 client connects that finished 2005.06.19 05:10:31 LOG7[7052:3184028592]: 0 client renegotiatations requested 2005.06.19 05:10:31 LOG7[7052:3184028592]: 624 server connects (SSL_accept()) 2005.06.19 05:10:31 LOG7[7052:3184028592]: 624 server connects that finished 2005.06.19 05:10:31 LOG7[7052:3184028592]: 0 server renegotiatiations requested 2005.06.19 05:10:31 LOG7[7052:3184028592]: 0 session cache hits 2005.06.19 05:10:31 LOG7[7052:3184028592]: 0 session cache misses 2005.06.19 05:10:31 LOG7[7052:3184028592]: 0 session cache timeouts 2005.06.19 05:10:31 LOG6[7052:3184028592]: Negotiated ciphers: DES-CBC3-SHA SSLv3 Kx=RSA Au=RSA Enc=3DES(168) Mac=SHA1 2005.06.19 05:10:31 LOG7[7052:3184028592]: FD 15 in non-blocking mode 2005.06.19 05:10:31 LOG7[7052:3184028592]: pop3s connecting 127.0.0.1:110 2005.06.19 05:10:31 LOG7[7052:3184028592]: remote connect #1: EINPROGRESS: retrying 2005.06.19 05:10:31 LOG7[7052:3184028592]: waitforsocket: FD=15, DIR=write 2005.06.19 05:10:31 LOG7[7052:3184028592]: waitforsocket: ok 2005.06.19 05:10:31 LOG7[7052:3184028592]: Remote FD=15 initialized 2005.06.19 05:10:33 LOG7[7052:3200814000]: Socket closed on read 2005.06.19 05:10:33 LOG7[7052:3200814000]: SSL alert (write): warning: close notify 2005.06.19 05:10:33 LOG7[7052:3200814000]: SSL write shutdown (output buffer empty) 2005.06.19 05:10:34 LOG7[7052:3209206704]: Socket closed on read 2005.06.19 05:10:34 LOG7[7052:3209206704]: SSL alert (write): warning: close notify 2005.06.19 05:10:34 LOG7[7052:3209206704]: SSL write shutdown (output buffer empty) 2005.06.19 05:10:34 LOG7[7052:3192421296]: Socket closed on read 2005.06.19 05:10:34 LOG7[7052:3192421296]: SSL alert (write): warning: close notify 2005.06.19 05:10:34 LOG7[7052:3192421296]: SSL write shutdown (output buffer empty) 2005.06.19 05:10:34 LOG7[7052:3200814000]: SSL socket closed on SSL_read 2005.06.19 05:10:34 LOG5[7052:3200814000]: Connection closed: 3470 bytes sent to SSL, 42 bytes sent to socket 2005.06.19 05:10:34 LOG7[7052:3200814000]: pop3s finished (3 left) 2005.06.19 05:10:34 LOG7[7052:3209206704]: SSL socket closed on SSL_read 2005.06.19 05:10:34 LOG5[7052:3209206704]: Connection closed: 3342 bytes sent to SSL, 53 bytes sent to socket 2005.06.19 05:10:34 LOG7[7052:3209206704]: pop3s finished (2 left) 2005.06.19 05:10:34 LOG7[7052:3192421296]: SSL socket closed on SSL_read 2005.06.19 05:10:34 LOG5[7052:3192421296]: Connection closed: 480 bytes sent to SSL, 47 bytes sent to socket 2005.06.19 05:10:34 LOG7[7052:3192421296]: pop3s finished (1 left) 2005.06.19 05:10:34 LOG7[7052:3184028592]: Socket closed on read 2005.06.19 05:10:34 LOG7[7052:3184028592]: SSL alert (write): warning: close notify 2005.06.19 05:10:34 LOG7[7052:3184028592]: SSL write shutdown (output buffer empty) 2005.06.19 05:10:34 LOG7[7052:3184028592]: SSL socket closed on SSL_read 2005.06.19 05:10:34 LOG5[7052:3184028592]: Connection closed: 1934 bytes sent to SSL, 51 bytes sent to socket 2005.06.19 05:10:34 LOG7[7052:3184028592]: pop3s finished (0 left)