Fixes logging of partial authentication when privsep is enabled

Previously, we recorded "Failed xxx" since we reset authenticated before
calling auth_log() in auth2.c. This adds an explcit "Partial" state.

Add a "submethod" to auth_log() to report which submethod is used
for keyboard-interactive.

Fix multiple authentication when one of the methods is
keyboard-interactive.

ok markus@

9 files changed, 84 insertions, 69 deletions

diff --git a/usr.bin/ssh/auth.c b/usr.bin/ssh/auth.c
index 9568b3fb6c2..e537ef70f45 100644
--- a/usr.bin/ssh/auth.c
+++ b/usr.bin/ssh/auth.c
@@ -1,4 +1,4 @@
-/* $OpenBSD: auth.c,v 1.97 2012/10/30 21:29:54 djm Exp $ */
+/* $OpenBSD: auth.c,v 1.98 2012/12/02 20:34:09 djm Exp $ */
 /*
  * Copyright (c) 2000 Markus Friedl.  All rights reserved.
  *
@@ -179,7 +179,8 @@ allowed_user(struct passwd * pw)
 }
 
 void
-auth_log(Authctxt *authctxt, int authenticated, char *method, char *info)
+auth_log(Authctxt *authctxt, int authenticated, int partial,
+    const char *method, const char *submethod, const char *info)
 {
 	void (*authlog) (const char *fmt,...) = verbose;
 	char *authmsg;
@@ -196,12 +197,15 @@ auth_log(Authctxt *authctxt, int authenticated, char *method, char *info)
 
 	if (authctxt->postponed)
 		authmsg = "Postponed";
+	else if (partial)
+		authmsg = "Partial";
 	else
 		authmsg = authenticated ? "Accepted" : "Failed";
 
-	authlog("%s %s for %s%.100s from %.200s port %d%s",
+	authlog("%s %s%s%s for %s%.100s from %.200s port %d%s",
 	    authmsg,
 	    method,
+	    submethod != NULL ? "/" : "", submethod == NULL ? "" : submethod,
 	    authctxt->valid ? "" : "invalid user ",
 	    authctxt->user,
 	    get_remote_ipaddr(),
@@ -213,7 +217,7 @@ auth_log(Authctxt *authctxt, int authenticated, char *method, char *info)
  * Check whether root logins are disallowed.
  */
 int
