Hello,
(I'm cleaning up some old git branches and found this. It was helpful
when I was trying to debug failures between an NSS client and an
OpenSSL server, and it seems general enough to help for more
complicated OpenSSL-only setups as well.)
Currently, debugging client cert verification failures is mostly
limited to looking at the TLS alert code on the client side. For simple
deployments, usually 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, so I've filled it out with error handling and added a COMMERROR
log so that a DBA can debug client failures more easily.
It ends up looking like
LOG: connection received: host=localhost port=44120
LOG: client certificate verification failed at depth 1: unable to get
local issuer certificate
DETAIL: failed certificate's subject: /CN=Test CA for PostgreSQL SSL
regression test client certs
LOG: could not accept SSL connection: certificate verify failed
It might be even nicer to make this available to the client, but I
think the server log is an appropriate place for this information -- an
admin might not want to advertise exactly why a client certificate has
failed verification (other than what's already available via the TLS
alert, that is), and I think more complicated failures (with
intermediate CAs, etc.) are going to need administrator intervention
anyway. So having to check the logs doesn't seem like a big hurdle.
One question/concern -- the Subject that's printed to the logs could be
pretty big (OpenSSL limits the incoming certificate chain to 100K, by
default), which introduces an avenue for intentional log spamming. Is
there an existing convention for limiting the length of log output used
for debugging? Maybe I should just hardcode a smaller limit and
truncate anything past that? Or we could just log the Common Name,
which should be limited to 64 bytes...
I'll add this to the July commitfest.
Thanks,
--Jacob
From e38e9afd8adfa5c39ea1f43f6c4d5b9238ec353c Mon Sep 17 00:00:00 2001
From: Jacob Champion <pchamp...@vmware.com>
Date: Mon, 29 Mar 2021 10:07:31 -0700
Subject: [PATCH] Log details for client certificate failures
Currently, debugging client cert 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. Fill it out with error handling and add a COMMERROR log so that a
DBA can debug client failures more easily. It ends up looking like
LOG: connection received: host=localhost port=44120
LOG: client certificate verification failed at depth 1: unable to get local issuer certificate
DETAIL: failed certificate's subject: /CN=Test CA for PostgreSQL SSL regression test client certs
LOG: could not accept SSL connection: certificate verify failed
---
src/backend/libpq/be-secure-openssl.c | 33 +++++++++++++++++++++++++--
src/test/ssl/t/001_ssltests.pl | 31 +++++++++++++++++++++++--
2 files changed, 60 insertions(+), 4 deletions(-)
diff --git a/src/backend/libpq/be-secure-openssl.c b/src/backend/libpq/be-secure-openssl.c
index 3d0168a369..1683f9cc9e 100644
--- a/src/backend/libpq/be-secure-openssl.c
+++ b/src/backend/libpq/be-secure-openssl.c
@@ -1080,8 +1080,7 @@ dummy_ssl_passwd_cb(char *buf, int size, int rwflag, void *userdata)
* 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.
+ * verification.
*
* This callback also allows us to override the default acceptance
* criteria (e.g., accepting self-signed or expired certs), but
@@ -1090,6 +1089,36 @@ 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;
+ X509 *cert;
+ char *certname = NULL;
+
+ 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);
+
+ cert = X509_STORE_CTX_get_current_cert(ctx);
+ if (cert)
+ certname = X509_NAME_to_cstring(X509_get_subject_name(cert));
+
+ ereport(COMMERROR,
+ (errmsg("client certificate verification failed at depth %d: %s",
+ depth, errstring),
+ /* only print detail if we have a certificate to print */
+ certname && errdetail("failed certificate's subject: %s", certname)));
+
+ if (certname)
+ pfree(certname);
+
return ok;
}
diff --git a/src/test/ssl/t/001_ssltests.pl b/src/test/ssl/t/001_ssltests.pl
index 58d2bc336f..ecc7bd2bce 100644
--- a/src/test/ssl/t/001_ssltests.pl
+++ b/src/test/ssl/t/001_ssltests.pl
@@ -666,6 +666,10 @@ $node->connect_fails(
"$common_connstr user=ssltestuser sslcert=ssl/client-revoked.crt " . sslkey('client-revoked.key'),
"certificate authorization fails with revoked client cert",
expected_stderr => qr/SSL error: sslv3 alert certificate revoked/,
+ log_like => [
+ qr/client certificate verification failed at depth 0: certificate revoked/,
+ qr/failed certificate's subject: \/CN=ssltestuser/,
+ ],
# revoked certificates should not authenticate the user
log_unlike => [qr/connection authenticated:/],);
@@ -708,7 +712,26 @@ $node->connect_ok(
$node->connect_fails(
$common_connstr . " " . "sslmode=require sslcert=ssl/client.crt",
"intermediate client certificate is missing",
- expected_stderr => qr/SSL error: tlsv1 alert unknown ca/);
+ expected_stderr => qr/SSL error: tlsv1 alert unknown ca/,
+ log_like => [
+ qr/client certificate verification failed at depth 0: unable to get local issuer certificate/,
+ qr/failed certificate's subject: \/CN=ssltestuser/,
+ ]);
+
+# Use an invalid cafile here so that the next test won't be able to verify the
+# client CA.
+switch_server_cert($node, certfile => 'server-cn-only', cafile => 'server-cn-only');
+
+# intermediate CA is provided but doesn't have a trusted root (checks error
+# logging for cert chain depths > 0)
+$node->connect_fails(
+ "$common_connstr sslmode=require sslcert=ssl/client+client_ca.crt",
+ "intermediate client certificate is untrusted",
+ expected_stderr => qr/SSL error: tlsv1 alert unknown ca/,
+ log_like => [
+ qr/client certificate verification failed at depth 1: unable to get local issuer certificate/,
+ qr/failed certificate's subject: \/CN=Test CA for PostgreSQL SSL regression test client certs/,
+ ]);
# test server-side CRL directory
switch_server_cert($node, certfile => 'server-cn-only', crldir => 'root+client-crldir');
@@ -717,6 +740,10 @@ switch_server_cert($node, certfile => 'server-cn-only', crldir => 'root+client-c
$node->connect_fails(
"$common_connstr user=ssltestuser sslcert=ssl/client-revoked.crt " . sslkey('client-revoked.key'),
"certificate authorization fails with revoked client cert with server-side CRL directory",
- expected_stderr => qr/SSL error: sslv3 alert certificate revoked/);
+ expected_stderr => qr/SSL error: sslv3 alert certificate revoked/,
+ log_like => [
+ qr/client certificate verification failed at depth 0: certificate revoked/,
+ qr/failed certificate's subject: \/CN=ssltestuser/,
+ ]);
done_testing();
--
2.25.1
