[stunnel-users] Odd termination of stunnel process...

Fri May 8 05:07:42 CEST 2009

Greetings,

I do not know the exact reason for the problem that you are experimenting but here are a couple of ideas.

- You mentioned that the web servers run on the same machine. So that makes them local to that host. The question is could you  bind the web servers to accept non-ssl connection on 127.0.0.1 and ssl-connections on 172.16.0.1?
If the client and the server run on the same host I think makes more sense to run the connections on 127.0.0.1

- The other thing is that maybe your web server forces you to use SSL and there is no way to try the solution stated above. Then I would suggest you upgrade your stunnel installation. The version you reported using is 4.15 and there have been several changes on stunnel since version 4.15

-  A quick google search for the  SSL3_GET_FINISHED:digest check failed error points more towards OpenSSL being reponsible for the situation here. I would just check the SSL settings, making sure you use the same protocol on both ends SSLv3 or TLSv1.

Hope this helps

 -----------------
Leandro Avila 

----- Original Message ----
From: Robert Nickel <rnickel+stunnel at scea.com>
To: stunnel-users at mirt..net
Sent: Monday, May 4, 2009 4:15:35 PM
Subject: [stunnel-users] Odd termination of stunnel process...

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 at 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
_______________________________________________
stunnel-users mailing list
stunnel-users at mirt.net
http://stunnel.mirt.net/mailman/listinfo/stunnel-users