[stunnel-users] Stunnel crashing
David Gomel
dave at gomel.ca
Sun Jun 19 16:58:34 CEST 2005
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)
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.stunnel.org/pipermail/stunnel-users/attachments/20050619/5d105f8d/attachment.html>
More information about the stunnel-users
mailing list