-auth_root_allowed(char *method)
+auth_root_allowed(const char *method)
 {
 	switch (options.permit_root_login) {
 	case PERMIT_YES:
diff --git a/usr.bin/ssh/auth.h b/usr.bin/ssh/auth.h
index da758086558..962bfe4e9ea 100644
--- a/usr.bin/ssh/auth.h
+++ b/usr.bin/ssh/auth.h
@@ -1,4 +1,4 @@
-/* $OpenBSD: auth.h,v 1.71 2012/11/04 11:09:15 djm Exp $ */
+/* $OpenBSD: auth.h,v 1.72 2012/12/02 20:34:09 djm Exp $ */
 
 /*
  * Copyright (c) 2000 Markus Friedl.  All rights reserved.
@@ -127,9 +127,10 @@ void	krb5_cleanup_proc(Authctxt *authctxt);
 void	do_authentication(Authctxt *);
 void	do_authentication2(Authctxt *);
 
-void	auth_log(Authctxt *, int, char *, char *);
-void	userauth_finish(Authctxt *, int, char *);
-int	auth_root_allowed(char *);
+void	auth_log(Authctxt *, int, int, const char *, const char *,
+    const char *);
+void	userauth_finish(Authctxt *, int, const char *, const char *);
+int	auth_root_allowed(const char *);
 
 char	*auth2_read_banner(void);
 int	 auth2_methods_valid(const char *, int);
diff --git a/usr.bin/ssh/auth1.c b/usr.bin/ssh/auth1.c
index ccc86a9a362..b19640d5ba6 100644
--- a/usr.bin/ssh/auth1.c
+++ b/usr.bin/ssh/auth1.c
@@ -1,4 +1,4 @@
-/* $OpenBSD: auth1.c,v 1.76 2012/11/04 11:09:15 djm Exp $ */
+/* $OpenBSD: auth1.c,v 1.77 2012/12/02 20:34:09 djm Exp $ */
 /*
  * Copyright (c) 1995 Tatu Ylonen <ylo@cs.hut.fi>, Espoo, Finland
  *                    All rights reserved
@@ -244,7 +244,7 @@ do_authloop(Authctxt *authctxt)
 	    (!options.kerberos_authentication || options.kerberos_or_local_passwd) &&
 #endif
 	    PRIVSEP(auth_password(authctxt, ""))) {
-		auth_log(authctxt, 1, "without authentication", "");
+		auth_log(authctxt, 1, 0, "without authentication", NULL, "");
 		return;
 	}
 
@@ -293,7 +293,8 @@ do_authloop(Authctxt *authctxt)
 
  skip:
 		/* Log before sending the reply */
-		auth_log(authctxt, authenticated, get_authname(type), info);
+		auth_log(authctxt, authenticated, 0, get_authname(type),
+		    NULL, info);
 
 		if (authenticated)
 			return;
diff --git a/usr.bin/ssh/auth2-chall.c b/usr.bin/ssh/auth2-chall.c
index 4f0c3667693..0090c8a9f36 100644
--- a/usr.bin/ssh/auth2-chall.c
+++ b/usr.bin/ssh/auth2-chall.c
@@ -1,4 +1,4 @@
-/* $OpenBSD: auth2-chall.c,v 1.34 2008/12/09 04:32:22 djm Exp $ */
+/* $OpenBSD: auth2-chall.c,v 1.35 2012/12/02 20:34:09 djm Exp $ */
 /*
  * Copyright (c) 2001 Markus Friedl.  All rights reserved.
  * Copyright (c) 2001 Per Allansson.  All rights reserved.
@@ -238,7 +238,7 @@ input_userauth_info_response(int type, u_int32_t seq, void *ctxt)
 	KbdintAuthctxt *kbdintctxt;
 	int authenticated = 0, res;
 	u_int i, nresp;
-	char **response = NULL, *method;
+	char *devicename = NULL, **response = NULL;
 
 	if (authctxt == NULL)
 		fatal("input_userauth_info_response: no authctxt");
@@ -284,9 +284,7 @@ input_userauth_info_response(int type, u_int32_t seq, void *ctxt)
 		/* Failure! */
 		break;
 	}
-
-	xasprintf(&method, "keyboard-interactive/%s", kbdintctxt->device->name);
-
+	devicename = kbdintctxt->device->name;
 	if (!authctxt->postponed) {
 		if (authenticated) {
 			auth2_challenge_stop(authctxt);
@@ -296,8 +294,8 @@ input_userauth_info_response(int type, u_int32_t seq, void *ctxt)
 			auth2_challenge_start(authctxt);
 		}
 	}
-	userauth_finish(authctxt, authenticated, method);
-	xfree(method);
+	userauth_finish(authctxt, authenticated, "keyboard-interactive",
+	    devicename);
 }
 
 void
