[Stunnel Guru needed] stunnel running, but no longer serve connection after a while ("Dispatching signals from the signal pipe" in logs ==> all stops)
Hi All,
I'm really struggling to make stunnel working for more than a few hours. (and the client is yelling hard...) (I solved some other issue : logging per website and making more than one stunnel works)
To put it in a nutshell :
- stunnel is running and working correctly (I can reach the website in https correctly) - after some hours I get the following situation : - stunnel is still running on linux - trying to connect to a website result in the connection taking very long time and then fails : "*The connection to * extranet.serviceplus-hse.com http://extranet.website.com* was interrupted. Error 101 (net::ERR_CONNECTION_RESET): The connection was reset.*" (Chrome) Same symptoms on IE9, Firefox & Lynx (on the server that runs stunnel) (see logs below)
- The following logs are the last one seen in the log file :
- 2012.04.03 23:33:28 LOG5[24792:140152610346752]: Service extranet.serviceplus-hse.com connected remote server from 127.0.0.1:36256 - 2012.04.03 23:33:28 LOG7[24792:140152610346752]: Remote FD=1 initialized - 2012.04.03 23:33:28 LOG7[24792:140152610346752]: Option TCP_NODELAY set on remote socket - 2012.04.03 23:33:41 LOG7[24792:140152610346752]: Socket closed on read - 2012.04.03 23:33:41 LOG7[24792:140152610346752]: Sending SSL write shutdown - 2012.04.03 23:33:41 LOG7[24792:140152610346752]: SSL alert (write): warning: close notify - 2012.04.03 23:33:41 LOG6[24792:140152610346752]: SSL_shutdown successfully sent close_notify - 2012.04.03 23:33:41 LOG3[24792:140152610346752]: transfer: s_poll_wait: TIMEOUTclose exceeded: closing - 2012.04.03 23:33:41 LOG5[24792:140152610346752]: Connection closed: 186584 bytes sent to SSL, 3275 bytes sent to socket - 2012.04.03 23:33:41 LOG7[24792:140152610346752]: Service extranet.serviceplus-hse.com finished (0 left) - 2012.04.04 06:25:04 LOG7[24792:140152610629408]: *Dispatching signals from the signal pipe *
stopping the firewall & fail2ban do not change anything.
(the last line is logged by this function : *static void signal_pipe_empty(void) ) * the base stunnel.log has the same ending :
- 2012.04.03 21:10:42 LOG7[24778:139641780209408]: Service https-123monsite.com permitted by libwrap from 212.162.10.34:3244 - 2012.04.03 21:10:42 LOG5[24778:139641780209408]: Service https-123monsite.com accepted connection from 212.162.10.34:3244 - 2012.04.03 21:10:42 LOG7[24778:139641780209408]: SSL state (accept): before/accept initialization - 2012.04.03 21:10:42 LOG3[24778:139641780209408]: SSL_accept: 1408F10B: error:1408F10B:SSL routines:SSL3_GET_RECORD:wrong version number - 2012.04.03 21:10:42 LOG5[24778:139641780209408]: Connection reset: 0 bytes sent to SSL, 0 bytes sent to socket - 2012.04.03 21:10:42 LOG7[24778:139641780209408]: Service https-123monsite.com finished (0 left) - 2012.04.04 06:25:04 LOG7[24778:139641780213536]: Dispatching signals from the signal pipe - and at the same time (2012.04.04 06:25:04) all logs file stops :
- root@ns0:/var/log/stunnel4# ll - total 128 - drwxr-xr-x 2 stunnel4 stunnel4 4096 2012-04-04 12:10 . - drwxr-xr-x 14 root root 4096 2012-04-04 06:25 .. - -rw-r----- 1 stunnel4 stunnel4 98084 2012-04-04 *06:25*extranet.serviceplus-hse.com_stunnel.log - -rw-r----- 1 stunnel4 stunnel4 4491 2012-04-04 06:25 mansonthomas.com_stunnel.log - -rw-r----- 1 stunnel4 stunnel4 0 2012-04-04 06:25 stunnel.log - -rw-r----- 1 stunnel4 stunnel4 11058 2012-04-04 06:25 stunnel.log.1 -
I've seen some message about the same behavior but after an upgrade on freebsd and didn't find any solution...
- Restarting stunnel restore the service immediately.
below some information about my configuration... ask for more if needed.
Thanks for any helps, Regards, Thomas.
Distribution & Pachage info (x64 system) ###################################################################### root@ns0:/var/log/stunnel4# cat /etc/lsb-release DISTRIB_ID=Ubuntu DISTRIB_RELEASE=11.10 DISTRIB_CODENAME=oneiric DISTRIB_DESCRIPTION="Ubuntu 11.10"
root@ns0:/var/log/stunnel4# aptitude show stunnel4 Package: stunnel4 New: yes State: installed Automatically installed: no Version: 3:*4.35-2build1* ######################################################################
lynx try : ###################################################################### root@ns0:/var/log/stunnel4# lynx https://extranet.serviceplus-hse.com
Looking up extranet.serviceplus-hse.com Making HTTPS connection to extranet.serviceplus-hse.com Retrying connection without TLS. Looking up extranet.serviceplus-hse.com Making HTTPS connection to extranet.serviceplus-hse.com Alert!: Unable to make secure connection to remote host.
lynx: Can't access startfile https://extranet.serviceplus-hse.com/ ######################################################################
ps -edf : ###################################################################### 1 24773 24762 18168 ? -1 S 109 0:00 /usr/bin/stunnel4 /etc/stunnel/base.conf TERM=screen-bce PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/X11R6/bin LANG=en_US.UTF-8 PWD=/ 1 24774 24762 18168 ? -1 S 109 0:00 /usr/bin/stunnel4 /etc/stunnel/base.conf TERM=screen-bce PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/X11R6/bin LANG=en_US.UTF-8 PWD=/ 1 24775 24762 18168 ? -1 S 109 0:00 /usr/bin/stunnel4 /etc/stunnel/base.conf TERM=screen-bce PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/X11R6/bin LANG=en_US.UTF-8 PWD=/ 1 24776 24762 18168 ? -1 S 109 0:00 /usr/bin/stunnel4 /etc/stunnel/base.conf TERM=screen-bce PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/X11R6/bin LANG=en_US.UTF-8 PWD=/ 1 24777 24762 18168 ? -1 S 109 0:00 /usr/bin/stunnel4 /etc/stunnel/base.conf TERM=screen-bce PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/X11R6/bin LANG=en_US.UTF-8 PWD=/ 1 24778 24778 24778 ? -1 Ss 109 0:00 /usr/bin/stunnel4 /etc/stunnel/base.conf TERM=screen-bce PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/X11R6/bin LANG=en_US.UTF-8 PWD=/ 1 24787 24762 18168 ? -1 S 109 0:00 /usr/bin/stunnel4 /etc/stunnel/extranet.serviceplus-hse.com.conf TERM=screen-bce PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/X11R6/bin LANG=en_US.UTF-8 P 1 24788 24762 18168 ? -1 S 109 0:00 /usr/bin/stunnel4 /etc/stunnel/extranet.serviceplus-hse.com.conf TERM=screen-bce PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/X11R6/bin LANG=en_US.UTF-8 P 1 24789 24762 18168 ? -1 S 109 0:00 /usr/bin/stunnel4 /etc/stunnel/extranet.serviceplus-hse.com.conf TERM=screen-bce PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/X11R6/bin LANG=en_US.UTF-8 P 1 24790 24762 18168 ? -1 S 109 0:00 /usr/bin/stunnel4 /etc/stunnel/extranet.serviceplus-hse.com.conf TERM=screen-bce PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/X11R6/bin LANG=en_US.UTF-8 P 1 24791 24762 18168 ? -1 S 109 0:00 /usr/bin/stunnel4 /etc/stunnel/extranet.serviceplus-hse.com.conf TERM=screen-bce PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/X11R6/bin LANG=en_US.UTF-8 P 1 24792 24792 24792 ? -1 Ss 109 0:00 /usr/bin/stunnel4 /etc/stunnel/extranet.serviceplus-hse.com.conf TERM=screen-bce PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/X11R6/bin LANG=en_US.UTF-8 P 1 24801 24762 18168 ? -1 S 109 0:00 /usr/bin/stunnel4 /etc/stunnel/mansonthomas.com.conf TERM=screen-bce PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/X11R6/bin LANG=en_US.UTF-8 PWD=/ 1 24802 24762 18168 ? -1 S 109 0:00 /usr/bin/stunnel4 /etc/stunnel/mansonthomas.com.conf TERM=screen-bce PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/X11R6/bin LANG=en_US.UTF-8 PWD=/ 1 24803 24762 18168 ? -1 S 109 0:00 /usr/bin/stunnel4 /etc/stunnel/mansonthomas.com.conf TERM=screen-bce PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/X11R6/bin LANG=en_US.UTF-8 PWD=/ 1 24804 24762 18168 ? -1 S 109 0:00 /usr/bin/stunnel4 /etc/stunnel/mansonthomas.com.conf TERM=screen-bce PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/X11R6/bin LANG=en_US.UTF-8 PWD=/ 1 24805 24762 18168 ? -1 S 109 0:00 /usr/bin/stunnel4 /etc/stunnel/mansonthomas.com.conf TERM=screen-bce PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/X11R6/bin LANG=en_US.UTF-8 PWD=/ 1 24806 24806 24806 ? -1 Ss 109 0:00 /usr/bin/stunnel4 /etc/stunnel/mansonthomas.com.conf TERM=screen-bce PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/X11R6/bin LANG=en_US.UTF-8 PWD=/ ######################################################################
/etc/stunnel/base.conf ###################################################################### debug = 7
sslVersion = SSLv3 cert=/etc/stunnel/sites/123monsite.com/123monsite.com.crt key=/etc/stunnel/sites/123monsite.com/123monsite.com.key
; security enhancements for UNIX systems ; for chroot a copy of some devices and files is needed within the jail ;chroot = /var/lib/stunnel4/ setuid = stunnel4 setgid = stunnel4 ; PID is created inside the chroot jail pid = /var/run/stunnel4/stunnel4.pid
socket = l:TCP_NODELAY=1 socket = r:TCP_NODELAY=1 output = /var/log/stunnel4/stunnel.log
[https-123monsite.com] accept=88.190.17.222:443 connect=127.0.0.1:82 ######################################################################
/etc/stunnel/extranet.serviceplus-hse.com.conf ###################################################################### debug = 7 output = /var/log/stunnel4/extranet.serviceplus-hse.com_stunnel.log setuid = stunnel4 setgid = stunnel4 pid = /var/run/stunnel4/extranet.serviceplus-hse.com.pid socket = l:TCP_NODELAY=1 socket = r:TCP_NODELAY=1
[extranet.serviceplus-hse.com] key = /etc/stunnel/sites/ extranet.serviceplus-hse.com/extranet.serviceplus-hse.com.key cert = /etc/stunnel/sites/ extranet.serviceplus-hse.com/extranet.serviceplus-hse.com.crt accept = 88.190.217.54:443 connect = 127.0.0.1:82
sslVersion = SSLv3 TIMEOUTclose = 0 ######################################################################
Last logs : /var/log/stunnel4/extranet.serviceplus-hse.com_stunnel.log ###################################################################### 2012.04.03 23:02:47 LOG6[24792:140152610346752]: SSL accepted: previous session reused 2012.04.03 23:02:47 LOG7[24792:140152610346752]: remote socket: FD=1 allocated (non-blocking mode) 2012.04.03 23:02:47 LOG6[24792:140152610346752]: connect_blocking: connecting 127.0.0.1:82 2012.04.03 23:02:47 LOG7[24792:140152610346752]: connect_blocking: s_poll_wait 127.0.0.1:82: waiting 10 seconds 2012.04.03 23:02:47 LOG5[24792:140152610346752]: connect_blocking: connected 127.0.0.1:82 2012.04.03 23:02:47 LOG5[24792:140152610346752]: Service extranet.serviceplus-hse.com connected remote server from 127.0.0.1:60624 2012.04.03 23:02:47 LOG7[24792:140152610346752]: Remote FD=1 initialized 2012.04.03 23:02:47 LOG7[24792:140152610346752]: Option TCP_NODELAY set on remote socket 2012.04.03 23:02:58 LOG7[24792:140152610346752]: Socket closed on read 2012.04.03 23:02:58 LOG7[24792:140152610346752]: Sending SSL write shutdown 2012.04.03 23:02:58 LOG7[24792:140152610346752]: SSL alert (write): warning: close notify 2012.04.03 23:02:58 LOG6[24792:140152610346752]: SSL_shutdown successfully sent close_notify 2012.04.03 23:02:58 LOG3[24792:140152610346752]: transfer: s_poll_wait: TIMEOUTclose exceeded: closing 2012.04.03 23:02:58 LOG5[24792:140152610346752]: Connection closed: 167313 bytes sent to SSL, 1871 bytes sent to socket 2012.04.03 23:02:58 LOG7[24792:140152610346752]: Service extranet.serviceplus-hse.com finished (0 left) 2012.04.03 23:33:20 LOG7[24792:140152610629408]: local socket: FD=0 allocated (non-blocking mode) 2012.04.03 23:33:20 LOG7[24792:140152610629408]: Service extranet.serviceplus-hse.com accepted FD=0 from 82.224.128.241:52114 2012.04.03 23:33:20 LOG7[24792:140152610346752]: Service extranet.serviceplus-hse.com started 2012.04.03 23:33:20 LOG7[24792:140152610346752]: Option TCP_NODELAY set on local socket 2012.04.03 23:33:20 LOG7[24792:140152610346752]: Waiting for a libwrap process 2012.04.03 23:33:20 LOG7[24792:140152610346752]: Acquired libwrap process #0 2012.04.03 23:33:20 LOG7[24792:140152610346752]: Releasing libwrap process #0 2012.04.03 23:33:20 LOG7[24792:140152610346752]: Released libwrap process #0 2012.04.03 23:33:20 LOG7[24792:140152610346752]: Service extranet.serviceplus-hse.com permitted by libwrap from 82.224.128.241:52114 2012.04.03 23:33:20 LOG5[24792:140152610346752]: Service extranet.serviceplus-hse.com accepted connection from 82.224.128.241:52114 2012.04.03 23:33:20 LOG7[24792:140152610346752]: SSL state (accept): before/accept initialization 2012.04.03 23:33:20 LOG7[24792:140152610346752]: SSL state (accept): SSLv3 read client hello B 2012.04.03 23:33:20 LOG7[24792:140152610346752]: SSL state (accept): SSLv3 write server hello A 2012.04.03 23:33:20 LOG7[24792:140152610346752]: SSL state (accept): SSLv3 write certificate A 2012.04.03 23:33:20 LOG7[24792:140152610346752]: SSL state (accept): SSLv3 write key exchange A 2012.04.03 23:33:20 LOG7[24792:140152610346752]: SSL state (accept): SSLv3 write server done A 2012.04.03 23:33:20 LOG7[24792:140152610346752]: SSL state (accept): SSLv3 flush data 2012.04.03 23:33:20 LOG7[24792:140152610346752]: SSL state (accept): SSLv3 read client key exchange A 2012.04.03 23:33:20 LOG7[24792:140152610346752]: SSL state (accept): SSLv3 read finished A 2012.04.03 23:33:20 LOG7[24792:140152610346752]: SSL state (accept): SSLv3 write change cipher spec A 2012.04.03 23:33:20 LOG7[24792:140152610346752]: SSL state (accept): SSLv3 write finished A 2012.04.03 23:33:20 LOG7[24792:140152610346752]: SSL state (accept): SSLv3 flush data 2012.04.03 23:33:20 LOG7[24792:140152610346752]: 7 items in the session cache 2012.04.03 23:33:20 LOG7[24792:140152610346752]: 0 client connects (SSL_connect()) 2012.04.03 23:33:20 LOG7[24792:140152610346752]: 0 client connects that finished 2012.04.03 23:33:20 LOG7[24792:140152610346752]: 0 client renegotiations requested 2012.04.03 23:33:20 LOG7[24792:140152610346752]: 21 server connects (SSL_accept()) 2012.04.03 23:33:20 LOG7[24792:140152610346752]: 20 server connects that finished 2012.04.03 23:33:20 LOG7[24792:140152610346752]: 0 server renegotiations requested 2012.04.03 23:33:20 LOG7[24792:140152610346752]: 9 session cache hits 2012.04.03 23:33:20 LOG7[24792:140152610346752]: 0 external session cache hits 2012.04.03 23:33:20 LOG7[24792:140152610346752]: 7 session cache misses 2012.04.03 23:33:20 LOG7[24792:140152610346752]: 4 session cache timeouts 2012.04.03 23:33:20 LOG6[24792:140152610346752]: SSL accepted: new session negotiated 2012.04.03 23:33:20 LOG6[24792:140152610346752]: Negotiated ciphers: DHE-RSA-CAMELLIA256-SHA SSLv3 Kx=DH Au=RSA Enc=Camellia(256) Mac=SHA1 2012.04.03 23:33:20 LOG7[24792:140152610346752]: remote socket: FD=1 allocated (non-blocking mode) 2012.04.03 23:33:20 LOG6[24792:140152610346752]: connect_blocking: connecting 127.0.0.1:82 2012.04.03 23:33:20 LOG7[24792:140152610346752]: connect_blocking: s_poll_wait 127.0.0.1:82: waiting 10 seconds 2012.04.03 23:33:20 LOG5[24792:140152610346752]: connect_blocking: connected 127.0.0.1:82 2012.04.03 23:33:20 LOG5[24792:140152610346752]: Service extranet.serviceplus-hse.com connected remote server from 127.0.0.1:36240 2012.04.03 23:33:20 LOG7[24792:140152610346752]: Remote FD=1 initialized 2012.04.03 23:33:20 LOG7[24792:140152610346752]: Option TCP_NODELAY set on remote socket 2012.04.03 23:33:27 LOG7[24792:140152610346752]: Socket closed on read 2012.04.03 23:33:27 LOG7[24792:140152610346752]: Sending SSL write shutdown 2012.04.03 23:33:27 LOG7[24792:140152610346752]: SSL alert (write): warning: close notify 2012.04.03 23:33:27 LOG6[24792:140152610346752]: SSL_shutdown successfully sent close_notify 2012.04.03 23:33:27 LOG3[24792:140152610346752]: transfer: s_poll_wait: TIMEOUTclose exceeded: closing 2012.04.03 23:33:27 LOG5[24792:140152610346752]: Connection closed: 537 bytes sent to SSL, 620 bytes sent to socket 2012.04.03 23:33:27 LOG7[24792:140152610346752]: Service extranet.serviceplus-hse.com finished (0 left) 2012.04.03 23:33:27 LOG7[24792:140152610629408]: local socket: FD=0 allocated (non-blocking mode) 2012.04.03 23:33:27 LOG7[24792:140152610629408]: Service extranet.serviceplus-hse.com accepted FD=0 from 82.224.128.241:52123 2012.04.03 23:33:27 LOG7[24792:140152610346752]: Service extranet.serviceplus-hse.com started 2012.04.03 23:33:27 LOG7[24792:140152610346752]: Option TCP_NODELAY set on local socket 2012.04.03 23:33:27 LOG7[24792:140152610346752]: Waiting for a libwrap process 2012.04.03 23:33:27 LOG7[24792:140152610346752]: Acquired libwrap process #0 2012.04.03 23:33:27 LOG7[24792:140152610346752]: Releasing libwrap process #0 2012.04.03 23:33:27 LOG7[24792:140152610346752]: Released libwrap process #0 2012.04.03 23:33:27 LOG7[24792:140152610346752]: Service extranet.serviceplus-hse.com permitted by libwrap from 82.224.128.241:52123 2012.04.03 23:33:27 LOG5[24792:140152610346752]: Service extranet.serviceplus-hse.com accepted connection from 82.224.128.241:52123 2012.04.03 23:33:27 LOG7[24792:140152610346752]: SSL state (accept): before/accept initialization 2012.04.03 23:33:27 LOG7[24792:140152610346752]: SSL state (accept): SSLv3 read client hello B 2012.04.03 23:33:27 LOG7[24792:140152610346752]: SSL state (accept): SSLv3 write server hello A 2012.04.03 23:33:27 LOG7[24792:140152610346752]: SSL state (accept): SSLv3 write change cipher spec A 2012.04.03 23:33:27 LOG7[24792:140152610346752]: SSL state (accept): SSLv3 write finished A 2012.04.03 23:33:27 LOG7[24792:140152610346752]: SSL state (accept): SSLv3 flush data 2012.04.03 23:33:28 LOG7[24792:140152610346752]: SSL state (accept): SSLv3 read finished A 2012.04.03 23:33:28 LOG7[24792:140152610346752]: 7 items in the session cache 2012.04.03 23:33:28 LOG7[24792:140152610346752]: 0 client connects (SSL_connect()) 2012.04.03 23:33:28 LOG7[24792:140152610346752]: 0 client connects that finished 2012.04.03 23:33:28 LOG7[24792:140152610346752]: 0 client renegotiations requested 2012.04.03 23:33:28 LOG7[24792:140152610346752]: 22 server connects (SSL_accept()) 2012.04.03 23:33:28 LOG7[24792:140152610346752]: 21 server connects that finished 2012.04.03 23:33:28 LOG7[24792:140152610346752]: 0 server renegotiations requested 2012.04.03 23:33:28 LOG7[24792:140152610346752]: 10 session cache hits 2012.04.03 23:33:28 LOG7[24792:140152610346752]: 0 external session cache hits 2012.04.03 23:33:28 LOG7[24792:140152610346752]: 7 session cache misses 2012.04.03 23:33:28 LOG7[24792:140152610346752]: 4 session cache timeouts 2012.04.03 23:33:28 LOG6[24792:140152610346752]: SSL accepted: previous session reused 2012.04.03 23:33:28 LOG7[24792:140152610346752]: remote socket: FD=1 allocated (non-blocking mode) 2012.04.03 23:33:28 LOG6[24792:140152610346752]: connect_blocking: connecting 127.0.0.1:82 2012.04.03 23:33:28 LOG7[24792:140152610346752]: connect_blocking: s_poll_wait 127.0.0.1:82: waiting 10 seconds 2012.04.03 23:33:28 LOG5[24792:140152610346752]: connect_blocking: connected 127.0.0.1:82 2012.04.03 23:33:28 LOG5[24792:140152610346752]: Service extranet.serviceplus-hse.com connected remote server from 127.0.0.1:36256 2012.04.03 23:33:28 LOG7[24792:140152610346752]: Remote FD=1 initialized 2012.04.03 23:33:28 LOG7[24792:140152610346752]: Option TCP_NODELAY set on remote socket 2012.04.03 23:33:41 LOG7[24792:140152610346752]: Socket closed on read 2012.04.03 23:33:41 LOG7[24792:140152610346752]: Sending SSL write shutdown 2012.04.03 23:33:41 LOG7[24792:140152610346752]: SSL alert (write): warning: close notify 2012.04.03 23:33:41 LOG6[24792:140152610346752]: SSL_shutdown successfully sent close_notify 2012.04.03 23:33:41 LOG3[24792:140152610346752]: transfer: s_poll_wait: TIMEOUTclose exceeded: closing 2012.04.03 23:33:41 LOG5[24792:140152610346752]: Connection closed: 186584 bytes sent to SSL, 3275 bytes sent to socket 2012.04.03 23:33:41 LOG7[24792:140152610346752]: Service extranet.serviceplus-hse.com finished (0 left) 2012.04.04 06:25:04 LOG7[24792:140152610629408]: Dispatching signals from the signal pipe ######################################################################
On Wed, Apr 4, 2012 at 6:16 AM, Thomas Manson dev.mansonthomas@gmail.comwrote:
Hi All,
I'm really struggling to make stunnel working for more than a few hours. (and the client is yelling hard...) (I solved some other issue : logging per website and making more than one stunnel works)
Hi Thomas,
I was just troubleshooting what looks like a very similar issue. I believe this is fixed in a later version of stunnel, which you can get from stunnel.org and compile yourself from source.
This is the ChangeLog entry that I think addresses your problem:
- Signal pipe set to non-blocking mode. This bug caused hangs of stunnel features based on signals, e.g. local mode, FORK threading, or configuration file reload on Unix. Win32 platform was not affected.
I have just updated from the official Oneiric version to this one, so I don't yet know if it will fix the problem long-term, but I think my odds are not too bad.
Hope this helps,
-----Scott.
Yes, it helps a lot !
I've another server running a different version of Ubuntu (11.04 where stunnel version is 4.29-1 instead of 11.10 and stunnel 4.35-2build1)
Do you think it can work on older version ?
I was thinking to try this because I've seen some message about the same symptoms after upgrade so...
but maybe the two version are too close and I will need to compile from sources...
what do you think about this?
Regards, Thomas.
On Sat, Apr 7, 2012 at 06:56, Scott Gifford sgifford@suspectclass.comwrote:
On Wed, Apr 4, 2012 at 6:16 AM, Thomas Manson dev.mansonthomas@gmail.comwrote:
Hi All,
I'm really struggling to make stunnel working for more than a few hours. (and the client is yelling hard...) (I solved some other issue : logging per website and making more than one stunnel works)
Hi Thomas,
I was just troubleshooting what looks like a very similar issue. I believe this is fixed in a later version of stunnel, which you can get from stunnel.org and compile yourself from source.
This is the ChangeLog entry that I think addresses your problem:
- Signal pipe set to non-blocking mode. This bug caused hangs of stunnel features based on signals, e.g. local mode, FORK threading, or configuration file reload on Unix. Win32 platform was not affected.
I have just updated from the official Oneiric version to this one, so I don't yet know if it will fix the problem long-term, but I think my odds are not too bad.
Hope this helps,
-----Scott.
i've just checked my setup right now and the funny thing is that I think it stopped working exactly at the same second of the same hour & minute of the day :
root@ns0:/var/log/stunnel4# ll total 940 drwxr-xr-x 2 stunnel4 stunnel4 4096 2012-04-07 06:25 . drwxr-xr-x 14 root root 4096 2012-04-07 06:25 .. -rw-r----- 1 stunnel4 stunnel4 0 2012-04-07 06:25 extranet.serviceplus-hse.com_stunnel.log -rw-r----- 1 stunnel4 stunnel4 926267 2012-04-07 06:25 extranet.serviceplus-hse.com_stunnel.log.1 -rw-r----- 1 stunnel4 stunnel4 0 2012-04-07 06:25 mansonthomas.com_stunnel.log -rw-r----- 1 stunnel4 stunnel4 5804 2012-04-07 06:25 mansonthomas.com_stunnel.log.1 -rw-r----- 1 stunnel4 stunnel4 0 2012-04-07 06:25 stunnel.log -rw-r----- 1 stunnel4 stunnel4 11710 2012-04-07 06:25 stunnel.log.1 root@ns0:/var/log/stunnel4# ll total 940 drwxr-xr-x 2 stunnel4 stunnel4 4096 2012-04-07 06:25 . drwxr-xr-x 14 root root 4096 2012-04-07 06:25 .. -rw-r----- 1 stunnel4 stunnel4 0 2012-04-07 06:25 extranet.serviceplus-hse.com_stunnel.log -rw-r----- 1 stunnel4 stunnel4 926267 2012-04-07 06:25 extranet.serviceplus-hse.com_stunnel.log.1 -rw-r----- 1 stunnel4 stunnel4 0 2012-04-07 06:25 mansonthomas.com_stunnel.log -rw-r----- 1 stunnel4 stunnel4 5804 2012-04-07 06:25 mansonthomas.com_stunnel.log.1 -rw-r----- 1 stunnel4 stunnel4 0 2012-04-07 06:25 stunnel.log -rw-r----- 1 stunnel4 stunnel4 11710 2012-04-07 06:25 stunnel.log.1 root@ns0:/var/log/stunnel4# tail stunnel.log.1 2012.04.06 22:21:19 LOG7[4745:139677248579328]: Option TCP_NODELAY set on remote socket 2012.04.06 22:21:19 LOG7[4745:139677248579328]: Socket closed on read 2012.04.06 22:21:19 LOG7[4745:139677248579328]: Sending SSL write shutdown 2012.04.06 22:21:19 LOG7[4745:139677248579328]: SSL alert (write): warning: close notify 2012.04.06 22:21:19 LOG6[4745:139677248579328]: SSL_shutdown successfully sent close_notify 2012.04.06 22:21:19 LOG7[4745:139677248579328]: SSL socket closed on SSL_read 2012.04.06 22:21:19 LOG7[4745:139677248579328]: Sending socket write shutdown 2012.04.06 22:21:19 LOG5[4745:139677248579328]: Connection closed: 206 bytes sent to SSL, 139 bytes sent to socket 2012.04.06 22:21:19 LOG7[4745:139677248579328]: Service https-123monsite.comfinished (0 left) 2012.04.07 06:25:04 LOG7[4745:139677248583456]: Dispatching signals from the signal pipe root@ns0:/var/log/stunnel4#
compared to my first post... :
- 2012.04.04 06:25:04 LOG7[24778:139641780213536]: Dispatching signals from the signal pipe - and at the same time (2012.04.04 06:25:04) all logs file stops :
- root@ns0:/var/log/stunnel4# ll - total 128 - drwxr-xr-x 2 stunnel4 stunnel4 4096 2012-04-04 12:10 . - drwxr-xr-x 14 root root 4096 2012-04-04 06:25 .. - -rw-r----- 1 stunnel4 stunnel4 98084 2012-04-04 *06:25* extranet.serviceplus-hse.com_stunnel.log - -rw-r----- 1 stunnel4 stunnel4 4491 2012-04-04 06:25 mansonthomas.com_stunnel.log - -rw-r----- 1 stunnel4 stunnel4 0 2012-04-04 06:25 stunnel.log - -rw-r----- 1 stunnel4 stunnel4 11058 2012-04-04 06:25 stunnel.log.1
I could cron a restart at the appropriate time but I think I'll compile from sources.
Regards, Thomas.
On Sat, Apr 7, 2012 at 07:51, Thomas Manson dev.mansonthomas@gmail.comwrote:
Yes, it helps a lot !
I've another server running a different version of Ubuntu (11.04 where stunnel version is 4.29-1 instead of 11.10 and stunnel 4.35-2build1)
Do you think it can work on older version ?
I was thinking to try this because I've seen some message about the same symptoms after upgrade so...
but maybe the two version are too close and I will need to compile from sources...
what do you think about this?
Regards, Thomas.
On Sat, Apr 7, 2012 at 06:56, Scott Gifford sgifford@suspectclass.comwrote:
On Wed, Apr 4, 2012 at 6:16 AM, Thomas Manson <dev.mansonthomas@gmail.com
wrote:
Hi All,
I'm really struggling to make stunnel working for more than a few hours. (and the client is yelling hard...) (I solved some other issue : logging per website and making more than one stunnel works)
Hi Thomas,
I was just troubleshooting what looks like a very similar issue. I believe this is fixed in a later version of stunnel, which you can get from stunnel.org and compile yourself from source.
This is the ChangeLog entry that I think addresses your problem:
- Signal pipe set to non-blocking mode. This bug caused hangs of
stunnel features based on signals, e.g. local mode, FORK threading, or configuration file reload on Unix. Win32 platform was not affected.
I have just updated from the official Oneiric version to this one, so I don't yet know if it will fix the problem long-term, but I think my odds are not too bad.
Hope this helps,
-----Scott.
This bug has been corrected in
Version 4.38, 2011.06.28, urgency: MEDIUM:
- New features - Server-side SNI implemented (RFC 3546 section 3.1) with a new service-level option "nsi". - "socket" option also accepts "yes" and "no" for flags. - Nagle's algorithm is now disabled by default for improved interactivity. - Bugfixes - A compilation fix was added for OpenSSL version < 1.0.0. - Signal pipe set to non-blocking mode. This bug caused hangs of stunnel features based on signals, e.g. local mode, FORK threading, or configuration file reload on Unix. Win32 platform was not affected.
however it don't precise from which version it affects stunnel... so my try with 11.04 is a bit risky, even if 4.29 is quite far from 4.38.
Maybe upgrading to 12.04 could solve the issue, but I don't like to upgrade right away (I had some bad surpise ;))
so compiling from source seems to be the safest option.
Thomas.
On Sat, Apr 7, 2012 at 07:58, Thomas Manson dev.mansonthomas@gmail.comwrote:
i've just checked my setup right now and the funny thing is that I think it stopped working exactly at the same second of the same hour & minute of the day :
root@ns0:/var/log/stunnel4# ll total 940 drwxr-xr-x 2 stunnel4 stunnel4 4096 2012-04-07 06:25 . drwxr-xr-x 14 root root 4096 2012-04-07 06:25 .. -rw-r----- 1 stunnel4 stunnel4 0 2012-04-07 06:25 extranet.serviceplus-hse.com_stunnel.log -rw-r----- 1 stunnel4 stunnel4 926267 2012-04-07 06:25 extranet.serviceplus-hse.com_stunnel.log.1 -rw-r----- 1 stunnel4 stunnel4 0 2012-04-07 06:25 mansonthomas.com_stunnel.log -rw-r----- 1 stunnel4 stunnel4 5804 2012-04-07 06:25 mansonthomas.com_stunnel.log.1 -rw-r----- 1 stunnel4 stunnel4 0 2012-04-07 06:25 stunnel.log -rw-r----- 1 stunnel4 stunnel4 11710 2012-04-07 06:25 stunnel.log.1 root@ns0:/var/log/stunnel4# ll total 940 drwxr-xr-x 2 stunnel4 stunnel4 4096 2012-04-07 06:25 . drwxr-xr-x 14 root root 4096 2012-04-07 06:25 .. -rw-r----- 1 stunnel4 stunnel4 0 2012-04-07 06:25 extranet.serviceplus-hse.com_stunnel.log -rw-r----- 1 stunnel4 stunnel4 926267 2012-04-07 06:25 extranet.serviceplus-hse.com_stunnel.log.1 -rw-r----- 1 stunnel4 stunnel4 0 2012-04-07 06:25 mansonthomas.com_stunnel.log -rw-r----- 1 stunnel4 stunnel4 5804 2012-04-07 06:25 mansonthomas.com_stunnel.log.1 -rw-r----- 1 stunnel4 stunnel4 0 2012-04-07 06:25 stunnel.log -rw-r----- 1 stunnel4 stunnel4 11710 2012-04-07 06:25 stunnel.log.1 root@ns0:/var/log/stunnel4# tail stunnel.log.1 2012.04.06 22:21:19 LOG7[4745:139677248579328]: Option TCP_NODELAY set on remote socket 2012.04.06 22:21:19 LOG7[4745:139677248579328]: Socket closed on read 2012.04.06 22:21:19 LOG7[4745:139677248579328]: Sending SSL write shutdown 2012.04.06 22:21:19 LOG7[4745:139677248579328]: SSL alert (write): warning: close notify 2012.04.06 22:21:19 LOG6[4745:139677248579328]: SSL_shutdown successfully sent close_notify 2012.04.06 22:21:19 LOG7[4745:139677248579328]: SSL socket closed on SSL_read 2012.04.06 22:21:19 LOG7[4745:139677248579328]: Sending socket write shutdown 2012.04.06 22:21:19 LOG5[4745:139677248579328]: Connection closed: 206 bytes sent to SSL, 139 bytes sent to socket 2012.04.06 22:21:19 LOG7[4745:139677248579328]: Service https-123monsite.com finished (0 left) 2012.04.07 06:25:04 LOG7[4745:139677248583456]: Dispatching signals from the signal pipe root@ns0:/var/log/stunnel4#
compared to my first post... :
- 2012.04.04 06:25:04 LOG7[24778:139641780213536]: Dispatching signals
from the signal pipe
and at the same time (2012.04.04 06:25:04) all logs file stops :
- root@ns0:/var/log/stunnel4# ll
- total 128
- drwxr-xr-x 2 stunnel4 stunnel4 4096 2012-04-04 12:10 .
- drwxr-xr-x 14 root root 4096 2012-04-04 06:25 ..
- -rw-r----- 1 stunnel4 stunnel4 98084 2012-04-04 *06:25*
extranet.serviceplus-hse.com_stunnel.log
- -rw-r----- 1 stunnel4 stunnel4 4491 2012-04-04 06:25
mansonthomas.com_stunnel.log
- -rw-r----- 1 stunnel4 stunnel4 0 2012-04-04 06:25 stunnel.log
- -rw-r----- 1 stunnel4 stunnel4 11058 2012-04-04 06:25 stunnel.log.1
I could cron a restart at the appropriate time but I think I'll compile from sources.
Regards, Thomas.
On Sat, Apr 7, 2012 at 07:51, Thomas Manson dev.mansonthomas@gmail.comwrote:
Yes, it helps a lot !
I've another server running a different version of Ubuntu (11.04 where stunnel version is 4.29-1 instead of 11.10 and stunnel 4.35-2build1)
Do you think it can work on older version ?
I was thinking to try this because I've seen some message about the same symptoms after upgrade so...
but maybe the two version are too close and I will need to compile from sources...
what do you think about this?
Regards, Thomas.
On Sat, Apr 7, 2012 at 06:56, Scott Gifford sgifford@suspectclass.comwrote:
On Wed, Apr 4, 2012 at 6:16 AM, Thomas Manson < dev.mansonthomas@gmail.com> wrote:
Hi All,
I'm really struggling to make stunnel working for more than a few hours. (and the client is yelling hard...) (I solved some other issue : logging per website and making more than one stunnel works)
Hi Thomas,
I was just troubleshooting what looks like a very similar issue. I believe this is fixed in a later version of stunnel, which you can get from stunnel.org and compile yourself from source.
This is the ChangeLog entry that I think addresses your problem:
- Signal pipe set to non-blocking mode. This bug caused hangs of
stunnel features based on signals, e.g. local mode, FORK threading, or configuration file reload on Unix. Win32 platform was not affected.
I have just updated from the official Oneiric version to this one, so I don't yet know if it will fix the problem long-term, but I think my odds are not too bad.
Hope this helps,
-----Scott.
On Sat, Apr 7, 2012 at 1:58 AM, Thomas Manson dev.mansonthomas@gmail.comwrote:
i've just checked my setup right now and the funny thing is that I think it stopped working exactly at the same second of the same hour & minute of the day :
Maybe the bug is triggered by a cronjob, such as logrotate.
-----Scott.
Yep, maybe.
I've compiled the 4.53 and it's running for about 36hours, so I guess the issue is fix.
Thanks Scott for putting me on the good path !
Thomas.
On Mon, Apr 9, 2012 at 16:24, Scott Gifford sgifford@suspectclass.comwrote:
On Sat, Apr 7, 2012 at 1:58 AM, Thomas Manson dev.mansonthomas@gmail.comwrote:
i've just checked my setup right now and the funny thing is that I think it stopped working exactly at the same second of the same hour & minute of the day :
Maybe the bug is triggered by a cronjob, such as logrotate.
-----Scott.
-
Scott Gifford -
Thomas Manson