[stunnel-users] problem migrating from 4.54 to 5.x

Hi there. I have a program I have used successfully with Stunnel for many years.

A while back, I discovered that my program, which is a pure stdio console program, stopped working with 5.x versions of Stunnel. I have spent many hours but have been unable to solve the problem, so I regretfully continue to use the 4.x branch. I was wondering if anyone had similar experiences? Relevant data is pasted below. I comment in the log output where the problem occurs.

Any help at all would be greatly appreciated.

stunnel.conf: setuid = stunnel setgid = stunnel pid = /var/run/stunnel/stunnel.pid socket = l:TCP_NODELAY=1 socket = r:TCP_NODELAY=1 foreground = no debug = 7 output = /var/log/stunnel.log

[CF2] client = no accept = 21 verify = 3 sslVersion = all cert = /etc/stunnel/demo.pem key = /etc/stunnel/demo.pem CApath = /etc/stunnel/certs CRLpath = /etc/stunnel/crls TIMEOUTbusy = 60 TIMEOUTclose = 0 TIMEOUTconnect = 60 TIMEOUTidle = 60

exec = /opt/cmf/bin/cf-server execargs = /opt/cmf/bin/cf-server -p /opt/jail/stunnel/pipes/

Log of successful session with 4.54: 2015.05.01 15:39:39 LOG7[3080:140402563495680]: Starting certificate verification: depth=0, /C=US/L=Bryan/ST=TX/O=Demo Account/emailAddress= demo@demo.com/CN=demo 2015.05.01 15:39:39 LOG6[3080:140402563495680]: CERT: Locally installed certificate matched 2015.05.01 15:39:39 LOG5[3080:140402563495680]: Certificate accepted: depth=0, /C=US/L=Bryan/ST=TX/O=Demo Account/emailAddress= demo@demo.com/CN=demo 2015.05.01 15:39:39 LOG7[3080:140402563495680]: SSL state (accept): SSLv3 read client certificate A 2015.05.01 15:39:39 LOG7[3080:140402563495680]: SSL state (accept): SSLv3 read client key exchange A 2015.05.01 15:39:39 LOG7[3080:140402563495680]: SSL state (accept): SSLv3 read certificate verify A 2015.05.01 15:39:39 LOG7[3080:140402563495680]: SSL state (accept): SSLv3 read finished A 2015.05.01 15:39:39 LOG7[3080:140402563495680]: SSL state (accept): SSLv3 write session ticket A 2015.05.01 15:39:39 LOG7[3080:140402563495680]: SSL state (accept): SSLv3 write change cipher spec A 2015.05.01 15:39:39 LOG7[3080:140402563495680]: SSL state (accept): SSLv3 write finished A 2015.05.01 15:39:39 LOG7[3080:140402563495680]: SSL state (accept): SSLv3 flush data 2015.05.01 15:39:39 LOG7[3080:140402563495680]: 0 items in the session cache 2015.05.01 15:39:39 LOG7[3080:140402563495680]: 0 client connects (SSL_connect()) 2015.05.01 15:39:39 LOG7[3080:140402563495680]: 0 client connects that finished 2015.05.01 15:39:39 LOG7[3080:140402563495680]: 0 client renegotiations requested 2015.05.01 15:39:39 LOG7[3080:140402563495680]: 1 server connects (SSL_accept()) 2015.05.01 15:39:39 LOG7[3080:140402563495680]: 1 server connects that finished 2015.05.01 15:39:39 LOG7[3080:140402563495680]: 0 server renegotiations requested 2015.05.01 15:39:39 LOG7[3080:140402563495680]: 0 session cache hits 2015.05.01 15:39:39 LOG7[3080:140402563495680]: 0 external session cache hits 2015.05.01 15:39:39 LOG7[3080:140402563495680]: 0 session cache misses 2015.05.01 15:39:39 LOG7[3080:140402563495680]: 0 session cache timeouts 2015.05.01 15:39:39 LOG6[3080:140402563495680]: SSL accepted: new session negotiated 2015.05.01 15:39:39 LOG6[3080:140402563495680]: Negotiated TLSv1/SSLv3 ciphersuite: ECDHE-RSA-AES256-GCM-SHA384 (256-bit encryption) 2015.05.01 15:39:39 LOG6[3080:140402563495680]: Compression: null, expansion: null 2015.05.01 15:39:39 LOG6[3080:140402563495680]: Local mode child started (PID=3118) 2015.05.01 15:39:39 LOG7[3080:140402563495680]: Remote socket (FD=11) initialized *** the connection is established and stable; i explicitly disconnect several seconds later 2015.05.01 15:39:45 LOG7[3080:140402563495680]: SSL socket closed on SSL_read 2015.05.01 15:39:45 LOG7[3080:140402563495680]: Sent socket write shutdown 2015.05.01 15:39:45 LOG5[3080:140402563495680]: Connection closed: 0 byte(s) sent to SSL, 0 byte(s) sent to socket 2015.05.01 15:39:45 LOG7[3080:140402563495680]: Remote socket (FD=11) closed 2015.05.01 15:39:45 LOG7[3080:140402563495680]: Local socket (FD=3) closed 2015.05.01 15:39:45 LOG7[3080:140402563495680]: Service [CF2] finished (0 left)

