Hi,
I want to connect to SMTP server by STARTTLS, from MUA who does not support STARTTLS. However, I cannot connect to the server with recent stunnel.
On Windows XP, my stunnel.conf is the following: client=yes debug=notice output=C:\logs\stunnel.log service=stunnel [smtp_server] accept=127.0.0.1:10025 connect=smtp.example.com:587 protocol=smtp
stunnel version 4.27 or 4.29 is started as service, by "C:\Network\stunnel\stunnel.exe" -service -install c:\home\turutani\INI\stunnel.conf
I cannot connect with OpenSSL distributed via stunnel. Then I changed the OpenSSL DLL, and found that I can connect with OpenSSL older than 0.9.8i, while that newer than 0.9.8j fails. But it works by adding "sslVersion=all" or "sslVersion=SSLv2" to configuration file.
I also ran stunnel on FreeBSD, and found the same result about SSL version.
Here is a debug level log, with no "sslVersion=" or "sslVersion=SSLv3": 2010.01.08 09:50:06 LOG7[2372:3760]: RAND_status claims sufficient entropy for the PRNG 2010.01.08 09:50:06 LOG7[2372:3760]: PRNG seeded successfully 2010.01.08 09:50:06 LOG7[2372:3760]: SSL context initialized for service smtp_server 2010.01.08 09:50:06 LOG5[2372:3760]: stunnel 4.28 on x86-pc-mingw32-gnu with OpenSSL 0.9.8l 5 Nov 2009 2010.01.08 09:50:06 LOG5[2372:3760]: Threading:WIN32 SSL:ENGINE Sockets:SELECT,IPv6 2010.01.08 09:50:06 LOG5[2372:2252]: No limit detected for the number of clients 2010.01.08 09:50:06 LOG7[2372:2252]: FD 236 in non-blocking mode 2010.01.08 09:50:06 LOG7[2372:2252]: SO_REUSEADDR option set on accept socket 2010.01.08 09:50:06 LOG7[2372:2252]: smtp_server bound to 127.0.0.1:10025 2010.01.08 09:50:34 LOG7[2372:2252]: smtp_server accepted FD=244 from 127.0.0.1:1953 2010.01.08 09:50:34 LOG7[2372:2252]: Creating a new thread 2010.01.08 09:50:34 LOG7[2372:2252]: New thread created 2010.01.08 09:50:34 LOG7[2372:1036]: smtp_server started 2010.01.08 09:50:34 LOG7[2372:1036]: FD 244 in non-blocking mode 2010.01.08 09:50:34 LOG5[2372:1036]: smtp_server accepted connection from 127.0.0.1:1953 2010.01.08 09:50:34 LOG7[2372:1036]: FD 268 in non-blocking mode 2010.01.08 09:50:34 LOG6[2372:1036]: connect_blocking: connecting 133.x.y.z:587 2010.01.08 09:50:34 LOG7[2372:1036]: connect_blocking: s_poll_wait 133.x.y.z:587: waiting 10 seconds 2010.01.08 09:50:34 LOG5[2372:1036]: connect_blocking: connected 133.x.y.z:587 2010.01.08 09:50:34 LOG5[2372:1036]: smtp_server connected remote server from 192.168.3.118:1954 2010.01.08 09:50:34 LOG7[2372:1036]: Remote FD=268 initialized 2010.01.08 09:50:34 LOG5[2372:1036]: Negotiations for smtp (client side) started 2010.01.08 09:50:37 LOG7[2372:1036]: <- 220 smtp.example.com ESMTP Postfix 2010.01.08 09:50:37 LOG7[2372:1036]: -> 220 smtp.example.com ESMTP Postfix 2010.01.08 09:50:37 LOG7[2372:1036]: -> EHLO localhost 2010.01.08 09:50:37 LOG7[2372:1036]: <- 250-smtp.example.com 2010.01.08 09:50:37 LOG7[2372:1036]: <- 250-PIPELINING 2010.01.08 09:50:37 LOG7[2372:1036]: <- 250-SIZE 51200000 2010.01.08 09:50:37 LOG7[2372:1036]: <- 250-VRFY 2010.01.08 09:50:37 LOG7[2372:1036]: <- 250-ETRN 2010.01.08 09:50:37 LOG7[2372:1036]: <- 250-STARTTLS 2010.01.08 09:50:37 LOG7[2372:1036]: <- 250 8BITMIME 2010.01.08 09:50:37 LOG7[2372:1036]: -> STARTTLS 2010.01.08 09:50:37 LOG7[2372:1036]: <- 220 Ready to start TLS 2010.01.08 09:50:37 LOG5[2372:1036]: Protocol negotiations succeeded 2010.01.08 09:50:37 LOG7[2372:1036]: SSL state (connect): before/connect initialization 2010.01.08 09:50:37 LOG7[2372:1036]: SSL state (connect): SSLv3 write client hello A 2010.01.08 09:50:40 LOG3[2372:1036]: SSL_connect: Peer suddenly disconnected 2010.01.08 09:50:40 LOG5[2372:1036]: Connection reset: 0 bytes sent to SSL, 0 bytes sent to socket 2010.01.08 09:50:40 LOG7[2372:1036]: smtp_server finished (0 left)
with "sslVersion=all", 2010.01.08 09:45:33 LOG7[2664:3880]: RAND_status claims sufficient entropy for the PRNG 2010.01.08 09:45:33 LOG7[2664:3880]: PRNG seeded successfully 2010.01.08 09:45:34 LOG7[2664:3880]: SSL context initialized for service smtp_server 2010.01.08 09:45:34 LOG5[2664:3880]: stunnel 4.28 on x86-pc-mingw32-gnu with OpenSSL 0.9.8l 5 Nov 2009 2010.01.08 09:45:34 LOG5[2664:3880]: Threading:WIN32 SSL:ENGINE Sockets:SELECT,IPv6 2010.01.08 09:45:34 LOG5[2664:2408]: No limit detected for the number of clients 2010.01.08 09:45:34 LOG7[2664:2408]: FD 236 in non-blocking mode 2010.01.08 09:45:34 LOG7[2664:2408]: SO_REUSEADDR option set on accept socket 2010.01.08 09:45:34 LOG7[2664:2408]: smtp_server bound to 127.0.0.1:10025 2010.01.08 09:46:05 LOG7[2664:2408]: smtp_server accepted FD=244 from 127.0.0.1:1944 2010.01.08 09:46:05 LOG7[2664:2408]: Creating a new thread 2010.01.08 09:46:05 LOG7[2664:2408]: New thread created 2010.01.08 09:46:05 LOG7[2664:2968]: smtp_server started 2010.01.08 09:46:05 LOG7[2664:2968]: FD 244 in non-blocking mode 2010.01.08 09:46:05 LOG5[2664:2968]: smtp_server accepted connection from 127.0.0.1:1944 2010.01.08 09:46:05 LOG7[2664:2968]: FD 268 in non-blocking mode 2010.01.08 09:46:05 LOG6[2664:2968]: connect_blocking: connecting 133.x.y.z:587 2010.01.08 09:46:05 LOG7[2664:2968]: connect_blocking: s_poll_wait 133.x.y.z:587: waiting 10 seconds 2010.01.08 09:46:05 LOG5[2664:2968]: connect_blocking: connected 133.x.y.z:587 2010.01.08 09:46:05 LOG5[2664:2968]: smtp_server connected remote server from 192.168.3.118:1945 2010.01.08 09:46:05 LOG7[2664:2968]: Remote FD=268 initialized 2010.01.08 09:46:05 LOG5[2664:2968]: Negotiations for smtp (client side) started 2010.01.08 09:46:05 LOG7[2664:2968]: <- 220 smtp.example.com ESMTP Postfix 2010.01.08 09:46:05 LOG7[2664:2968]: -> 220 smtp.example.com ESMTP Postfix 2010.01.08 09:46:05 LOG7[2664:2968]: -> EHLO localhost 2010.01.08 09:46:05 LOG7[2664:2968]: <- 250-smtp.example.com 2010.01.08 09:46:05 LOG7[2664:2968]: <- 250-PIPELINING 2010.01.08 09:46:05 LOG7[2664:2968]: <- 250-SIZE 51200000 2010.01.08 09:46:05 LOG7[2664:2968]: <- 250-VRFY 2010.01.08 09:46:05 LOG7[2664:2968]: <- 250-ETRN 2010.01.08 09:46:05 LOG7[2664:2968]: <- 250-STARTTLS 2010.01.08 09:46:05 LOG7[2664:2968]: <- 250 8BITMIME 2010.01.08 09:46:05 LOG7[2664:2968]: -> STARTTLS 2010.01.08 09:46:05 LOG7[2664:2968]: <- 220 Ready to start TLS 2010.01.08 09:46:05 LOG5[2664:2968]: Protocol negotiations succeeded 2010.01.08 09:46:05 LOG7[2664:2968]: SSL state (connect): before/connect initialization 2010.01.08 09:46:05 LOG7[2664:2968]: SSL state (connect): SSLv2/v3 write client hello A 2010.01.08 09:46:05 LOG7[2664:2968]: SSL state (connect): SSLv3 read server hello A 2010.01.08 09:46:05 LOG7[2664:2968]: SSL state (connect): SSLv3 read server certificate A 2010.01.08 09:46:05 LOG7[2664:2968]: SSL state (connect): SSLv3 read server key exchange A 2010.01.08 09:46:05 LOG7[2664:2968]: SSL state (connect): SSLv3 read server done A 2010.01.08 09:46:05 LOG7[2664:2968]: SSL state (connect): SSLv3 write client key exchange A 2010.01.08 09:46:05 LOG7[2664:2968]: SSL state (connect): SSLv3 write change cipher spec A 2010.01.08 09:46:05 LOG7[2664:2968]: SSL state (connect): SSLv3 write finished A 2010.01.08 09:46:05 LOG7[2664:2968]: SSL state (connect): SSLv3 flush data 2010.01.08 09:46:05 LOG7[2664:2968]: SSL state (connect): SSLv3 read finished A 2010.01.08 09:46:05 LOG7[2664:2968]: 1 items in the session cache 2010.01.08 09:46:05 LOG7[2664:2968]: 1 client connects (SSL_connect()) 2010.01.08 09:46:05 LOG7[2664:2968]: 1 client connects that finished 2010.01.08 09:46:05 LOG7[2664:2968]: 0 client renegotiations requested 2010.01.08 09:46:05 LOG7[2664:2968]: 0 server connects (SSL_accept()) 2010.01.08 09:46:05 LOG7[2664:2968]: 0 server connects that finished 2010.01.08 09:46:05 LOG7[2664:2968]: 0 server renegotiations requested 2010.01.08 09:46:05 LOG7[2664:2968]: 0 session cache hits 2010.01.08 09:46:05 LOG7[2664:2968]: 0 external session cache hits 2010.01.08 09:46:05 LOG7[2664:2968]: 0 session cache misses 2010.01.08 09:46:05 LOG7[2664:2968]: 0 session cache timeouts 2010.01.08 09:46:05 LOG6[2664:2968]: SSL connected: new session negotiated 2010.01.08 09:46:05 LOG6[2664:2968]: Negotiated ciphers: DHE-RSA-AES256-SHA SSLv3 Kx=DH Au=RSA Enc=AES(256) Mac=SHA1 2010.01.08 09:46:05 LOG7[2664:2968]: SSL socket closed on SSL_read 2010.01.08 09:46:05 LOG7[2664:2968]: Socket write shutdown 2010.01.08 09:46:05 LOG5[2664:2968]: Connection closed: 625 bytes sent to SSL, 286 bytes sent to socket 2010.01.08 09:46:05 LOG7[2664:2968]: smtp_server finished (0 left) 2010.01.08 09:50:06 LOG7[2372:3760]: RAND_status claims sufficient entropy for the PRNG
with "sslVersion=SSLv2", 2010.01.08 09:50:50 LOG7[2692:3460]: RAND_status claims sufficient entropy for the PRNG 2010.01.08 09:50:50 LOG7[2692:3460]: PRNG seeded successfully 2010.01.08 09:50:50 LOG7[2692:3460]: SSL context initialized for service smtp_server 2010.01.08 09:50:50 LOG5[2692:3460]: stunnel 4.28 on x86-pc-mingw32-gnu with OpenSSL 0.9.8l 5 Nov 2009 2010.01.08 09:50:50 LOG5[2692:3460]: Threading:WIN32 SSL:ENGINE Sockets:SELECT,IPv6 2010.01.08 09:50:50 LOG5[2692:2496]: No limit detected for the number of clients 2010.01.08 09:50:50 LOG7[2692:2496]: FD 236 in non-blocking mode 2010.01.08 09:50:50 LOG7[2692:2496]: SO_REUSEADDR option set on accept socket 2010.01.08 09:50:50 LOG7[2692:2496]: smtp_server bound to 127.0.0.1:10025 2010.01.08 09:51:04 LOG7[2692:2496]: smtp_server accepted FD=244 from 127.0.0.1:1955 2010.01.08 09:51:04 LOG7[2692:2496]: Creating a new thread 2010.01.08 09:51:04 LOG7[2692:2496]: New thread created 2010.01.08 09:51:04 LOG7[2692:2056]: smtp_server started 2010.01.08 09:51:04 LOG7[2692:2056]: FD 244 in non-blocking mode 2010.01.08 09:51:04 LOG5[2692:2056]: smtp_server accepted connection from 127.0.0.1:1955 2010.01.08 09:51:04 LOG7[2692:2056]: FD 268 in non-blocking mode 2010.01.08 09:51:04 LOG6[2692:2056]: connect_blocking: connecting 133.x.y.z:587 2010.01.08 09:51:04 LOG7[2692:2056]: connect_blocking: s_poll_wait 133.x.y.z:587: waiting 10 seconds 2010.01.08 09:51:04 LOG5[2692:2056]: connect_blocking: connected 133.x.y.z:587 2010.01.08 09:51:04 LOG5[2692:2056]: smtp_server connected remote server from 192.168.3.118:1956 2010.01.08 09:51:04 LOG7[2692:2056]: Remote FD=268 initialized 2010.01.08 09:51:04 LOG5[2692:2056]: Negotiations for smtp (client side) started 2010.01.08 09:51:04 LOG7[2692:2056]: <- 220 smtp.example.com ESMTP Postfix 2010.01.08 09:51:04 LOG7[2692:2056]: -> 220 smtp.example.com ESMTP Postfix 2010.01.08 09:51:04 LOG7[2692:2056]: -> EHLO localhost 2010.01.08 09:51:04 LOG7[2692:2056]: <- 250-smtp.example.com 2010.01.08 09:51:04 LOG7[2692:2056]: <- 250-PIPELINING 2010.01.08 09:51:04 LOG7[2692:2056]: <- 250-SIZE 51200000 2010.01.08 09:51:04 LOG7[2692:2056]: <- 250-VRFY 2010.01.08 09:51:04 LOG7[2692:2056]: <- 250-ETRN 2010.01.08 09:51:04 LOG7[2692:2056]: <- 250-STARTTLS 2010.01.08 09:51:04 LOG7[2692:2056]: <- 250 8BITMIME 2010.01.08 09:51:04 LOG7[2692:2056]: -> STARTTLS 2010.01.08 09:51:04 LOG7[2692:2056]: <- 220 Ready to start TLS 2010.01.08 09:51:04 LOG5[2692:2056]: Protocol negotiations succeeded 2010.01.08 09:51:04 LOG7[2692:2056]: SSL state (connect): before/connect initialization 2010.01.08 09:51:04 LOG7[2692:2056]: SSL state (connect): SSLv2 write client hello A 2010.01.08 09:51:04 LOG7[2692:2056]: SSL state (connect): SSLv2 read server hello A 2010.01.08 09:51:04 LOG7[2692:2056]: SSL state (connect): SSLv2 write client master key A 2010.01.08 09:51:04 LOG7[2692:2056]: SSL state (connect): SSLv2 client start encryption 2010.01.08 09:51:04 LOG7[2692:2056]: SSL state (connect): SSLv2 write client finished A 2010.01.08 09:51:04 LOG7[2692:2056]: SSL state (connect): SSLv2 read server verify A 2010.01.08 09:51:04 LOG7[2692:2056]: SSL state (connect): SSLv2 read server finished A 2010.01.08 09:51:04 LOG7[2692:2056]: 1 items in the session cache 2010.01.08 09:51:04 LOG7[2692:2056]: 1 client connects (SSL_connect()) 2010.01.08 09:51:04 LOG7[2692:2056]: 1 client connects that finished 2010.01.08 09:51:04 LOG7[2692:2056]: 0 client renegotiations requested 2010.01.08 09:51:04 LOG7[2692:2056]: 0 server connects (SSL_accept()) 2010.01.08 09:51:04 LOG7[2692:2056]: 0 server connects that finished 2010.01.08 09:51:04 LOG7[2692:2056]: 0 server renegotiations requested 2010.01.08 09:51:04 LOG7[2692:2056]: 0 session cache hits 2010.01.08 09:51:04 LOG7[2692:2056]: 0 external session cache hits 2010.01.08 09:51:04 LOG7[2692:2056]: 0 session cache misses 2010.01.08 09:51:04 LOG7[2692:2056]: 0 session cache timeouts 2010.01.08 09:51:04 LOG6[2692:2056]: SSL connected: new session negotiated 2010.01.08 09:51:04 LOG6[2692:2056]: Negotiated ciphers: DES-CBC3-MD5 SSLv2 Kx=RSA Au=RSA Enc=3DES(168) Mac=MD5 2010.01.08 09:51:04 LOG7[2692:2056]: SSL closed on SSL_read 2010.01.08 09:51:04 LOG7[2692:2056]: Socket write shutdown 2010.01.08 09:51:04 LOG7[2692:2056]: Socket closed on read 2010.01.08 09:51:04 LOG7[2692:2056]: SSL write shutdown 2010.01.08 09:51:04 LOG5[2692:2056]: Connection closed: 626 bytes sent to SSL, 286 bytes sent to socket 2010.01.08 09:51:04 LOG7[2692:2056]: smtp_server finished (0 left)
However, with OpenSSL older than 0.9.8i it can connect without "sslVersion=all" or with "sslVersion=SSLv3", and log tells SSLv3 was used.
Why stunnel cannot connect with OpenSSL newer than 0.9.8j ?
--- Tsurutani Naoki turutani@scphys.kyoto-u.ac.jp