Michel Lind 1c324b
--- a/auth2-pubkey.c
d1c05f
+++ b/auth2-pubkey.c
Michel Lind 1c324b
@@ -390,6 +390,10 @@ check_principals_line(struct ssh *ssh, c
d1c05f
 			continue;
d1c05f
 		debug3("%s: matched principal \"%.100s\"",
d1c05f
 		    loc, cert->principals[i]);
d1c05f
+		verbose("Matched principal \"%.100s\" from %s against \"%.100s\" "
d1c05f
+		    "from cert",
d1c05f
+		    cp, loc, cert->principals[i]);
d1c05f
+
d1c05f
 		found = 1;
d1c05f
 		slog_set_principal(cp);
d1c05f
 	}
Michel Lind 1c324b
@@ -433,6 +437,8 @@ process_principals(struct ssh *ssh, FILE
d1c05f
 			found_principal = 1;
d1c05f
 	}
d1c05f
 	free(line);
d1c05f
+	if (!found_principal)
d1c05f
+		verbose("Did not match any principals from auth_principals_* files");
d1c05f
 	return found_principal;
d1c05f
 }
d1c05f
 
Michel Lind 1c324b
@@ -711,7 +717,7 @@ check_authkey_line(struct ssh *ssh, stru
d1c05f
 	    &reason) != 0)
d1c05f
 		goto fail_reason;
d1c05f
 