diff --git a/usr.bin/ssh/auth2-gss.c b/usr.bin/ssh/auth2-gss.c
index 4f5fc28419f..be7c88d7dff 100644
--- a/usr.bin/ssh/auth2-gss.c
+++ b/usr.bin/ssh/auth2-gss.c
@@ -1,4 +1,4 @@
-/* $OpenBSD: auth2-gss.c,v 1.17 2011/03/10 02:52:57 djm Exp $ */
+/* $OpenBSD: auth2-gss.c,v 1.18 2012/12/02 20:34:09 djm Exp $ */
 
 /*
  * Copyright (c) 2001-2003 Simon Wilkinson. All rights reserved.
@@ -159,7 +159,7 @@ input_gssapi_token(int type, u_int32_t plen, void *ctxt)
 		}
 		authctxt->postponed = 0;
 		dispatch_set(SSH2_MSG_USERAUTH_GSSAPI_TOKEN, NULL);
-		userauth_finish(authctxt, 0, "gssapi-with-mic");
+		userauth_finish(authctxt, 0, "gssapi-with-mic", NULL);
 	} else {
 		if (send_tok.length != 0) {
 			packet_start(SSH2_MSG_USERAUTH_GSSAPI_TOKEN);
@@ -247,7 +247,7 @@ input_gssapi_exchange_complete(int type, u_int32_t plen, void *ctxt)
 	dispatch_set(SSH2_MSG_USERAUTH_GSSAPI_ERRTOK, NULL);
 	dispatch_set(SSH2_MSG_USERAUTH_GSSAPI_MIC, NULL);
 	dispatch_set(SSH2_MSG_USERAUTH_GSSAPI_EXCHANGE_COMPLETE, NULL);
-	userauth_finish(authctxt, authenticated, "gssapi-with-mic");
+	userauth_finish(authctxt, authenticated, "gssapi-with-mic", NULL);
 }
 
 static void
@@ -287,7 +287,7 @@ input_gssapi_mic(int type, u_int32_t plen, void *ctxt)
 	dispatch_set(SSH2_MSG_USERAUTH_GSSAPI_ERRTOK, NULL);
 	dispatch_set(SSH2_MSG_USERAUTH_GSSAPI_MIC, NULL);
 	dispatch_set(SSH2_MSG_USERAUTH_GSSAPI_EXCHANGE_COMPLETE, NULL);
-	userauth_finish(authctxt, authenticated, "gssapi-with-mic");
+	userauth_finish(authctxt, authenticated, "gssapi-with-mic", NULL);
 }
 
 Authmethod method_gssapi = {
diff --git a/usr.bin/ssh/auth2-jpake.c b/usr.bin/ssh/auth2-jpake.c
index a460e821625..ed0eba47b47 100644
--- a/usr.bin/ssh/auth2-jpake.c
+++ b/usr.bin/ssh/auth2-jpake.c
@@ -1,4 +1,4 @@
-/* $OpenBSD: auth2-jpake.c,v 1.4 2010/08/31 11:54:45 djm Exp $ */
+/* $OpenBSD: auth2-jpake.c,v 1.5 2012/12/02 20:34:09 djm Exp $ */
 /*
  * Copyright (c) 2008 Damien Miller.  All rights reserved.
  *
@@ -556,7 +556,7 @@ input_userauth_jpake_client_confirm(int type, u_int32_t seq, void *ctxt)
 	authctxt->postponed = 0;
 	jpake_free(authctxt->jpake_ctx);
 	authctxt->jpake_ctx = NULL;
-	userauth_finish(authctxt, authenticated, method_jpake.name);
+	userauth_finish(authctxt, authenticated, method_jpake.name, NULL);
 }
 
 #endif /* JPAKE */
diff --git a/usr.bin/ssh/auth2.c b/usr.bin/ssh/auth2.c
index a1359b74dca..8b157b4bed9 100644
--- a/usr.bin/ssh/auth2.c
+++ b/usr.bin/ssh/auth2.c
@@ -1,4 +1,4 @@
-/* $OpenBSD: auth2.c,v 1.125 2012/11/04 11:09:15 djm Exp $ */
+/* $OpenBSD: auth2.c,v 1.126 2012/12/02 20:34:09 djm Exp $ */
 /*
  * Copyright (c) 2000 Markus Friedl.  All rights reserved.
  *
@@ -266,7 +266,7 @@ input_userauth_request(int type, u_int32_t seq, void *ctxt)
 		debug2("input_userauth_request: try method %s", method);
 		authenticated =	m->userauth(authctxt);
 	}
-	userauth_finish(authctxt, authenticated, method);
+	userauth_finish(authctxt, authenticated, method, NULL);
 
 	xfree(service);
 	xfree(user);
@@ -274,7 +274,8 @@ input_userauth_request(int type, u_int32_t seq, void *ctxt)
 }
 
 void
-userauth_finish(Authctxt *authctxt, int authenticated, char *method)
+userauth_finish(Authctxt *authctxt, int authenticated, const char *method,
+    const char *submethod)
 {
 	char *methods;
 	int partial = 0;
@@ -282,18 +283,14 @@ userauth_finish(Authctxt *authctxt, int authenticated, char *method)
 	if (!authctxt->valid && authenticated)
 		fatal("INTERNAL ERROR: authenticated invalid user %s",
 		    authctxt->user);
+	if (authenticated && authctxt->postponed)
+		fatal("INTERNAL ERROR: authenticated and postponed");
 
 	/* Special handling for root */
 	if (authenticated && authctxt->pw->pw_uid == 0 &&
 	    !auth_root_allowed(method))
 		authenticated = 0;
 
