We’ve been using stunnel as part of a vendor supplied product for some time to connect a large application running in an application server on Windows to Active Directory for authentication via LDAPS (for some reason, it only natively supports LDAP!).
Anyway, it’s been working fine until a couple of weeks ago when we started getting intermittent failures against all of our configured Domain Controllers (the upstream LDAPS servers).
With no change in STunnel or DC config, some connections would abort with the following log:
SSL_connect: 1408F10B: error:1408F10B:SSL routines:SSL3_GET_RECORD:wrong version number
… while others worked fine.
The error is not limited to any one of the upstream DCs nor does it occur for every request.
We’ve updated STunnel to the latest version (5.31) and the problem remains running on Windows 2008 R2 SP1.
Below are two transactions from the same instance of STunnel connecting to the same DC one which works and one which doesn’t (IP addresses obfuscated).
2016.03.04 15:20:25 LOG7[14]: Service [ldaps] started
2016.03.04 15:20:25 LOG5[14]: Service [ldaps] accepted connection from 127.0.0.1:63130
2016.03.04 15:20:25 LOG6[14]: failover: round-robin, starting at entry #2
2016.03.04 15:20:25 LOG6[14]: s_connect: connecting 10.10.1.254:636
2016.03.04 15:20:25 LOG7[14]: s_connect: s_poll_wait 10.10.1.254:636: waiting 10 seconds
2016.03.04 15:20:25 LOG5[14]: s_connect: connected 10.10.1.254:636
2016.03.04 15:20:25 LOG5[14]: Service [ldaps] connected remote server from 10.10.1.225:63131
2016.03.04 15:20:25 LOG7[14]: Remote socket (FD=448) initialized
2016.03.04 15:20:25 LOG6[14]: SNI: sending servername:
ad.kent.ac.uk2016.03.04 15:20:25 LOG7[14]: SSL state (connect): before/connect initialization
2016.03.04 15:20:25 LOG7[14]: SSL state (connect): SSLv3 write client hello A
2016.03.04 15:20:25 LOG7[14]: SSL alert (write): fatal: protocol version
2016.03.04 15:20:25 LOG3[14]: SSL_connect: 1408F10B: error:1408F10B:SSL routines:SSL3_GET_RECORD:wrong version number
2016.03.04 15:20:25 LOG5[14]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2016.03.04 15:20:25 LOG7[14]: Remote socket (FD=448) closed
2016.03.04 15:20:25 LOG7[14]: Local socket (FD=492) closed
2016.03.04 15:20:25 LOG7[14]: Service [ldaps] finished (0 left)
Works
======
2016.03.02 18:18:01 LOG7[204]: Service [ldaps] started
2016.03.02 18:18:01 LOG5[204]: Service [ldaps] accepted connection from 127.0.0.1:52873
2016.03.02 18:18:01 LOG6[204]: failover: round-robin, starting at entry #0
2016.03.02 18:18:01 LOG6[204]: s_connect: connecting 10.10.1.254:636
2016.03.02 18:18:01 LOG7[204]: s_connect: s_poll_wait 10.10.1.254:636: waiting 10 seconds
2016.03.02 18:18:01 LOG5[204]: s_connect: connected 10.10.1.254:636
2016.03.02 18:18:01 LOG5[204]: Service [ldaps] connected remote server from 10.10.1.223:52874
2016.03.02 18:18:01 LOG7[204]: Remote socket (FD=492) initialized
2016.03.02 18:18:01 LOG6[204]: SNI: sending servername:
ad.kent.ac.uk2016.03.02 18:18:01 LOG7[204]: SSL state (connect): before/connect initialization
2016.03.02 18:18:01 LOG7[204]: SSL state (connect): SSLv3 write client hello A
2016.03.02 18:18:01 LOG7[204]: SSL state (connect): SSLv3 read server hello A
2016.03.02 18:18:01 LOG6[204]: Certificate verification disabled
2016.03.02 18:18:01 LOG6[204]: Certificate verification disabled
2016.03.02 18:18:01 LOG7[204]: SSL state (connect): SSLv3 read server certificate A
2016.03.02 18:18:01 LOG7[204]: SSL state (connect): SSLv3 read server key exchange A
2016.03.02 18:18:01 LOG7[204]: SSL state (connect): SSLv3 read server certificate request A
2016.03.02 18:18:01 LOG7[204]: SSL state (connect): SSLv3 read server done A
2016.03.02 18:18:01 LOG7[204]: SSL state (connect): SSLv3 write client certificate A
2016.03.02 18:18:01 LOG7[204]: SSL state (connect): SSLv3 write client key exchange A
2016.03.02 18:18:01 LOG7[204]: SSL state (connect): SSLv3 write change cipher spec A
2016.03.02 18:18:01 LOG7[204]: SSL state (connect): SSLv3 write finished A
2016.03.02 18:18:01 LOG7[204]: SSL state (connect): SSLv3 flush data
2016.03.02 18:18:01 LOG7[204]: SSL state (connect): SSLv3 read finished A
2016.03.02 18:18:01 LOG7[204]: 205 client connect(s) requested
2016.03.02 18:18:01 LOG7[204]: 205 client connect(s) succeeded
2016.03.02 18:18:01 LOG7[204]: 0 client renegotiation(s) requested
2016.03.02 18:18:01 LOG7[204]: 0 session reuse(s)
2016.03.02 18:18:01 LOG6[204]: SSL connected: new session negotiated
2016.03.02 18:18:01 LOG7[204]: Deallocating application specific data for addr index
2016.03.02 18:18:01 LOG6[204]: Negotiated TLSv1 ciphersuite ECDHE-RSA-AES256-SHA (256-bit encryption)
2016.03.02 18:18:01 LOG7[204]: Compression: null, expansion: null
2016.03.02 18:18:01 LOG6[204]: Read socket closed (readsocket)
2016.03.02 18:18:01 LOG7[204]: Sending close_notify alert
2016.03.02 18:18:01 LOG7[204]: SSL alert (write): warning: close notify
2016.03.02 18:18:01 LOG6[204]: SSL_shutdown successfully sent close_notify alert
2016.03.02 18:18:01 LOG3[204]: SSL_read: Connection reset by peer (WSAECONNRESET) (10054)
2016.03.02 18:18:01 LOG5[204]: Connection reset: 276 byte(s) sent to SSL, 44 byte(s) sent to socket
2016.03.02 18:18:01 LOG7[204]: Remote socket (FD=492) closed
2016.03.02 18:18:01 LOG7[204]: Local socket (FD=456) closed
2016.03.02 18:18:01 LOG7[204]: Service [ldaps] finished (0 left)