Re: [stunnel-users] Problem with Stunnel Working fine on the firstconnection and not on subsequent connections
I'd try to disable chroot and run stunnel under strace with "foreground =
yes" option.
Mike,
When running in foreground, with or without chroot, things work as expected. Without foreground, it did not work.
Two key differences on the logs for each:
Output of "Cleaning up the signal pipe" prior to checking the libwrap permissions a finish line of "ssmtp finished (0 left)" instead of "ssmtp finished (-1 left)"
(Yes, this is a dual processor box.)
It looks like the key problem lies in the regerenation of the standalone mode. Is there a way with v4 to just use inetd to answer on port 465, negotiate and connect on port 25 on another host because perhaps that will avoid the issue.
Regards, KAM
2005.11.19 13:07:51 LOG7[3893:1024]: Key file: /usr/local/ssl/certs/stunnel.pem 2005.11.19 13:07:51 LOG6[3893:1024]: file ulimit = 1024 (can be changed with 'ulimit -n') 2005.11.19 13:07:51 LOG6[3893:1024]: poll() used - no FD_SETSIZE limit for file descriptors 2005.11.19 13:07:51 LOG5[3893:1024]: 500 clients allowed 2005.11.19 13:07:51 LOG7[3893:1024]: FD 4 in non-blocking mode 2005.11.19 13:07:51 LOG7[3893:1024]: FD 5 in non-blocking mode 2005.11.19 13:07:51 LOG7[3893:1024]: FD 6 in non-blocking mode 2005.11.19 13:07:51 LOG7[3893:1024]: SO_REUSEADDR option set on accept socket 2005.11.19 13:07:51 LOG7[3893:1024]: ssmtp bound to 0.0.0.0:465 2005.11.19 13:07:51 LOG7[3893:1024]: Created pid file /stunnel.pid
[ed: 1st email] 2005.11.19 13:08:32 LOG7[3893:1024]: ssmtp accepted FD=7 from 66.149.103.32:3130 2005.11.19 13:08:32 LOG7[3898:1026]: ssmtp started 2005.11.19 13:08:32 LOG7[3898:1026]: FD 7 in non-blocking mode 2005.11.19 13:08:32 LOG7[3898:1026]: TCP_NODELAY option set on local socket 2005.11.19 13:08:32 LOG7[3898:1026]: FD 10 in non-blocking mode 2005.11.19 13:08:32 LOG7[3898:1026]: FD 11 in non-blocking mode 2005.11.19 13:08:32 LOG7[3893:1024]: Cleaning up the signal pipe 2005.11.19 13:08:32 LOG7[3898:1026]: Connection from 66.149.103.32:3130 permitted by libwrap 2005.11.19 13:08:32 LOG5[3898:1026]: ssmtp connected from 66.149.103.32:3130 2005.11.19 13:08:32 LOG7[3898:1026]: SSL state (accept): before/accept initialization 2005.11.19 13:08:32 LOG7[3898:1026]: SSL state (accept): SSLv3 read client hello A 2005.11.19 13:08:32 LOG7[3898:1026]: SSL state (accept): SSLv3 write server hello A 2005.11.19 13:08:32 LOG7[3898:1026]: SSL state (accept): SSLv3 write certificate A 2005.11.19 13:08:32 LOG7[3898:1026]: SSL state (accept): SSLv3 write server done A 2005.11.19 13:08:32 LOG7[3898:1026]: SSL state (accept): SSLv3 flush data 2005.11.19 13:08:32 LOG7[3898:1026]: SSL state (accept): SSLv3 read client key exchange A 2005.11.19 13:08:32 LOG7[3898:1026]: SSL state (accept): SSLv3 read finished A 2005.11.19 13:08:32 LOG7[3898:1026]: SSL state (accept): SSLv3 write change cipher spec A 2005.11.19 13:08:32 LOG7[3898:1026]: SSL state (accept): SSLv3 write finished A 2005.11.19 13:08:32 LOG7[3898:1026]: SSL state (accept): SSLv3 flush data 2005.11.19 13:08:32 LOG7[3898:1026]: 1 items in the session cache 2005.11.19 13:08:32 LOG7[3898:1026]: 0 client connects (SSL_connect()) 2005.11.19 13:08:32 LOG7[3898:1026]: 0 client connects that finished 2005.11.19 13:08:32 LOG7[3898:1026]: 0 client renegotiatations requested 2005.11.19 13:08:32 LOG7[3898:1026]: 1 server connects (SSL_accept()) 2005.11.19 13:08:32 LOG7[3898:1026]: 1 server connects that finished 2005.11.19 13:08:32 LOG7[3898:1026]: 0 server renegotiatiations requested 2005.11.19 13:08:32 LOG7[3898:1026]: 0 session cache hits 2005.11.19 13:08:32 LOG7[3898:1026]: 1 session cache misses 2005.11.19 13:08:32 LOG7[3898:1026]: 0 session cache timeouts 2005.11.19 13:08:32 LOG6[3898:1026]: SSL accepted: new session negotiated 2005.11.19 13:08:32 LOG6[3898:1026]: Negotiated ciphers: RC4-MD5 SSLv3 Kx=RSA Au=RSA Enc=RC4(128) Mac=MD5 2005.11.19 13:08:32 LOG7[3898:1026]: FD 10 in non-blocking mode 2005.11.19 13:08:32 LOG7[3898:1026]: ssmtp connecting 10.10.10.30:25 2005.11.19 13:08:32 LOG7[3898:1026]: connect_wait: waiting 10 seconds 2005.11.19 13:08:32 LOG7[3898:1026]: connect_wait: connected 2005.11.19 13:08:32 LOG7[3898:1026]: Remote FD=10 initialized 2005.11.19 13:08:32 LOG7[3898:1026]: TCP_NODELAY option set on remote socket 2005.11.19 13:08:33 LOG7[3898:1026]: Socket closed on read 2005.11.19 13:08:33 LOG7[3898:1026]: SSL write shutdown 2005.11.19 13:08:33 LOG7[3898:1026]: SSL alert (write): warning: close notify 2005.11.19 13:08:33 LOG7[3898:1026]: SSL_shutdown retrying 2005.11.19 13:08:33 LOG7[3898:1026]: SSL doesn't need to read or write 2005.11.19 13:08:33 LOG7[3898:1026]: SSL socket closed on SSL_read 2005.11.19 13:08:33 LOG7[3898:1026]: Socket write shutdown 2005.11.19 13:08:33 LOG5[3898:1026]: Connection closed: 834 bytes sent to SSL, 1358 bytes sent to socket 2005.11.19 13:08:33 LOG7[3898:1026]: ssmtp finished (0 left)
[ed: 2nd email] 2005.11.19 13:08:40 LOG7[3893:1024]: ssmtp accepted FD=7 from 66.149.103.32:3137 2005.11.19 13:08:40 LOG7[3900:2050]: ssmtp started 2005.11.19 13:08:40 LOG7[3900:2050]: FD 7 in non-blocking mode 2005.11.19 13:08:40 LOG7[3900:2050]: TCP_NODELAY option set on local socket 2005.11.19 13:08:40 LOG7[3900:2050]: FD 10 in non-blocking mode 2005.11.19 13:08:40 LOG7[3900:2050]: FD 11 in non-blocking mode 2005.11.19 13:08:40 LOG7[3893:1024]: Cleaning up the signal pipe 2005.11.19 13:08:40 LOG7[3900:2050]: Connection from 66.149.103.32:3137 permitted by libwrap 2005.11.19 13:08:40 LOG5[3900:2050]: ssmtp connected from 66.149.103.32:3137 2005.11.19 13:08:40 LOG7[3900:2050]: SSL state (accept): before/accept initialization 2005.11.19 13:08:40 LOG7[3900:2050]: SSL state (accept): SSLv3 read client hello A 2005.11.19 13:08:40 LOG7[3900:2050]: SSL state (accept): SSLv3 write server hello A 2005.11.19 13:08:40 LOG7[3900:2050]: SSL state (accept): SSLv3 write certificate A 2005.11.19 13:08:40 LOG7[3900:2050]: SSL state (accept): SSLv3 write server done A 2005.11.19 13:08:40 LOG7[3900:2050]: SSL state (accept): SSLv3 flush data 2005.11.19 13:08:40 LOG7[3900:2050]: SSL state (accept): SSLv3 read client key exchange A 2005.11.19 13:08:40 LOG7[3900:2050]: SSL state (accept): SSLv3 read finished A 2005.11.19 13:08:40 LOG7[3900:2050]: SSL state (accept): SSLv3 write change cipher spec A 2005.11.19 13:08:40 LOG7[3900:2050]: SSL state (accept): SSLv3 write finished A 2005.11.19 13:08:40 LOG7[3900:2050]: SSL state (accept): SSLv3 flush data 2005.11.19 13:08:40 LOG7[3900:2050]: 2 items in the session cache 2005.11.19 13:08:40 LOG7[3900:2050]: 0 client connects (SSL_connect()) 2005.11.19 13:08:40 LOG7[3900:2050]: 0 client connects that finished 2005.11.19 13:08:40 LOG7[3900:2050]: 0 client renegotiatations requested 2005.11.19 13:08:40 LOG7[3900:2050]: 2 server connects (SSL_accept()) 2005.11.19 13:08:40 LOG7[3900:2050]: 2 server connects that finished 2005.11.19 13:08:40 LOG7[3900:2050]: 0 server renegotiatiations requested 2005.11.19 13:08:40 LOG7[3900:2050]: 0 session cache hits 2005.11.19 13:08:40 LOG7[3900:2050]: 2 session cache misses 2005.11.19 13:08:40 LOG7[3900:2050]: 0 session cache timeouts 2005.11.19 13:08:40 LOG6[3900:2050]: SSL accepted: new session negotiated 2005.11.19 13:08:40 LOG6[3900:2050]: Negotiated ciphers: RC4-MD5 SSLv3 Kx=RSA Au=RSA Enc=RC4(128) Mac=MD5 2005.11.19 13:08:40 LOG7[3900:2050]: FD 10 in non-blocking mode 2005.11.19 13:08:40 LOG7[3900:2050]: ssmtp connecting 10.10.10.30:25 2005.11.19 13:08:40 LOG7[3900:2050]: connect_wait: waiting 10 seconds 2005.11.19 13:08:40 LOG7[3900:2050]: connect_wait: connected 2005.11.19 13:08:40 LOG7[3900:2050]: Remote FD=10 initialized 2005.11.19 13:08:40 LOG7[3900:2050]: TCP_NODELAY option set on remote socket 2005.11.19 13:08:42 LOG7[3900:2050]: Socket closed on read 2005.11.19 13:08:42 LOG7[3900:2050]: SSL write shutdown 2005.11.19 13:08:42 LOG7[3900:2050]: SSL alert (write): warning: close notify 2005.11.19 13:08:42 LOG7[3900:2050]: SSL_shutdown retrying 2005.11.19 13:08:42 LOG7[3900:2050]: SSL doesn't need to read or write 2005.11.19 13:08:42 LOG7[3900:2050]: SSL socket closed on SSL_read 2005.11.19 13:08:42 LOG7[3900:2050]: Socket write shutdown 2005.11.19 13:08:42 LOG5[3900:2050]: Connection closed: 834 bytes sent to SSL, 1358 bytes sent to socket 2005.11.19 13:08:42 LOG7[3900:2050]: ssmtp finished (0 left)
Without foreground, things do not continue past the first connection: 2005.11.19 13:10:32 LOG7[3910:1024]: ssmtp accepted FD=7 from 66.149.103.32:3268 2005.11.19 13:10:32 LOG7[3916:1026]: ssmtp started 2005.11.19 13:10:32 LOG7[3916:1026]: FD 7 in non-blocking mode 2005.11.19 13:10:32 LOG7[3916:1026]: TCP_NODELAY option set on local socket 2005.11.19 13:10:32 LOG7[3916:1026]: FD 10 in non-blocking mode 2005.11.19 13:10:32 LOG7[3916:1026]: FD 11 in non-blocking mode 2005.11.19 13:10:32 LOG7[3916:1026]: Connection from 66.149.103.32:3268 permitted by libwrap 2005.11.19 13:10:32 LOG5[3916:1026]: ssmtp connected from 66.149.103.32:3268 2005.11.19 13:10:32 LOG7[3916:1026]: SSL state (accept): before/accept initialization 2005.11.19 13:10:32 LOG7[3916:1026]: SSL state (accept): SSLv3 read client hello A 2005.11.19 13:10:32 LOG7[3916:1026]: SSL state (accept): SSLv3 write server hello A 2005.11.19 13:10:32 LOG7[3916:1026]: SSL state (accept): SSLv3 write certificate A 2005.11.19 13:10:32 LOG7[3916:1026]: SSL state (accept): SSLv3 write server done A 2005.11.19 13:10:32 LOG7[3916:1026]: SSL state (accept): SSLv3 flush data 2005.11.19 13:10:32 LOG7[3916:1026]: SSL state (accept): SSLv3 read client key exchange A 2005.11.19 13:10:32 LOG7[3916:1026]: SSL state (accept): SSLv3 read finished A 2005.11.19 13:10:32 LOG7[3916:1026]: SSL state (accept): SSLv3 write change cipher spec A 2005.11.19 13:10:32 LOG7[3916:1026]: SSL state (accept): SSLv3 write finished A 2005.11.19 13:10:32 LOG7[3916:1026]: SSL state (accept): SSLv3 flush data 2005.11.19 13:10:32 LOG7[3916:1026]: 1 items in the session cache 2005.11.19 13:10:32 LOG7[3916:1026]: 0 client connects (SSL_connect()) 2005.11.19 13:10:32 LOG7[3916:1026]: 0 client connects that finished 2005.11.19 13:10:32 LOG7[3916:1026]: 0 client renegotiatations requested 2005.11.19 13:10:32 LOG7[3916:1026]: 1 server connects (SSL_accept()) 2005.11.19 13:10:32 LOG7[3916:1026]: 1 server connects that finished 2005.11.19 13:10:32 LOG7[3916:1026]: 0 server renegotiatiations requested 2005.11.19 13:10:32 LOG7[3916:1026]: 0 session cache hits 2005.11.19 13:10:32 LOG7[3916:1026]: 1 session cache misses 2005.11.19 13:10:32 LOG7[3916:1026]: 0 session cache timeouts 2005.11.19 13:10:32 LOG6[3916:1026]: SSL accepted: new session negotiated 2005.11.19 13:10:32 LOG6[3916:1026]: Negotiated ciphers: RC4-MD5 SSLv3 Kx=RSA Au=RSA Enc=RC4(128) Mac=MD5 2005.11.19 13:10:32 LOG7[3916:1026]: FD 10 in non-blocking mode 2005.11.19 13:10:32 LOG7[3916:1026]: ssmtp connecting 10.10.10.30:25 2005.11.19 13:10:32 LOG7[3916:1026]: connect_wait: waiting 10 seconds 2005.11.19 13:10:32 LOG7[3916:1026]: connect_wait: connected 2005.11.19 13:10:32 LOG7[3916:1026]: Remote FD=10 initialized 2005.11.19 13:10:32 LOG7[3916:1026]: TCP_NODELAY option set on remote socket 2005.11.19 13:10:33 LOG7[3916:1026]: Socket closed on read 2005.11.19 13:10:33 LOG7[3916:1026]: SSL write shutdown 2005.11.19 13:10:33 LOG7[3916:1026]: SSL alert (write): warning: close notify 2005.11.19 13:10:33 LOG7[3916:1026]: SSL_shutdown retrying 2005.11.19 13:10:33 LOG7[3916:1026]: SSL doesn't need to read or write 2005.11.19 13:10:34 LOG7[3916:1026]: SSL socket closed on SSL_read 2005.11.19 13:10:34 LOG7[3916:1026]: Socket write shutdown 2005.11.19 13:10:34 LOG5[3916:1026]: Connection closed: 834 bytes sent to SSL, 1353 bytes sent to socket 2005.11.19 13:10:34 LOG7[3916:1026]: ssmtp finished (-1 left)
-
Kevin A. McGrail