-	/* Log before sending the reply */
-	auth_log(authctxt, authenticated, method, " ssh2");
-
-	if (authctxt->postponed)
-		return;
-
 	if (authenticated && options.num_auth_methods != 0) {
 		if (!auth2_update_methods_lists(authctxt, method)) {
 			authenticated = 0;
@@ -301,6 +298,12 @@ userauth_finish(Authctxt *authctxt, int authenticated, char *method)
 		}
 	}
 
+	/* Log before sending the reply */
+	auth_log(authctxt, authenticated, partial, method, submethod, " ssh2");
+
+	if (authctxt->postponed)
+		return;
+
 	if (authenticated == 1) {
 		/* turn off userauth */
 		dispatch_set(SSH2_MSG_USERAUTH_REQUEST, &dispatch_protocol_ignore);
diff --git a/usr.bin/ssh/monitor.c b/usr.bin/ssh/monitor.c
index 7e21358fedc..628200e9bf2 100644
--- a/usr.bin/ssh/monitor.c
+++ b/usr.bin/ssh/monitor.c
@@ -1,4 +1,4 @@
-/* $OpenBSD: monitor.c,v 1.118 2012/11/04 11:09:15 djm Exp $ */
+/* $OpenBSD: monitor.c,v 1.119 2012/12/02 20:34:10 djm Exp $ */
 /*
  * Copyright 2002 Niels Provos <provos@citi.umich.edu>
  * Copyright 2002 Markus Friedl <markus@openbsd.org>
@@ -163,6 +163,7 @@ static int key_blobtype = MM_NOKEY;
 static char *hostbased_cuser = NULL;
 static char *hostbased_chost = NULL;
 static char *auth_method = "unknown";
+static char *auth_submethod = NULL;
 static u_int session_id2_len = 0;
 static u_char *session_id2 = NULL;
 static pid_t monitor_child_pid;
@@ -274,7 +275,7 @@ void
 monitor_child_preauth(Authctxt *_authctxt, struct monitor *pmonitor)
 {
 	struct mon_table *ent;
-	int authenticated = 0;
+	int authenticated = 0, partial = 0;
 
 	debug3("preauth child monitor started");
 
@@ -299,7 +300,9 @@ monitor_child_preauth(Authctxt *_authctxt, struct monitor *pmonitor)
 
 	/* The first few requests do not require asynchronous access */
 	while (!authenticated) {
+		partial = 0;
 		auth_method = "unknown";
+		auth_submethod = NULL;
 		authenticated = (monitor_read(pmonitor, mon_dispatch, &ent) == 1);
 
 		/* Special handling for multiple required authentications */
@@ -313,6 +316,7 @@ monitor_child_preauth(Authctxt *_authctxt, struct monitor *pmonitor)
 				debug3("%s: method %s: partial", __func__,
 				    auth_method);
 				authenticated = 0;
+				partial = 1;
 			}
 		}
 