Log of unsuccessful session with 5.16: 2015.05.01 15:37:33 LOG7[0]: Verification started at depth=0: C=US, L=Bryan, ST=TX, O=Demo Account, emailAddress=demo@demo.com, CN=demo 2015.05.01 15:37:33 LOG7[0]: CERT: Pre-verification succeeded 2015.05.01 15:37:33 LOG6[0]: CERT: Locally installed certificate matched 2015.05.01 15:37:33 LOG5[0]: Certificate accepted at depth=0: C=US, L=Bryan, ST=TX, O=Demo Account, emailAddress=demo@demo.com, CN=demo 2015.05.01 15:37:33 LOG7[0]: SSL state (accept): SSLv3 read client certificate A 2015.05.01 15:37:33 LOG7[0]: SSL state (accept): SSLv3 read client key exchange A 2015.05.01 15:37:33 LOG7[0]: SSL state (accept): SSLv3 read certificate verify A 2015.05.01 15:37:33 LOG7[0]: SSL state (accept): SSLv3 read finished A 2015.05.01 15:37:33 LOG7[0]: SSL state (accept): SSLv3 write change cipher spec A 2015.05.01 15:37:33 LOG7[0]: SSL state (accept): SSLv3 write finished A 2015.05.01 15:37:33 LOG7[0]: SSL state (accept): SSLv3 flush data 2015.05.01 15:37:33 LOG7[0]: 1 server accept(s) requested 2015.05.01 15:37:33 LOG7[0]: 1 server accept(s) succeeded 2015.05.01 15:37:33 LOG7[0]: 0 server renegotiation(s) requested 2015.05.01 15:37:33 LOG7[0]: 0 session reuse(s) 2015.05.01 15:37:33 LOG7[0]: 0 internal session cache item(s) 2015.05.01 15:37:33 LOG7[0]: 0 internal session cache fill-up(s) 2015.05.01 15:37:33 LOG7[0]: 0 internal session cache miss(es) 2015.05.01 15:37:33 LOG7[0]: 0 external session cache hit(s) 2015.05.01 15:37:33 LOG7[0]: 0 expired session(s) retrieved 2015.05.01 15:37:33 LOG6[0]: SSL accepted: new session negotiated 2015.05.01 15:37:33 LOG7[0]: Peer certificate was cached (1610 bytes) 2015.05.01 15:37:33 LOG6[0]: Negotiated TLSv1.2 ciphersuite ECDHE-RSA-AES256-GCM-SHA384 (256-bit encryption) 2015.05.01 15:37:33 LOG7[0]: Compression: null, expansion: null 2015.05.01 15:37:33 LOG6[0]: Local mode child started (PID=2899) 2015.05.01 15:37:33 LOG7[0]: Remote socket (FD=11) initialized *** immediately after successful connection, something happens; my program has no log output either, which seems to indicate that stunnel is closing it 2015.05.01 15:37:33 LOG6[0]: Read socket closed (readsocket) 2015.05.01 15:37:33 LOG7[main]: Dispatching signals from the signal pipe 2015.05.01 15:37:33 LOG7[0]: Sending close_notify alert 2015.05.01 15:37:33 LOG7[main]: Processing SIGCHLD 2015.05.01 15:37:33 LOG7[0]: SSL alert (write): warning: close notify 2015.05.01 15:37:33 LOG6[main]: Child process 2899 terminated on signal 11 2015.05.01 15:37:33 LOG6[0]: SSL_shutdown successfully sent close_notify alert 2015.05.01 15:37:33 LOG7[main]: Signal pipe is empty 2015.05.01 15:37:33 LOG3[0]: transfer: s_poll_wait: TIMEOUTclose exceeded: closing 2015.05.01 15:37:33 LOG5[0]: Connection closed: 0 byte(s) sent to SSL, 0 byte(s) sent to socket 2015.05.01 15:37:33 LOG7[0]: Remote socket (FD=11) closed 2015.05.01 15:37:33 LOG7[0]: Local socket (FD=3) closed 2015.05.01 15:37:33 LOG7[0]: Service [CF2] finished (0 left)