Log details for client certificate failures

Currently, debugging client certificate verification failures is
mostly limited to looking at the TLS alert code on the client side.
For simple deployments, sometimes it's enough to see "sslv3 alert
certificate revoked" and know exactly what needs to be fixed, but if
you add any more complexity (multiple CA layers, misconfigured CA
certificates, etc.), trying to debug what happened based on the TLS
alert alone can be an exercise in frustration.

Luckily, the server has more information about exactly what failed in
the chain, and we already have the requisite callback implemented as a
stub.  We fill that in, collect the data, and pass the constructed
error message back to the main code via a static variable.  This lets
us add our error details directly to the final "could not accept SSL
connection" log message, as opposed to issuing intermediate LOGs.

It ends up looking like

    LOG:  connection received: host=localhost port=43112
    LOG:  could not accept SSL connection: certificate verify failed
    DETAIL:  Client certificate verification failed at depth 1: unable to get local issuer certificate.
            Failed certificate data (unverified): subject "/CN=Test CA for PostgreSQL SSL regression test client certs", serial number 2315134995201656577, issuer "/CN=Test root CA for PostgreSQL SSL regression test suite".

The length of the Subject and Issuer strings is limited to prevent
malicious client certs from spamming the logs.  In case the truncation
makes things ambiguous, the certificate's serial number is also
logged.

Author: Jacob Champion <pchampion@vmware.com>
Discussion: https://www.postgresql.org/message-id/flat/d13c4a5787c2a3f83705124f0391e0738c796751.camel@vmware.com

1 files changed, 109 insertions, 3 deletions

diff --git a/src/backend/libpq/be-secure-openssl.c b/src/backend/libpq/be-secure-openssl.c
index 3d0168a3696..9cec6866a39 100644
--- a/src/backend/libpq/be-secure-openssl.c
+++ b/src/backend/libpq/be-secure-openssl.c
@@ -81,6 +81,9 @@ static bool ssl_is_server_start;
 static int	ssl_protocol_version_to_openssl(int v);
 static const char *ssl_protocol_version_to_string(int v);
 
+/* for passing data back from verify_cb() */
+static const char *cert_errdetail;
+
 /* ------------------------------------------------------------ */
 /*						 Public interface						*/
 /* ------------------------------------------------------------ */
@@ -541,6 +544,7 @@ aloop:
 						(errcode(ERRCODE_PROTOCOL_VIOLATION),
 						 errmsg("could not accept SSL connection: %s",
 								SSLerrmessage(ecode)),
+						 cert_errdetail ? errdetail_internal("%s", cert_errdetail) : 0,
 						 give_proto_hint ?
 						 errhint("This may indicate that the client does not support any SSL protocol version between %s and %s.",
 								 ssl_min_protocol_version ?
@@ -549,6 +553,7 @@ aloop:
 								 ssl_max_protocol_version ?
 								 ssl_protocol_version_to_string(ssl_max_protocol_version) :
 								 MAX_OPENSSL_TLS_VERSION) : 0));
+				cert_errdetail = NULL;
 				break;
 			case SSL_ERROR_ZERO_RETURN:
 				ereport(COMMERROR,
@@ -1077,11 +1082,45 @@ dummy_ssl_passwd_cb(char *buf, int size, int rwflag, void *userdata)
 }
 
 /*
+ * Examines the provided certificate name, and if it's too long to log, modifies
+ * and truncates it. The return value is NULL if no truncation was needed; it
+ * otherwise points into the middle of the input string, and should not be
+ * freed.
+ */
+static char *
+truncate_cert_name(char *name)
+{
+	size_t		namelen = strlen(name);
+	char	   *truncated;
+
+	/*
+	 * Common Names are 64 chars max, so for a common case where the CN is the
+	 * last field, we can still print the longest possible CN with a
+	 * 7-character prefix (".../CN=[64 chars]"), for a reasonable limit of 71
+	 * characters.
+	 */
+#define MAXLEN 71
+
+	if (namelen <= MAXLEN)
+		return NULL;
+
+	/*
+	 * Keep the end of the name, not the beginning, since the most specific
+	 * field is likely to give users the most information.
+	 */
+	truncated = name + namelen - MAXLEN;
+	truncated[0] = truncated[1] = truncated[2] = '.';
+
+#undef MAXLEN
+
+	return truncated;
+}
+
+/*
  *	Certificate verification callback
  *
- *	This callback allows us to log intermediate problems during
- *	verification, but for now we'll see if the final error message
- *	contains enough information.
+ *	This callback allows us to examine intermediate problems during
+ *	verification, for later logging.
  *
  *	This callback also allows us to override the default acceptance
  *	criteria (e.g., accepting self-signed or expired certs), but
@@ -1090,6 +1129,73 @@ dummy_ssl_passwd_cb(char *buf, int size, int rwflag, void *userdata)
 static int
 verify_cb(int ok, X509_STORE_CTX *ctx)
 {
+	int			depth;
+	int			errcode;
+	const char *errstring;
+	StringInfoData str;
+	X509	   *cert;
+
+	if (ok)
+	{
+		/* Nothing to do for the successful case. */
+		return ok;
+	}
+
+	/* Pull all the information we have on the verification failure. */
+	depth = X509_STORE_CTX_get_error_depth(ctx);
+	errcode = X509_STORE_CTX_get_error(ctx);
+	errstring = X509_verify_cert_error_string(errcode);
+
+	initStringInfo(&str);
+	appendStringInfo(&str,
+					 _("Client certificate verification failed at depth %d: %s."),
+					 depth, errstring);
+
+	cert = X509_STORE_CTX_get_current_cert(ctx);
+	if (cert)
+	{
+		char	   *subject,
+				   *issuer;
+		char	   *sub_truncated,
+				   *iss_truncated;
+		char	   *serialno;
+		ASN1_INTEGER *sn;
+		BIGNUM	   *b;
+
+		/*
+		 * Get the Subject and Issuer for logging, but don't let maliciously
+		 * huge certs flood the logs.
+		 */
+		subject = X509_NAME_to_cstring(X509_get_subject_name(cert));
+		sub_truncated = truncate_cert_name(subject);
+
+		issuer = X509_NAME_to_cstring(X509_get_issuer_name(cert));
+		iss_truncated = truncate_cert_name(issuer);
+
+		/*
+		 * Pull the serial number, too, in case a Subject is still ambiguous.
+		 * This mirrors be_tls_get_peer_serial().
+		 */
+		sn = X509_get_serialNumber(cert);
+		b = ASN1_INTEGER_to_BN(sn, NULL);
+		serialno = BN_bn2dec(b);
+
+		appendStringInfoChar(&str, '\n');
+		appendStringInfo(&str,
+						 _("Failed certificate data (unverified): subject \"%s\", serial number %s, issuer \"%s\"."),
+						 sub_truncated ? sub_truncated : subject,
+						 serialno ? serialno : _("unknown"),
+						 iss_truncated ? iss_truncated : issuer);
+
+		BN_free(b);
+		OPENSSL_free(serialno);
+		pfree(issuer);
+		pfree(subject);
+	}
+
+	/* Store our detail message to be logged later. */
+	cert_errdetail = str.data;
+
 	return ok;
 }