diff --git a/spamc/libspamc.c b/spamc/libspamc.c index ed5f66a773..16e15a1365 100644 --- a/spamc/libspamc.c +++ b/spamc/libspamc.c @@ -714,11 +714,40 @@ static int _try_ssl_connect(SSL_CTX *ctx, struct transport *tp, if (ssl_rtn != 1) { int ssl_err = SSL_get_error(ssl, ssl_rtn); libspamc_log(flags, LOG_ERR, - "SSL_connect error: %s", _ssl_err_as_string()); + "SSL_connect error: %d %s", ssl_err, _ssl_err_as_string()); return EX_UNAVAILABLE; } + if (flags & SPAMC_DEBUG_SSL) { + libspamc_log(flags, LOG_DEBUG, + "SSL connected: version=%s cipher=%s state=%s", + SSL_get_version(ssl), SSL_get_cipher(ssl), + SSL_state_string_long(ssl)); + } return EX_OK; } + +static int _ssl_write_with_retry(SSL *ssl, const void *buf, int len, + int flags) +{ + int rc; + int ssl_err; + do { + rc = SSL_write(ssl, buf, len); + if (rc > 0) { + if (flags & SPAMC_DEBUG_SSL) { + libspamc_log(flags, LOG_DEBUG, "SSL_write: wrote %d bytes", rc); + } + return rc; + } + ssl_err = SSL_get_error(ssl, rc); + if (flags & SPAMC_DEBUG_SSL) { + libspamc_log(flags, LOG_DEBUG, + "SSL_write: rc=%d ssl_err=%d state=%s", + rc, ssl_err, SSL_state_string_long(ssl)); + } + } while (ssl_err == SSL_ERROR_WANT_READ || ssl_err == SSL_ERROR_WANT_WRITE); + return rc; +} #endif /* Aug 14, 2002 bj: Reworked things. Now we have message_read, message_write, @@ -1009,6 +1038,15 @@ _spamc_read_full_line(struct message *m, int flags, SSL * ssl, int sock, for (len = 0; len < bufsiz - 1; len++) { if (flags & SPAMC_USE_SSL) { bytesread = ssl_timeout_read(ssl, buf + len, 1); + if (bytesread <= 0 && (flags & SPAMC_DEBUG_SSL)) { +#ifdef SPAMC_SSL + libspamc_log(flags, LOG_DEBUG, + "ssl_timeout_read: returned %d, ssl_err=%d, " + "errno=%d, state=%s", + bytesread, SSL_get_error(ssl, bytesread), + errno, SSL_state_string_long(ssl)); +#endif + } } else { bytesread = fd_timeout_read(sock, 0, buf + len, 1); @@ -1497,20 +1535,32 @@ int message_filter(struct transport *tp, const char *username, /* Send to spamd */ if (flags & SPAMC_USE_SSL) { #ifdef SPAMC_SSL - rc = SSL_write(ssl, buf, len); - if (rc <= 0) { - libspamc_log(flags, LOG_ERR, "SSL write failed (%d)", - SSL_get_error(ssl, rc)); - failureval = EX_IOERR; - goto failure; + if (flags & SPAMC_DEBUG_SSL) { + libspamc_log(flags, LOG_DEBUG, + "SSL_write: sending header (%d bytes), state=%s", + len, SSL_state_string_long(ssl)); } - rc = SSL_write(ssl, towrite_buf, towrite_len); + rc = _ssl_write_with_retry(ssl, buf, len, flags); if (rc <= 0) { - libspamc_log(flags, LOG_ERR, "SSL write failed (%d)", - SSL_get_error(ssl, rc)); + libspamc_log(flags, LOG_ERR, "SSL write failed: error=%d state=%s", + SSL_get_error(ssl, rc), SSL_state_string_long(ssl)); failureval = EX_IOERR; goto failure; } + if (towrite_len > 0) { + if (flags & SPAMC_DEBUG_SSL) { + libspamc_log(flags, LOG_DEBUG, + "SSL_write: sending body (%d bytes), state=%s", + towrite_len, SSL_state_string_long(ssl)); + } + rc = _ssl_write_with_retry(ssl, towrite_buf, towrite_len, flags); + if (rc <= 0) { + libspamc_log(flags, LOG_ERR, "SSL write failed: error=%d state=%s", + SSL_get_error(ssl, rc), SSL_state_string_long(ssl)); + failureval = EX_IOERR; + goto failure; + } + } SSL_shutdown(ssl); shutdown(sock, SHUT_WR); #endif diff --git a/spamc/libspamc.h b/spamc/libspamc.h index 269e57464d..c4c50d5277 100644 --- a/spamc/libspamc.h +++ b/spamc/libspamc.h @@ -142,6 +142,9 @@ /* April 2022, add SSL client certificate support, bug 7267 */ #define SPAMC_CLIENT_SSL_CERT (1<<12) +/* TLS 1.3 post-handshake SSL debug tracing */ +#define SPAMC_DEBUG_SSL (1<<11) + #define SPAMC_MESSAGE_CLASS_SPAM 1 #define SPAMC_MESSAGE_CLASS_HAM 2 diff --git a/spamc/spamc.c b/spamc/spamc.c index 6f14e2512c..0d8f1c9994 100644 --- a/spamc/spamc.c +++ b/spamc/spamc.c @@ -150,6 +150,8 @@ print_usage(void) usg(" --ssl-key key Specify an SSL client key PEM file.\n"); usg(" --ssl-ca-file file Specify the location of the CA PEM file.\n"); usg(" --ssl-ca-path path Specify a directory containin CA files.\n"); + usg(" -D, --ssl-debug Trace SSL state (version, cipher, error codes)\n" + " to stderr. Useful for diagnosing TLS 1.3 hangs.\n"); #endif #ifndef _WIN32 usg(" -U, --socket path Connect to spamd via UNIX domain sockets.\n"); @@ -239,9 +241,9 @@ read_args(int argc, char **argv, struct transport *ptrn) { #ifndef _WIN32 - const char *opts = "-BcrR46d:e:fyp:n:t:s:u:L:C:xXzSHU:ElhVKF:0:1:2"; + const char *opts = "-BcrR46d:e:fyp:n:t:s:u:L:C:xXzSHU:ElhVKDF:0:1:2"; #else - const char *opts = "-BcrR46d:fyp:n:t:s:u:L:C:xXzSHElhVKF:0:1:2"; + const char *opts = "-BcrR46d:fyp:n:t:s:u:L:C:xXzSHElhVKDF:0:1:2"; #endif int opt; int ret = EX_OK; @@ -282,6 +284,9 @@ read_args(int argc, char **argv, { "help", no_argument, 0, 'h' }, { "version", no_argument, 0, 'V' }, { "compress", no_argument, 0, 'z' }, +#ifdef SPAMC_SSL + { "ssl-debug", no_argument, 0, 'D' }, +#endif { 0, 0, 0, 0} /* last element _must_ be all zeroes */ }; @@ -344,6 +349,13 @@ read_args(int argc, char **argv, flags |= SPAMC_PING; break; } +#ifdef SPAMC_SSL + case 'D': + { + flags |= SPAMC_DEBUG_SSL; + break; + } +#endif case 'l': { flags |= SPAMC_LOG_TO_STDERR; diff --git a/spamc/spamc.pod b/spamc/spamc.pod index 8a3a3f445b..db52694e8e 100644 --- a/spamc/spamc.pod +++ b/spamc/spamc.pod @@ -216,6 +216,15 @@ directories to verify the server certificate. The server certificate must be signed by one of these Certificate Authorities. See the man page for B for additional details. +=item B<-D>, B<--ssl-debug> + +If spamc was built with SSL support, log SSL state information to stderr +at each stage of the connection: the negotiated protocol version and cipher +after the handshake, the byte counts and SSL state string for each write, +and the SSL error code and state on any read failure. Useful for diagnosing +TLS connection problems, particularly with TLS 1.3. Requires B<-l> to +direct log output to stderr. + =item B<-t> I, B<--timeout>=I Set the timeout for spamc-to-spamd communications (default: 600, 0 disables). diff --git a/spamc/utils.c b/spamc/utils.c index 0e130fbc6a..7cb34f0789 100644 --- a/spamc/utils.c +++ b/spamc/utils.c @@ -155,15 +155,21 @@ int ssl_timeout_read(SSL * ssl, void *buf, int nbytes) do { #ifdef SPAMC_SSL + int ssl_err = 0; nred = SSL_read(ssl, buf, nbytes); + if (nred < 0) ssl_err = SSL_get_error(ssl, nred); + if (nred < 0 && (errno == EWOULDBLOCK || ssl_err == SSL_ERROR_WANT_READ)) + continue; + break; #else UNUSED_VARIABLE(ssl); UNUSED_VARIABLE(buf); UNUSED_VARIABLE(nbytes); nred = 0; /* never used */ + break; #endif - } while (nred < 0 && errno == EWOULDBLOCK); + } while (1); #ifndef _WIN32 if (nred < 0 && errno == EINTR)