upstream: 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 the key filename, its type and fingerprint, and whether
the key is hosted in an agent or a token.

OpenBSD-Commit-ID: 2a01d59285a8a7e01185bb0a43316084b4f06a1f

1 files changed, 47 insertions, 26 deletions

diff --git a/sshconnect2.c b/sshconnect2.c
index 10e4f0a08..ad9b850d2 100644
--- a/sshconnect2.c
+++ b/sshconnect2.c
@@ -1,4 +1,4 @@
-/* $OpenBSD: sshconnect2.c,v 1.284 2018/08/13 02:41:05 djm Exp $ */
+/* $OpenBSD: sshconnect2.c,v 1.285 2018/09/14 04:17:12 djm Exp $ */
 /*
  * Copyright (c) 2000 Markus Friedl.  All rights reserved.
  * Copyright (c) 2008 Damien Miller.  All rights reserved.
@@ -581,6 +581,27 @@ 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, *ret = NULL;
+
+        if ((fp = sshkey_fingerprint(id->key, options.fingerprint_hash,
+            SSH_FP_DEFAULT)) == NULL)
+                fatal("%s: sshkey_fingerprint failed", __func__);
+        xasprintf(&ret, "%s %s %s%s%s%s",
+            id->filename, sshkey_type(id->key), fp,
+            id->userprovided ? ", explicit" : "",
+            (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 +609,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 +623,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 +637,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 +645,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 +1484,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 +1601,11 @@ 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" : "");
+                ident = format_identity(id);
+                debug("Will attempt key: %s", ident);
+                free(ident);
         }
+        debug2("%s: done", __func__);
 }
 
 static void
@@ -1625,7 +1653,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 +1668,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 {