Hi,
While configuring stunnel to connect as a client to a TLS server that requires client certificate auth (known as mutual TLS auth), I noticed that each new connection generates lots (up to hundreds) of duplicate logs like:
2025.06.18 10:23:58 LOG6[0]: Received trusted client CA: CN=Example CA
2025.06.18 10:23:58 LOG6[0]: Received trusted client CA: CN=Example CA
I expect one log per trusted client CA provided by the server. Openssl s_client -msg shows that the server only sends a small CertificateRequest. Stunnel logs show that only one connection is made.
This only happens if the server offers exactly one trusted client CA. If multiple client CA options are offered by the server then a single log entry is recorded for each.
What appears to be happening is that OpenSSL’s state machine generates lots of info callbacks (the number depends on latency). This appears to be harmless except for the excessive logging.
I’m running stunnel 5.75 against OpenSSL 3.5.0 (compiled with enable-weak-ssl-ciphers, enable-ssl3 and enable-ssl3-method):
$ stunnel
[ ] Initializing inetd mode configuration
[ ] Clients allowed=125
[.] stunnel 5.75 on sparc-sun-solaris2.10 platform
[.] Compiled/running with OpenSSL 3.5.0 8 Apr 2025
[.] Threading:PTHREAD Sockets:POLL,IPv6 TLS:ENGINE,OCSP,PSK,SNI
[ ] errno: (*(___errno()))
…
$ openssl version
OpenSSL 3.5.0 8 Apr 2025 (Library: OpenSSL 3.5.0 8 Apr 2025)
This is probably NOT caused by an OpenSSL 3.5.0 behaviour change, I also see duplicate messages from the public stunnel build running on Windows:
[ ] Initializing inetd mode configuration
[ ] Running on Windows 6.2
[ ] No limit detected for the number of clients
[.] stunnel 5.74 on x64-pc-mingw32-gnu platform
[.] Compiled/running with OpenSSL 3.3.2 3 Sep 2024
[.] Threading:WIN32 Sockets:SELECT,IPv6 TLS:ENGINE,FIPS,OCSP,PSK,SNI
[ ] errno: (*_errno())
To diagnose this further, I modified stunnel src/ctx.c info_callback() to log the TLS state in callbacks:
//#if 0
// s_log(LOG_DEBUG, "state = %x", state);
state_string=SSL_state_string_long(ssl);
s_log(LOG_DEBUG, "TLS state (where %08X state %08X): %s", where, state, state_string);
//#endif
This shows that there are many callbacks from where SSL_CB_ACCEPT_EXIT and one final callback from SSL_CB_ACCEPT_LOOP:
2025.06.18 10:23:58 LOG6[0]: Received trusted client CA: CN=Example CA
2025.06.18 10:23:58 LOG7[0]: TLS state (where 00001002 state 00000008): SSLv3/TLS read server certificate request
2025.06.18 10:23:58 LOG6[0]: Received trusted client CA: CN=Example CA
2025.06.18 10:23:58 LOG7[0]: TLS state (where 00001002 state 00000008): SSLv3/TLS read server certificate request
2025.06.18 10:23:58 LOG6[0]: Received trusted client CA: CN=Example CA
2025.06.18 10:23:58 LOG7[0]: TLS state (where 00001002 state 00000008): SSLv3/TLS read server certificate request
2025.06.18 10:23:58 LOG6[0]: Received trusted client CA: CN=Example CA
2025.06.18 10:23:58 LOG7[0]: TLS state (where 00001001 state 00000008): SSLv3/TLS read server certificate request
2025.06.18 10:23:58 LOG6[0]: Received trusted client CA: CN=Example CA
2025.06.18 10:23:58 LOG7[0]: TLS state (connect): SSLv3/TLS read server certificate request
Modifying info_callback to look for SSL_CB_LOOP in where suppresses the excess messages:
/* log the client certificate request (if received) */
#ifndef SSL3_ST_CR_CERT_REQ_A
if(state==TLS_ST_CR_CERT_REQ && where & SSL_CB_LOOP)
#else
if(state==SSL3_ST_CR_CERT_REQ_A && where & SSL_CB_LOOP)
#endif
print_CA_list("Received trusted client CA",
SSL_get_client_CA_list(ssl));
Here’s my config:
debug=info
[outbound-http-to-https-mtls]
accept = 127.0.0.1:8447
connect = 127.0.0.1:8445
client = yes
; verify 2 - verify peer certificate chain
verify = 2
sni = www.example.com
checkHost = www.example.com
verifyChain = yes
CAfile = /export/home/user/stunnel/trusted-ca-certs.pem
; Authenticate ourselves to peer using a client certificate.
cert = /export/home/user/stunnel/user.ecdsa-p256.pem
key = /export/home/user/stunnel/user.ecdsa-p256.key