Spamc ssl fixes

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

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
 

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;

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<IO::Socket::SSL> 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<timeout>, B<--timeout>=I<timeout>
 
 Set the timeout for spamc-to-spamd communications (default: 600, 0 disables).

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)