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)