From beb9e522dc7717df08179f9e59f36b361bfa14ab Mon Sep 17 00:00:00 2001
From: "djm@openbsd.org" <djm@openbsd.org>
Date: Fri, 14 Sep 2018 05:26:27 +0000
Subject: [PATCH] upstream: second try, deals properly with missing and
 private-only

Use consistent format in debug log for keys readied, offered and
received during public key authentication.

This makes it a little easier to see what is going on, as each message
now contains (where available) the key filename, its type and fingerprint,
and whether the key is hosted in an agent or a token.

OpenBSD-Commit-ID: f1c6a8e9cfc4e108c359db77f24f9a40e1e25ea7
---
 sshconnect2.c | 79 ++++++++++++++++++++++++++++++++++-----------------
 1 file changed, 53 insertions(+), 26 deletions(-)

diff --git a/sshconnect2.c b/sshconnect2.c
index 41d1a56bd..86a0254be 100644
--- a/sshconnect2.c
+++ b/sshconnect2.c
@@ -1,4 +1,4 @@
-/* $OpenBSD: sshconnect2.c,v 1.286 2018/09/14 04:44:04 djm Exp $ */
+/* $OpenBSD: sshconnect2.c,v 1.287 2018/09/14 05:26:27 djm Exp $ */
 /*
  * Copyright (c) 2000 Markus Friedl.  All rights reserved.
  * Copyright (c) 2008 Damien Miller.  All rights reserved.
@@ -581,6 +581,30 @@ input_userauth_failure(int type, u_int32_t seq, struct ssh *ssh)
 	return 0;
 }
 
+/*
+ * Format an identity for logging including filename, key type, fingerprint
+ * and location (agent, etc.). Caller must free.
+ */
+static char *
+format_identity(Identity *id)
+{
+	char *fp = NULL, *ret = NULL;
+
+	if (id->key != NULL) {
+	     fp = sshkey_fingerprint(id->key, options.fingerprint_hash,
+		    SSH_FP_DEFAULT);
+	}
+	xasprintf(&ret, "%s %s%s%s%s%s%s",
+	    id->filename,
+	    id->key ? sshkey_type(id->key) : "", id->key ? " " : "",
+	    fp ? fp : "",
+	    id->userprovided ? " explicit" : "",
+	    (id->key && (id->key->flags & SSHKEY_FLAG_EXT)) ? " token" : "",
+	    id->agent_fd != -1 ? " agent" : "");
+	free(fp);
+	return ret;
+}
+
 /* ARGSUSED */
 int
 input_userauth_pk_ok(int type, u_int32_t seq, struct ssh *ssh)
@@ -588,9 +612,9 @@ input_userauth_pk_ok(int type, u_int32_t seq, struct ssh *ssh)
 	Authctxt *authctxt = ssh->authctxt;
 	struct sshkey *key = NULL;
 	Identity *id = NULL;
-	int pktype, sent = 0;
+	int pktype, found = 0, sent = 0;
 	size_t blen;
-	char *pkalg = NULL, *fp;
+	char *pkalg = NULL, *fp = NULL, *ident = NULL;
 	u_char *pkblob = NULL;
 	int r;
 
@@ -602,10 +626,8 @@ input_userauth_pk_ok(int type, u_int32_t seq, struct ssh *ssh)
 	    (r = sshpkt_get_end(ssh)) != 0)
 		goto done;
 
-	debug("Server accepts key: pkalg %s blen %zu", pkalg, blen);
-
 	if ((pktype = sshkey_type_from_name(pkalg)) == KEY_UNSPEC) {
-		debug("unknown pkalg %s", pkalg);
+		debug("%s: server sent unknown pkalg %s", __func__, pkalg);
 		goto done;
 	}
 	if ((r = sshkey_from_blob(pkblob, blen, &key)) != 0) {
@@ -618,11 +640,6 @@ input_userauth_pk_ok(int type, u_int32_t seq, struct ssh *ssh)
 		    key->type, pktype);
 		goto done;
 	}
-	if ((fp = sshkey_fingerprint(key, options.fingerprint_hash,
-	    SSH_FP_DEFAULT)) == NULL)
-		goto done;
-	debug2("input_userauth_pk_ok: fp %s", fp);
-	free(fp);
 
 	/*
 	 * search keys in the reverse order, because last candidate has been
@@ -631,13 +648,25 @@ input_userauth_pk_ok(int type, u_int32_t seq, struct ssh *ssh)
 	 */
 	TAILQ_FOREACH_REVERSE(id, &authctxt->keys, idlist, next) {
 		if (sshkey_equal(key, id->key)) {
-			sent = sign_and_send_pubkey(ssh, authctxt, id);
+			found = 1;
 			break;
 		}
 	}
+	if (!found || id == NULL) {
+		fp = sshkey_fingerprint(key, options.fingerprint_hash,
+		    SSH_FP_DEFAULT);
+		error("%s: server replied with unknown key: %s %s", __func__,
+		    sshkey_type(key), fp == NULL ? "<ERROR>" : fp);
+		goto done;
+	}
+	ident = format_identity(id);
+	debug("Server accepts key: %s", ident);
+	sent = sign_and_send_pubkey(ssh, authctxt, id);
 	r = 0;
  done:
 	sshkey_free(key);
+	free(ident);
+	free(fp);
 	free(pkalg);
 	free(pkblob);
 
@@ -1458,6 +1487,7 @@ pubkey_prepare(Authctxt *authctxt)
 	int agent_fd = -1, i, r, found;
 	size_t j;
 	struct ssh_identitylist *idlist;
+	char *ident;
 
 	TAILQ_INIT(&agent);	/* keys from the agent */
 	TAILQ_INIT(&files);	/* keys from the config file */
@@ -1574,10 +1604,14 @@ pubkey_prepare(Authctxt *authctxt)
 			memset(id, 0, sizeof(*id));
 			continue;
 		}
-		debug2("key: %s (%p)%s%s", id->filename, id->key,
-		    id->userprovided ? ", explicit" : "",
-		    id->agent_fd != -1 ? ", agent" : "");
 	}
+	/* List the keys we plan on using */
+	TAILQ_FOREACH_SAFE(id, preferred, next, id2) {
+		ident = format_identity(id);
+		debug("Will attempt key: %s", ident);
+		free(ident);
+	}
+	debug2("%s: done", __func__);
 }
 
 static void
@@ -1625,7 +1659,7 @@ userauth_pubkey(Authctxt *authctxt)
 	struct ssh *ssh = active_state; /* XXX */
 	Identity *id;
 	int sent = 0;
-	char *fp;
+	char *ident;
 
 	while ((id = TAILQ_FIRST(&authctxt->keys))) {
 		if (id->tried++)
@@ -1640,16 +1674,9 @@ userauth_pubkey(Authctxt *authctxt)
 		 */
 		if (id->key != NULL) {
 			if (try_identity(id)) {
-				if ((fp = sshkey_fingerprint(id->key,
-				    options.fingerprint_hash,
-				    SSH_FP_DEFAULT)) == NULL) {
-					error("%s: sshkey_fingerprint failed",
-					    __func__);
-					return 0;
-				}
-				debug("Offering public key: %s %s %s",
-				    sshkey_type(id->key), fp, id->filename);
-				free(fp);
+				ident = format_identity(id);
+				debug("Offering public key: %s", ident);
+				free(ident);
 				sent = send_pubkey_test(ssh, authctxt, id);
 			}
 		} else {