OpenSSL: log conns rejected for bad ALPN, with the offered value

Unfortunately, no way to do this under GnuTLS

5 files changed, 25 insertions, 3 deletions

diff --git a/src/src/match.c b/src/src/match.c
index 91a49c0f0..07070362d 100644
--- a/src/src/match.c
+++ b/src/src/match.c
@@ -968,6 +968,7 @@ Arguments:
   s              string to search for
   listptr        ptr to ptr to colon separated list of patterns, or NULL
   sep            a separator value for the list (see string_nextinlist())
+		 or zero for auto
   anchorptr      ptr to tree for named items, or NULL if no named items
   cache_bits     ptr to cache_bits for ditto, or NULL if not caching
   type           MCL_DOMAIN when matching a domain list
diff --git a/src/src/tls-gnu.c b/src/src/tls-gnu.c
index 729fb5879..b47fabf1d 100644
--- a/src/src/tls-gnu.c
+++ b/src/src/tls-gnu.c
@@ -1119,21 +1119,28 @@ switch (tls_id)
     /* The format of "data" here doesn't seem to be documented, but appears
     to be a 2-byte field with a (redundant, given the "size" arg) total length
     then a sequence of one-byte size then string (not nul-term) names.  The
-    latter is as described in OpenSSL documentation. */
+    latter is as described in OpenSSL documentation.
+    Note that we do not get called for a match_fail, making it hard to log
+    a single bad ALPN being offered (the common case). */
+    {
+    gstring * g = NULL;
 
     DEBUG(D_tls) debug_printf("Seen ALPN extension from client (s=%u):", size);
     for (const uschar * s = data+2; s-data < size-1; s += *s + 1)
       {
       server_seen_alpn++;
+      g = string_append_listele_n(g, ':', s+1, *s);
       DEBUG(D_tls) debug_printf(" '%.*s'", (int)*s, s+1);
       }
     DEBUG(D_tls) debug_printf("\n");
     if (server_seen_alpn > 1)
       {
+      log_write(0, LOG_MAIN, "TLS ALPN (%s) rejected", string_from_gstring(g));
       DEBUG(D_tls) debug_printf("TLS: too many ALPNs presented in handshake\n");
       return GNUTLS_E_NO_APPLICATION_PROTOCOL;
       }
     break;
+    }
 #endif
   }
 return 0;
diff --git a/src/src/tls-openssl.c b/src/src/tls-openssl.c
index e063d29bd..513ba0d3a 100644
--- a/src/src/tls-openssl.c
+++ b/src/src/tls-openssl.c
@@ -2324,6 +2324,8 @@ static int
 tls_server_alpn_cb(SSL *ssl, const uschar ** out, uschar * outlen,
   const uschar * in, unsigned int inlen, void * arg)
 {
+gstring * g = NULL;
+
 server_seen_alpn = TRUE;
 DEBUG(D_tls)
   {
@@ -2354,12 +2356,19 @@ if (  inlen > 1		/* at least one name */
       }
   }
 
-/* More than one name from clilent, or name did not match our list. */
+/* More than one name from client, or name did not match our list. */
 
 /* This will be fatal to the TLS conn; would be nice to kill TCP also.
 Maybe as an option in future; for now leave control to the config (must-tls). */
 
-DEBUG(D_tls) debug_printf("TLS ALPN rejected\n");
+for (int pos = 0, siz; pos < inlen; pos += siz+1)
+  {
+  siz = in[pos];
+  if (pos + 1 + siz > inlen) siz = inlen - pos - 1;
+  g = string_append_listele_n(g, ':', in + pos + 1, siz);
+  }
+log_write(0, LOG_MAIN, "TLS ALPN (%s) rejected", string_from_gstring(g));
+gstring_release_unused(g);
 return SSL_TLSEXT_ERR_ALERT_FATAL;
 }
 #endif	/* EXIM_HAVE_ALPN */
diff --git a/test/log/1190 b/test/log/1190
index 53c56f59a..e01fb2685 100644
--- a/test/log/1190
+++ b/test/log/1190
@@ -23,7 +23,9 @@
 1999-03-02 09:44:33 10HmaY-0005vi-00 <= CALLER@myhost.test.ex H=the.local.host.name (myhost.test.ex) [ip4.ip4.ip4.ip4] P=esmtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no S=sss id=E10HmaX-0005vi-00@myhost.test.ex
 1999-03-02 09:44:33 10HmaY-0005vi-00 => :blackhole: <a@test.ex> R=server
 1999-03-02 09:44:33 10HmaY-0005vi-00 Completed
+1999-03-02 09:44:33 TLS ALPN (http) rejected
 1999-03-02 09:44:33 TLS error on connection from the.local.host.name (myhost.test.ex) [ip4.ip4.ip4.ip4] (SSL_accept): error: <<detail omitted>>
+1999-03-02 09:44:33 TLS ALPN (smtp:smtp) rejected
 1999-03-02 09:44:33 TLS error on connection from the.local.host.name (myhost.test.ex) [ip4.ip4.ip4.ip4] (SSL_accept): error: <<detail omitted>>
 1999-03-02 09:44:33 10HmbC-0005vi-00 <= CALLER@myhost.test.ex H=the.local.host.name (myhost.test.ex) [ip4.ip4.ip4.ip4] P=esmtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no S=sss id=E10HmbB-0005vi-00@myhost.test.ex
 1999-03-02 09:44:33 10HmbC-0005vi-00 => :blackhole: <d@test.ex> R=server
diff --git a/test/runtest b/test/runtest
index 900fc7bbb..86fc79acb 100755
--- a/test/runtest
+++ b/test/runtest
@@ -1562,6 +1562,9 @@ RESET_AFTER_EXTRA_LINE_READ:
     s/signer: [^ ]* bits:\K 256/ 253/;
     s/public key too short:\K 256 bits/ 253 bits/;
 
+    # with GnuTLS we cannot log single bad ALPN.  So ignore the with-OpenSSL log line.
+    # next if /TLS ALPN (http) rejected$/;
+
     # port numbers
     s/(?:\[[^\]]*\]:|port )\K$parm_port_d/PORT_D/;
     s/(?:\[[^\]]*\]:|port )\K$parm_port_d2/PORT_D2/;