We've been happily using stunnel for quite some time now and have run into a strange problem. At seemingly random intervals, stunnel just freaks out an dies. I don't know if it's getting overwhelmed or what but I'm not seeing anything in the logs for stunnel or any other process. Any help is appreciated.
Stunnel is being used to wrap a service that was written without use of the ssl libraries directly and connects to two remote web servers (that happen to be running on the same host, separate ports).
Config information: OS: CentOS 5.1 OpenSSL: 0.9.8b stunnel -version: stunnel 4.15 on i686-redhat-linux-gnu with OpenSSL 0.9.8b 04 May 2006 Threading:PTHREAD SSL:ENGINE Sockets:POLL,IPv6 Auth:LIBWRAP
Global options debug = 5 pid = /var/run/stunnel.pid RNDbytes = 64 RNDfile = /dev/urandom RNDoverwrite = yes
Service-level options cert = /etc/stunnel/stunnel.pem ciphers = ALL:!ADH:+RC4:@STRENGTH key = /etc/stunnel/stunnel.pem session = 300 seconds TIMEOUTbusy = 300 seconds TIMEOUTclose = 60 seconds TIMEOUTconnect = 10 seconds TIMEOUTidle = 43200 seconds verify = none Config file contents: client=yes foreground=no pid=/var/run/pid chroot=/path/to/chroot setuid=non-priv-user setgid=non-priv-group [webservice1] accept=127.0.0.1:11000 connect=172.16.0.1:11000 [webservice2] accept=127.0.0.1:11001 connect=172.16.0.1:11001
Below are the log lines just before the process disappears:
May 4 19:49:18 host stunnel: LOG7[28683:3085368208]: Remote FD=15 initialized May 4 19:49:18 host stunnel: LOG7[28683:3085298576]: SSL state (connect): SSLv3 write client key exchange A May 4 19:49:18 host stunnel: LOG7[28683:3085298576]: SSL state (connect): SSLv3 write change cipher spec A May 4 19:49:18 host stunnel: LOG7[28683:3085298576]: SSL state (connect): SSLv3 write finished A May 4 19:49:18 host stunnel: LOG7[28683:3085716368]: SSL state (connect): SSLv3 read server hello A May 4 19:49:18 host stunnel: LOG7[28683:3085716368]: SSL state (connect): SSLv3 read server certificate A May 4 19:49:18 host stunnel: LOG7[28683:3085298576]: SSL state (connect): SSLv3 flush data May 4 19:49:18 host stunnel: LOG7[28683:3085368208]: SSL state (connect): before/connect initialization May 4 19:49:18 host stunnel: LOG7[28683:3085786000]: SSL alert (write): fatal: handshake failure May 4 19:49:18 host stunnel: LOG3[28683:3085786000]: SSL_connect: 1408C095: error:1408C095:SSL routines:SSL3_GET_FINISHED:digest check failed May 4 19:49:18 host stunnel: LOG5[28683:3085786000]: Connection reset: 0 bytes sent to SSL, 0 bytes sent to socket May 4 19:49:18 host stunnel: LOG7[28683:3085786000]: replay finished (8 left) May 4 19:49:18 host stunnel: LOG7[28683:3085368208]: SSL state (connect): SSLv3 write client hello A May 4 19:49:18 host stunnel: LOG7[28683:3085716368]: SSL state (connect): SSLv3 read server key exchange A May 4 19:49:18 host stunnel: LOG7[28683:3085716368]: SSL state (connect): SSLv3 read server done A May 4 19:49:18 host stunnel: LOG7[28683:3085928144]: replay accepted FD=18 from 127.0.0.1:40308 May 4 19:49:18 host stunnel: LOG7[28683:3085786000]: replay started May 4 19:49:18 host stunnel: LOG7[28683:3085786000]: FD 18 in non-blocking mode May 4 19:49:18 host stunnel: LOG7[28683:3085786000]: FD 19 in non-blocking mode May 4 19:49:18 host stunnel: LOG7[28683:3085786000]: FD 26 in non-blocking mode May 4 19:49:18 host stunnel: LOG7[28683:3085786000]: Connection from 127.0.0.1:40308 permitted by libwrap May 4 19:49:18 host stunnel: LOG5[28683:3085786000]: replay connected from 127.0.0.1:40308 May 4 19:49:18 host stunnel: LOG7[28683:3085786000]: FD 19 in non-blocking mode May 4 19:49:18 host stunnel: LOG7[28683:3085786000]: replay connecting 160.33.167.33:11026 May 4 19:49:18 host stunnel: LOG7[28683:3085786000]: connect_wait: waiting 10 seconds May 4 19:49:18 host stunnel: LOG7[28683:3085928144]: Cleaning up the signal pipe May 4 19:49:18 host stunnel: LOG6[28683:3085928144]: Child process 13775 finished with code 0 May 4 19:49:18 host stunnel: LOG7[28683:3085646736]: SSL alert (write): fatal: handshake failure May 4 19:49:18 host stunnel: LOG3[28683:3085646736]: SSL_connect: 1408C095: error:1408C095:SSL routines:SSL3_GET_FINISHED:digest check failed May 4 19:49:18 host stunnel: LOG5[28683:3085646736]: Connection reset: 0 bytes sent to SSL, 0 bytes sent to socket May 4 19:49:18 host stunnel: LOG7[28683:3085716368]: SSL state (connect): SSLv3 write client key exchange A May 4 19:49:18 host stunnel: LOG7[28683:3085716368]: SSL state (connect): SSLv3 write change cipher spec A May 4 19:49:18 host stunnel: LOG7[28683:3085716368]: SSL state (connect): SSLv3 write finished A May 4 19:49:18 host stunnel: LOG7[28683:3085716368]: SSL state (connect): SSLv3 flush data May 4 19:49:18 host stunnel: LOG7[28683:3085646736]: replay finished (8 left) May 4 19:49:18 host stunnel: LOG7[28683:3085855632]: connect_wait: connected May 4 19:49:18 host stunnel: LOG7[28683:3085855632]: Remote FD=17 initialized May 4 19:49:18 host stunnel: LOG7[28683:3085855632]: SSL state (connect): before/connect initialization May 4 19:49:18 host stunnel: LOG7[28683:3085855632]: SSL state (connect): SSLv3 write client hello A May 4 19:49:18 host stunnel: LOG7[28683:3085928144]: replay accepted FD=22 from 127.0.0.1:40310 May 4 19:49:18 host stunnel: LOG7[28683:3085646736]: replay started May 4 19:49:18 host stunnel: LOG7[28683:3085646736]: FD 22 in non-blocking mode May 4 19:49:18 host stunnel: LOG7[28683:3085646736]: FD 23 in non-blocking mode May 4 19:49:18 host stunnel: LOG7[28683:3085646736]: FD 26 in non-blocking mode May 4 19:49:18 host stunnel: LOG7[28683:3085928144]: Cleaning up the signal pipe May 4 19:49:18 host stunnel: LOG6[28683:3085928144]: Child process 13777 finished with code 0 May 4 19:49:18 host stunnel: LOG7[28683:3085646736]: Connection from 127.0.0.1:40310 permitted by libwrap May 4 19:49:18 host stunnel: LOG5[28683:3085646736]: replay connected from 127.0.0.1:40310 May 4 19:49:18 host stunnel: LOG7[28683:3085646736]: FD 23 in non-blocking mode May 4 19:49:18 host stunnel: LOG7[28683:3085646736]: replay connecting 160.33.167.33:11026 May 4 19:49:18 host stunnel: LOG7[28683:3085646736]: connect_wait: waiting 10 seconds May 4 19:49:18 host stunnel: LOG7[28683:3085507472]: SSL state (connect): SSLv3 read server hello A May 4 19:49:18 host stunnel: LOG7[28683:3085507472]: SSL state (connect): SSLv3 read server certificate A May 4 19:49:18 host stunnel: LOG7[28683:3085507472]: SSL state (connect): SSLv3 read server key exchange A May 4 19:49:18 host stunnel: LOG7[28683:3085507472]: SSL state (connect): SSLv3 read server done A May 4 19:49:18 host stunnel: LOG7[28683:3085786000]: connect_wait: connected May 4 19:49:18 host stunnel: LOG7[28683:3085786000]: Remote FD=19 initialized May 4 19:49:18 host stunnel: LOG7[28683:3085786000]: SSL state (connect): before/connect initialization May 4 19:49:18 host stunnel: LOG7[28683:3085786000]: SSL state (connect): SSLv3 write client hello A May 4 19:49:18 host stunnel: LOG7[28683:3085298576]: SSL alert (write): fatal: handshake failure May 4 19:49:18 host stunnel: LOG3[28683:3085298576]: SSL_connect: 1408C095: error:1408C095:SSL routines:SSL3_GET_FINISHED:digest check failed May 4 19:49:18 host stunnel: LOG5[28683:3085298576]: Connection reset: 0 bytes sent to SSL, 0 bytes sent to socket May 4 19:49:18 host stunnel: LOG7[28683:3085298576]: replay finished (8 left) May 4 19:49:18 host stunnel: LOG7[28683:3085507472]: SSL state (connect): SSLv3 write client key exchange A May 4 19:49:18 host stunnel: LOG7[28683:3085507472]: SSL state (connect): SSLv3 write change cipher spec A May 4 19:49:18 host stunnel: LOG7[28683:3085507472]: SSL state (connect): SSLv3 write finished A May 4 19:49:18 host stunnel: LOG7[28683:3085507472]: SSL state (connect): SSLv3 flush data May 4 19:49:18 host stunnel: LOG7[28683:3085925264]: SSL alert (write): fatal: handshake failure May 4 19:49:18 host stunnel: LOG3[28683:3085925264]: SSL_connect: 1408C095: error:1408C095:SSL routines:SSL3_GET_FINISHED:digest check failed May 4 19:49:18 host stunnel: LOG5[28683:3085925264]: Connection reset: 0 bytes sent to SSL, 0 bytes sent to socket May 4 19:49:18 host stunnel: LOG7[28683:3085925264]: replay finished (7 left) May 4 19:49:18 host stunnel: LOG7[28683:3085368208]: SSL state (connect): SSLv3 read server hello A May 4 19:49:18 host stunnel: LOG7[28683:3085368208]: SSL state (connect): SSLv3 read server certificate A May 4 19:49:18 host stunnel: LOG7[28683:3085368208]: SSL state (connect): SSLv3 read server key exchange A May 4 19:49:18 host stunnel: LOG7[28683:3085368208]: SSL state (connect): SSLv3 read server done A May 4 19:49:18 host stunnel: LOG7[28683:3085577104]: SSL state (connect): SSLv3 read server hello A May 4 19:49:18 host stunnel: LOG7[28683:3085577104]: SSL state (connect): SSLv3 read server certificate A May 4 19:49:18 host stunnel: LOG7[28683:3085577104]: SSL state (connect): SSLv3 read server key exchange A May 4 19:49:18 host stunnel: LOG7[28683:3085577104]: SSL state (connect): SSLv3 read server done A [stunnel vanishes at this point. No core, no logs. POOF!]
The lines that stand out to me are the SSL_connect digest errors, the finished lines (showing the number of queued requests in parenthesis?) and the fatal handshake failure.
Another odd log entry that I'm seeing often is this transfer() loop error:
May 4 21:12:53 host stunnel: LOG3[14341:3085822864]: transfer() loop executes not transferring any data May 4 21:12:53 host stunnel: LOG3[14341:3085822864]: please report the problem to Michal.Trojnara@mirt.net May 4 21:12:53 host stunnel: LOG3[14341:3085822864]: socket open: rd=no wr=yes, ssl open: rd=no wr=no May 4 21:12:53 host stunnel: LOG3[14341:3085822864]: socket ready: rd=yes wr=no, ssl ready: rd=no wr=no May 4 21:12:53 host stunnel: LOG3[14341:3085822864]: ssl want: rd=no wr=no May 4 21:12:53 host stunnel: LOG3[14341:3085822864]: socket input buffer: 0 byte(s), ssl input buffer: 29 byte(s) May 4 21:12:53 host stunnel: LOG3[14341:3085822864]: check_SSL_pending=0, ssl_closing=3 May 4 21:12:53 host stunnel: LOG5[14341:3085822864]: Connection reset: 238 bytes sent to SSL, 225 bytes sent to socket
Don't know if it's related but might as well post it along as a possible symptom.
Thanks, --Robert