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

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.
---
 usr.bin/ssh/sshconnect2.c | 79 ++++++++++++++++++++++++++-------------
 1 file changed, 53 insertions(+), 26 deletions(-)

diff --git a/usr.bin/ssh/sshconnect2.c b/usr.bin/ssh/sshconnect2.c
index fbddc7dacc4..f104408375e 100644
--- a/usr.bin/ssh/sshconnect2.c
+++ b/usr.bin/ssh/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.
@@ -573,6 +573,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)
@@ -580,9 +604,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;
 
@@ -594,10 +618,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) {
@@ -610,11 +632,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
@@ -623,13 +640,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);
 
@@ -1450,6 +1479,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 */
@@ -1566,10 +1596,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
@@ -1617,7 +1651,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++)
@@ -1632,16 +1666,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 {
-- 
2.20.1