@@ -325,7 +329,8 @@ monitor_child_preauth(Authctxt *_authctxt, struct monitor *pmonitor)
 				authenticated = 0;
 		}
 		if (ent->flags & (MON_AUTHDECIDE|MON_ALOG)) {
-			auth_log(authctxt, authenticated, auth_method,
+			auth_log(authctxt, authenticated, partial,
+			    auth_method, auth_submethod,
 			    compat20 ? " ssh2" : "");
 			if (!authenticated)
 				authctxt->failures++;
@@ -844,7 +849,7 @@ mm_answer_bsdauthrespond(int sock, Buffer *m)
 	mm_request_send(sock, MONITOR_ANS_BSDAUTHRESPOND, m);
 
 	if (compat20)
-		auth_method = "keyboard-interactive";
+		auth_method = "keyboard-interactive"; /* XXX auth_submethod */
 	else
 		auth_method = "bsdauth";
 
@@ -920,7 +925,8 @@ mm_answer_keyallowed(int sock, Buffer *m)
 		hostbased_chost = chost;
 	} else {
 		/* Log failed attempt */
-		auth_log(authctxt, 0, auth_method, compat20 ? " ssh2" : "");
+		auth_log(authctxt, 0, 0, auth_method, NULL,
+		    compat20 ? " ssh2" : "");
 		xfree(blob);
 		xfree(cuser);
 		xfree(chost);
diff --git a/usr.bin/ssh/monitor.h b/usr.bin/ssh/monitor.h
index 05eccf31e12..bf4dccba342 100644
--- a/usr.bin/ssh/monitor.h
+++ b/usr.bin/ssh/monitor.h
@@ -1,4 +1,4 @@
-/* $OpenBSD: monitor.h,v 1.16 2011/06/17 21:44:31 djm Exp $ */
+/* $OpenBSD: monitor.h,v 1.17 2012/12/02 20:34:10 djm Exp $ */
 
 /*
  * Copyright 2002 Niels Provos <provos@citi.umich.edu>
@@ -28,37 +28,39 @@
 #ifndef _MONITOR_H_
 #define _MONITOR_H_
 
+/* Please keep *_REQ_* values on even numbers and *_ANS_* on odd numbers */
 enum monitor_reqtype {
-	MONITOR_REQ_MODULI, MONITOR_ANS_MODULI,
-	MONITOR_REQ_FREE, MONITOR_REQ_AUTHSERV,
-	MONITOR_REQ_SIGN, MONITOR_ANS_SIGN,
-	MONITOR_REQ_PWNAM, MONITOR_ANS_PWNAM,
-	MONITOR_REQ_AUTH2_READ_BANNER, MONITOR_ANS_AUTH2_READ_BANNER,
-	MONITOR_REQ_AUTHPASSWORD, MONITOR_ANS_AUTHPASSWORD,
-	MONITOR_REQ_BSDAUTHQUERY, MONITOR_ANS_BSDAUTHQUERY,
-	MONITOR_REQ_BSDAUTHRESPOND, MONITOR_ANS_BSDAUTHRESPOND,
-	MONITOR_REQ_SKEYQUERY, MONITOR_ANS_SKEYQUERY,
-	MONITOR_REQ_SKEYRESPOND, MONITOR_ANS_SKEYRESPOND,
-	MONITOR_REQ_KEYALLOWED, MONITOR_ANS_KEYALLOWED,
-	MONITOR_REQ_KEYVERIFY, MONITOR_ANS_KEYVERIFY,
-	MONITOR_REQ_KEYEXPORT,
-	MONITOR_REQ_PTY, MONITOR_ANS_PTY,
-	MONITOR_REQ_PTYCLEANUP,
-	MONITOR_REQ_SESSKEY, MONITOR_ANS_SESSKEY,
-	MONITOR_REQ_SESSID,
-	MONITOR_REQ_RSAKEYALLOWED, MONITOR_ANS_RSAKEYALLOWED,
-	MONITOR_REQ_RSACHALLENGE, MONITOR_ANS_RSACHALLENGE,
-	MONITOR_REQ_RSARESPONSE, MONITOR_ANS_RSARESPONSE,
-	MONITOR_REQ_GSSSETUP, MONITOR_ANS_GSSSETUP,
-	MONITOR_REQ_GSSSTEP, MONITOR_ANS_GSSSTEP,
-	MONITOR_REQ_GSSUSEROK, MONITOR_ANS_GSSUSEROK,
-	MONITOR_REQ_GSSCHECKMIC, MONITOR_ANS_GSSCHECKMIC,
-	MONITOR_REQ_TERM,
-	MONITOR_REQ_JPAKE_STEP1, MONITOR_ANS_JPAKE_STEP1,
-	MONITOR_REQ_JPAKE_GET_PWDATA, MONITOR_ANS_JPAKE_GET_PWDATA,
-	MONITOR_REQ_JPAKE_STEP2, MONITOR_ANS_JPAKE_STEP2,
-	MONITOR_REQ_JPAKE_KEY_CONFIRM, MONITOR_ANS_JPAKE_KEY_CONFIRM,
-	MONITOR_REQ_JPAKE_CHECK_CONFIRM, MONITOR_ANS_JPAKE_CHECK_CONFIRM,
+	MONITOR_REQ_MODULI = 0, MONITOR_ANS_MODULI = 1,
+	MONITOR_REQ_FREE = 2,
+	MONITOR_REQ_AUTHSERV = 4,
+	MONITOR_REQ_SIGN = 6, MONITOR_ANS_SIGN = 7,
+	MONITOR_REQ_PWNAM = 8, MONITOR_ANS_PWNAM = 9,
+	MONITOR_REQ_AUTH2_READ_BANNER = 10, MONITOR_ANS_AUTH2_READ_BANNER = 11,
+	MONITOR_REQ_AUTHPASSWORD = 12, MONITOR_ANS_AUTHPASSWORD = 13,
+	MONITOR_REQ_BSDAUTHQUERY = 14, MONITOR_ANS_BSDAUTHQUERY = 15,
+	MONITOR_REQ_BSDAUTHRESPOND = 16, MONITOR_ANS_BSDAUTHRESPOND = 17,
+	MONITOR_REQ_SKEYQUERY = 18, MONITOR_ANS_SKEYQUERY = 19,
+	MONITOR_REQ_SKEYRESPOND = 20, MONITOR_ANS_SKEYRESPOND = 21,
+	MONITOR_REQ_KEYALLOWED = 22, MONITOR_ANS_KEYALLOWED = 23,
+	MONITOR_REQ_KEYVERIFY = 24, MONITOR_ANS_KEYVERIFY = 25,
+	MONITOR_REQ_KEYEXPORT = 26,
+	MONITOR_REQ_PTY = 28, MONITOR_ANS_PTY = 29,
+	MONITOR_REQ_PTYCLEANUP = 30,
+	MONITOR_REQ_SESSKEY = 32, MONITOR_ANS_SESSKEY = 33,
+	MONITOR_REQ_SESSID = 34,
+	MONITOR_REQ_RSAKEYALLOWED = 36, MONITOR_ANS_RSAKEYALLOWED = 37,
+	MONITOR_REQ_RSACHALLENGE = 38, MONITOR_ANS_RSACHALLENGE = 39,
+	MONITOR_REQ_RSARESPONSE = 40, MONITOR_ANS_RSARESPONSE = 41,
+	MONITOR_REQ_GSSSETUP = 42, MONITOR_ANS_GSSSETUP = 43,
+	MONITOR_REQ_GSSSTEP = 44, MONITOR_ANS_GSSSTEP = 45,
+	MONITOR_REQ_GSSUSEROK = 46, MONITOR_ANS_GSSUSEROK = 47,
+	MONITOR_REQ_GSSCHECKMIC = 48, MONITOR_ANS_GSSCHECKMIC = 49,
+	MONITOR_REQ_TERM = 50,
+	MONITOR_REQ_JPAKE_STEP1 = 52, MONITOR_ANS_JPAKE_STEP1 = 53,
+	MONITOR_REQ_JPAKE_GET_PWDATA = 54, MONITOR_ANS_JPAKE_GET_PWDATA = 55,
+	MONITOR_REQ_JPAKE_STEP2 = 56, MONITOR_ANS_JPAKE_STEP2 = 57,
+	MONITOR_REQ_JPAKE_KEY_CONFIRM = 58, MONITOR_ANS_JPAKE_KEY_CONFIRM = 59,
+	MONITOR_REQ_JPAKE_CHECK_CONFIRM = 60, MONITOR_ANS_JPAKE_CHECK_CONFIRM = 61,
 };
 
 struct mm_master;