d1c05f
-	verbose("Accepted certificate ID \"%s\" (serial %llu) "
d1c05f
+	verbose("Accepted cert ID \"%s\" (serial %llu) "
d1c05f
 	    "signed by CA %s %s found at %s",
d1c05f
 	    key->cert->key_id,
d1c05f
 	    (unsigned long long)key->cert->serial,
Michel Lind 1c324b
@@ -781,7 +787,7 @@ static int
d1c05f
 user_cert_trusted_ca(struct ssh *ssh, struct passwd *pw, struct sshkey *key,
d1c05f
     struct sshauthopt **authoptsp)
d1c05f
 {
d1c05f
-	char *ca_fp, *principals_file = NULL;
d1c05f
+	char *ca_fp, *key_fp, *principals_file = NULL;
d1c05f
 	const char *reason;
d1c05f
 	struct sshauthopt *principals_opts = NULL, *cert_opts = NULL;
d1c05f
 	struct sshauthopt *final_opts = NULL;
Michel Lind 1c324b
@@ -797,11 +803,16 @@ user_cert_trusted_ca(struct ssh *ssh, st
d1c05f
 	    options.fingerprint_hash, SSH_FP_DEFAULT)) == NULL)
d1c05f
 		return 0;
d1c05f
 
d1c05f
+	key_fp = sshkey_fingerprint(key, options.fingerprint_hash, SSH_FP_DEFAULT);
d1c05f
+
d1c05f
 	if ((r = sshkey_in_file(key->cert->signature_key,
d1c05f
 	    options.trusted_user_ca_keys, 1, 0)) != 0) {
d1c05f
 		debug2_fr(r, "CA %s %s is not listed in %s",
d1c05f
 		    sshkey_type(key->cert->signature_key), ca_fp,
d1c05f
 		    options.trusted_user_ca_keys);
d1c05f
+		verbose("CA %s %s is not listed in %s",
d1c05f
+		    sshkey_type(key->cert->signature_key), ca_fp,
d1c05f
+		    options.trusted_user_ca_keys);
d1c05f
 		goto out;
d1c05f
 	}
d1c05f
 	/*
Michel Lind 1c324b
@@ -852,6 +863,11 @@ user_cert_trusted_ca(struct ssh *ssh, st
d1c05f
 		if ((final_opts = sshauthopt_merge(principals_opts,
d1c05f
 		    cert_opts, &reason)) == NULL) {
d1c05f
  fail_reason:
d1c05f
+			verbose("Rejected cert ID \"%s\" with signature "
d1c05f
+			    "%s signed by %s CA %s via %s",
d1c05f
+			    key->cert->key_id, key_fp,
d1c05f
+			    sshkey_type(key->cert->signature_key), ca_fp,
d1c05f
+			    options.trusted_user_ca_keys);
d1c05f
 			error("%s", reason);
d1c05f
 			auth_debug_add("%s", reason);
d1c05f
 			goto out;
Michel Lind 1c324b
@@ -859,9 +875,10 @@ user_cert_trusted_ca(struct ssh *ssh, st
d1c05f
 	}
d1c05f
 
d1c05f
 	/* Success */
d1c05f
-	verbose("Accepted certificate ID \"%s\" (serial %llu) signed by "
d1c05f
-	    "%s CA %s via %s", key->cert->key_id,
d1c05f
-	    (unsigned long long)key->cert->serial,
d1c05f
+	verbose("Accepted cert ID \"%s\" (serial %llu) with signature %s "
d1c05f
+	    "signed by %s CA %s via %s",
d1c05f
+	    key->cert->key_id,
d1c05f
+	    (unsigned long long)key->cert->serial, key_fp,
d1c05f
 	    sshkey_type(key->cert->signature_key), ca_fp,
d1c05f
 	    options.trusted_user_ca_keys);
d1c05f
 	if (authoptsp != NULL) {
Michel Lind 1c324b
@@ -876,6 +893,7 @@ user_cert_trusted_ca(struct ssh *ssh, st
d1c05f
 	sshauthopt_free(final_opts);
d1c05f
 	free(principals_file);
d1c05f
 	free(ca_fp);
d1c05f
+	free(key_fp);
d1c05f
 	return ret;
d1c05f
 }
d1c05f
 
d1c05f
--- /dev/null
d1c05f
+++ b/regress/cert-logging.sh
d1c05f
@@ -0,0 +1,84 @@
d1c05f
+tid="cert logging"
d1c05f
+
d1c05f
+CERT_ID="cert_id"
d1c05f
+PRINCIPAL=$USER
d1c05f
+SERIAL=0
d1c05f
+
d1c05f
+log_grep() {
d1c05f
+    if [ "$(grep -c -G "$1" "$TEST_SSHD_LOGFILE")" == "0" ]; then
d1c05f
+        return 1;
d1c05f
+    else
d1c05f
+        return 0;
d1c05f
+    fi
d1c05f
+}
d1c05f
+
d1c05f
+cat << EOF >> $OBJ/sshd_config
d1c05f
+TrustedUserCAKeys $OBJ/ssh-rsa.pub
d1c05f
+Protocol 2
d1c05f
+PubkeyAuthentication yes
d1c05f
+AuthenticationMethods publickey
d1c05f
+AuthorizedPrincipalsFile $OBJ/auth_principals
d1c05f
+EOF
d1c05f
+
d1c05f
+if [ ! -f $OBJ/trusted_rsa ]; then
d1c05f
+    ${SSHKEYGEN} -q -t rsa -C '' -N '' -f $OBJ/trusted_rsa
d1c05f
+fi
d1c05f
+if [ ! -f $OBJ/untrusted_rsa ]; then
d1c05f
+    ${SSHKEYGEN} -q -t rsa -C '' -N '' -f $OBJ/untrusted_rsa
d1c05f
+fi
d1c05f
+
d1c05f
+${SSHKEYGEN} -q -s $OBJ/ssh-rsa -I $CERT_ID -n $PRINCIPAL -z $SERIAL $OBJ/trusted_rsa.pub ||
d1c05f
+    fatal "Could not create trusted SSH cert"
d1c05f
+
d1c05f
+${SSHKEYGEN} -q -s $OBJ/untrusted_rsa -I $CERT_ID -n $PRINCIPAL -z $SERIAL $OBJ/untrusted_rsa.pub ||
d1c05f
+    fatal "Could not create untrusted SSH cert"
d1c05f
+
d1c05f
+CA_FP="$(${SSHKEYGEN} -l -E sha256 -f ssh-rsa | cut -d' ' -f2)"
d1c05f
+KEY_FP="$(${SSHKEYGEN} -l -E sha256 -f trusted_rsa | cut -d' ' -f2)"
d1c05f
+UNTRUSTED_CA_FP="$(${SSHKEYGEN} -l -E sha256 -f untrusted_rsa | cut -d' ' -f2)"
d1c05f
+
d1c05f
+start_sshd
d1c05f
+
d1c05f
+
d1c05f
+test_no_principals() {
d1c05f
+    echo > $OBJ/auth_principals
d1c05f
+    ${SSH} -F $OBJ/ssh_config -i $OBJ/trusted_rsa-cert.pub somehost true ||
d1c05f
+        fatal "SSH failed"
d1c05f
+
d1c05f
+    if ! log_grep 'Did not match any principals from auth_principals_\* files'; then
d1c05f
+        fail "No 'Did not match any principals' message"
d1c05f
+    fi
d1c05f
+
d1c05f
+    if ! log_grep "Rejected cert ID \"$CERT_ID\" with signature $KEY_FP signed by RSA CA $CA_FP via $OBJ/ssh-rsa.pub"; then
d1c05f
+        fail "No 'Rejected cert ID' message"
d1c05f
+    fi
d1c05f
+}
d1c05f
+
d1c05f
+
d1c05f
+test_with_principals() {
d1c05f
+    echo $USER > $OBJ/auth_principals
d1c05f
+    ${SSH} -F $OBJ/ssh_config -i $OBJ/trusted_rsa-cert.pub somehost true ||
d1c05f
+        fatal "SSH failed"
d1c05f
+
d1c05f
+    if ! log_grep "Matched principal \"$PRINCIPAL\" from $OBJ/auth_principals:1 against \"$PRINCIPAL\" from cert"; then
d1c05f
+        fail "No 'Matched principal' message"
d1c05f
+    fi
d1c05f
+    if ! log_grep "Accepted cert ID \"$CERT_ID\" (serial $SERIAL) with signature $KEY_FP signed by RSA CA $CA_FP via $OBJ/ssh-rsa.pub"; then
d1c05f
+        fail "No 'Accepted cert ID' message"
d1c05f
+    fi
d1c05f
+}
d1c05f
+
d1c05f
+
d1c05f
+test_untrusted_cert() {
d1c05f
+    ${SSH} -F $OBJ/ssh_config -i $OBJ/untrusted_rsa-cert.pub somehost true ||
d1c05f
+        fatal "SSH failed"
d1c05f
+
d1c05f
+    if ! log_grep "CA RSA $UNTRUSTED_CA_FP is not listed in $OBJ/ssh-rsa.pub"; then
d1c05f
+        fail "No 'CA is not listed' message"
d1c05f
+    fi
d1c05f
+}
d1c05f
+
d1c05f
+
d1c05f
+test_no_principals
d1c05f
+test_with_principals
d1c05f
+test_untrusted_cert