LogLevel INFO shows few details for Certificate invalid: not yet valid / expired

[Damien Miller]

On Wed, 21 May 2025, Lars Noodén via openssh-unix-dev wrote:

> On 4/5/25 15:01, Lars Noodén wrote:
> > I notice that when using log level INFO it seems sshd(8) provides very 
> > little information about failed SSH certificate log in attempts:
> > 
> > Apr  5 14:44:41 server sshd-session[51695]: error: Certificate invalid: 
> > not yet valid
> > 
> > Apr  5 14:45:31 server sshd-session[88953]: error: Certificate invalid: 
> > expired
> > 
> > Likewise for invalid principals:
> > 
> > Apr  5 14:46:56 server sshd-session[66692]: error: Certificate invalid: 
> > name is not a listed principal
> > 
> > Is that on purpose or is there a recommended practice to note the 
> > account, principal, or certificate used in failed attempts?
> > 
> > Having a valid principal + certificate but from an invalid source 
> > address provides more information in the log, but it is split into two 
> > lines:
> > 
> > Apr  5 14:57:47 server sshd-session[78381]: cert: Authentication tried 
> > for lars with valid certificate but not from a permitted source address 
> > (10.11.9.65).
> > Apr  5 14:57:47 server sshd-session[78381]: error: Refused by 
> > certificate options
> > 
> > Thanks,
> > Lars
> 
> Apologies for the timing of the first message.
> 
> As a follow up, it would save a lot of detective work with the logs if, 
> when specific certificate is part of the problem, to include the 
> certificate's id and serial number in the log message.  I'm not sure of 
> what the best punctuation might be or if there is already an established 
> practice for annotating all that.  But here is an illustration of how it 
> could be:

Please give the attached patch a try.

-d

-------------- next part --------------
diff --git a/auth2-hostbased.c b/auth2-hostbased.c
index e221417..0227d8e 100644
--- a/auth2-hostbased.c
+++ b/auth2-hostbased.c
@@ -212,8 +212,16 @@ hostbased_key_allowed(struct ssh *ssh, struct passwd *pw,
 
 	if (sshkey_is_cert(key) &&
 	    sshkey_cert_check_authority_now(key, 1, 0, 0, lookup, &reason)) {
-		error("%s", reason);
-		auth_debug_add("%s", reason);
+		if ((fp = sshkey_fingerprint(key->cert->signature_key,
+		    options.fingerprint_hash, SSH_FP_DEFAULT)) == NULL)
+			fatal_f("sshkey_fingerprint fail");
+		error("Refusing certificate ID \"%s\" serial=%llu signed by "
+		    "%s CA %s: %s", key->cert->key_id, key->cert->serial,
+		    sshkey_type(key->cert->signature_key), fp, reason);
+		auth_debug_add("Refused Certificate ID \"%s\" serial=%llu: %s",
+		    key->cert->key_id, (unsigned long long)key->cert->serial,
+		    reason);
+		free(fp);
 		return 0;
 	}
 
diff --git a/auth2-pubkey.c b/auth2-pubkey.c
index d6bc309..3292f7c 100644
--- a/auth2-pubkey.c
+++ b/auth2-pubkey.c
@@ -583,8 +583,14 @@ user_cert_trusted_ca(struct passwd *pw, struct sshkey *key,
 		if ((final_opts = sshauthopt_merge(principals_opts,
 		    cert_opts, &reason)) == NULL) {
  fail_reason:
-			error("%s", reason);
-			auth_debug_add("%s", reason);
+			error("Refusing certificate ID \"%s\" serial=%llu "
+			    "signed by %s CA %s: %s", key->cert->key_id,
+			    key->cert->serial,
+			    sshkey_type(key->cert->signature_key), ca_fp,
+			    reason);
+			auth_debug_add("Refused Certificate ID \"%s\" "
+			    "serial=%llu: %s", key->cert->key_id,
+			    (unsigned long long)key->cert->serial, reason);
 			goto out;
 		}
 	}
diff --git a/auth2-pubkeyfile.c b/auth2-pubkeyfile.c
index c3bd24b..09ce37e 100644
--- a/auth2-pubkeyfile.c
+++ b/auth2-pubkeyfile.c
@@ -343,15 +343,15 @@ auth_check_authkey_line(struct passwd *pw, struct sshkey *key,
 	/* Parse and check options present in certificate */
 	if ((certopts = sshauthopt_from_cert(key)) == NULL) {
 		reason = "Invalid certificate options";
-		goto fail_reason;
+		goto cert_fail_reason;
 	}
 	if (auth_authorise_keyopts(pw, certopts, 0,
 	    remote_ip, remote_host, loc) != 0) {
 		reason = "Refused by certificate options";
-		goto fail_reason;
+		goto cert_fail_reason;
 	}
 	if ((finalopts = sshauthopt_merge(keyopts, certopts, &reason)) == NULL)
-		goto fail_reason;
+		goto cert_fail_reason;
 
 	/*
 	 * If the user has specified a list of principals as
@@ -361,12 +361,12 @@ auth_check_authkey_line(struct passwd *pw, struct sshkey *key,
 	if (keyopts->cert_principals != NULL &&
 	    !match_principals_option(keyopts->cert_principals, key->cert)) {
 		reason = "Certificate does not contain an authorized principal";
-		goto fail_reason;
+		goto cert_fail_reason;
 	}
 	if (sshkey_cert_check_authority_now(key, 0, 0, 0,
 	    keyopts->cert_principals == NULL ? pw->pw_name : NULL,
 	    &reason) != 0)
-		goto fail_reason;
+		goto cert_fail_reason;
 
 	verbose("Accepted certificate ID \"%s\" (serial %llu) "
 	    "signed by CA %s %s found at %s",
@@ -385,8 +385,17 @@ auth_check_authkey_line(struct passwd *pw, struct sshkey *key,
 	ret = 0;
 	goto out;
 
+ cert_fail_reason:
+	error("Refusing certificate ID \"%s\" serial=%llu "
+	    "signed by %s CA %s via %s: %s", key->cert->key_id,
+	    key->cert->serial, sshkey_type(key->cert->signature_key),
+	    fp, loc, reason);
+	auth_debug_add("Refused Certificate ID \"%s\" serial=%llu: %s",
+	    key->cert->key_id, (unsigned long long)key->cert->serial, reason);
+	goto out;
+
  fail_reason:
-	error("%s", reason);
+	error("%s at %s", reason, loc);
 	auth_debug_add("%s", reason);
  out:
 	free(fp);