# HG changeset patch
# User Matt Johnston <matt@ucc.asn.au>
# Date 1365005930 -28800
# Node ID d63ef1e211ea0eb0bea7bcd7c551132442435112
# Parent  24172f555f9cdd997bd81c8f5eb852c5e72b4433
Take transmit and receive keys into use separately

diff -r 24172f555f9c -r d63ef1e211ea cli-kex.c
--- a/cli-kex.c	Wed Apr 03 23:54:58 2013 +0800
+++ b/cli-kex.c	Thu Apr 04 00:18:50 2013 +0800
@@ -256,7 +256,6 @@
 		/* Compare hostnames */
 		if (strncmp(cli_opts.remotehost, buf_getptr(line, hostlen),
 					hostlen) != 0) {
-			TRACE2(("hosts don't match"))
 			continue;
 		}
 
diff -r 24172f555f9c -r d63ef1e211ea cli-session.c
--- a/cli-session.c	Wed Apr 03 23:54:58 2013 +0800
+++ b/cli-session.c	Thu Apr 04 00:18:50 2013 +0800
@@ -204,8 +204,7 @@
 	}
 
 	/* A KEX has finished, so we should go back to our KEX_NOTHING state */
-	if (cli_ses.kex_state != KEX_NOTHING && ses.kexstate.recvkexinit == 0
-			&& ses.kexstate.sentkexinit == 0) {
+	if (cli_ses.kex_state != KEX_NOTHING && ses.kexstate.sentnewkeys) {
 		cli_ses.kex_state = KEX_NOTHING;
 	}
 
@@ -218,6 +217,7 @@
 	if (ses.kexstate.donefirstkex == 0) {
 		/* We might reach here if we have partial packet reads or have
 		 * received SSG_MSG_IGNORE etc. Just skip it */
+		TRACE2(("donefirstkex false\n"))
 		return;
 	}
 
diff -r 24172f555f9c -r d63ef1e211ea common-kex.c
--- a/common-kex.c	Wed Apr 03 23:54:58 2013 +0800
+++ b/common-kex.c	Thu Apr 04 00:18:50 2013 +0800
@@ -80,7 +80,7 @@
 static const int DH_G_VAL = 2;
 
 static void kexinitialise();
-void gen_new_keys();
+static void gen_new_keys();
 #ifndef DISABLE_ZLIB
 static void gen_new_zstreams();
 #endif
@@ -159,11 +159,39 @@
 
 }
 
-/* *** NOTE regarding (send|recv)_msg_newkeys *** 
- * Changed by mihnea from the original kex.c to set dataallowed after a 
- * completed key exchange, no matter the order in which it was performed.
- * This enables client mode without affecting server functionality.
- */
+void switch_keys() {
+	TRACE2(("enter switch_keys"))
+	if (!(ses.kexstate.sentkexinit && ses.kexstate.recvkexinit)) {
+		dropbear_exit("Unexpected newkeys message");
+	}
+
+	if (!ses.keys) {
+		ses.keys = m_malloc(sizeof(*ses.newkeys));
+	}
+	if (ses.kexstate.recvnewkeys && ses.newkeys->recv.valid) {
+		TRACE(("switch_keys recv"))
+		ses.keys->recv = ses.newkeys->recv;
+		m_burn(&ses.newkeys->recv, sizeof(ses.newkeys->recv));
+		ses.newkeys->recv.valid = 0;
+	}
+	if (ses.kexstate.sentnewkeys && ses.newkeys->trans.valid) {
+		TRACE(("switch_keys trans"))
+		ses.keys->trans = ses.newkeys->trans;
+		m_burn(&ses.newkeys->trans, sizeof(ses.newkeys->trans));
+		ses.newkeys->trans.valid = 0;
+	}
+	if (ses.kexstate.sentnewkeys && ses.kexstate.recvnewkeys)
+	{
+		TRACE(("switch_keys done"))
+		ses.keys->algo_kex = ses.newkeys->algo_kex;
+		ses.keys->algo_hostkey = ses.newkeys->algo_hostkey;
+		ses.keys->allow_compress = 0;
+		m_free(ses.newkeys);
+		ses.newkeys = NULL;
+		kexinitialise();
+	}
+	TRACE2(("leave switch_keys"))
+}
 
 /* Bring new keys into use after a key exchange, and let the client know*/
 void send_msg_newkeys() {
@@ -174,44 +202,25 @@
 	CHECKCLEARTOWRITE();
 	buf_putbyte(ses.writepayload, SSH_MSG_NEWKEYS);
 	encrypt_packet();
+
 	
-
 	/* set up our state */
-	if (ses.kexstate.recvnewkeys) {
-		TRACE(("while RECVNEWKEYS=1"))
-		gen_new_keys();
-		kexinitialise(); /* we've finished with this kex */
-		TRACE((" -> DATAALLOWED=1"))
-		ses.dataallowed = 1; /* we can send other packets again now */
-		ses.kexstate.donefirstkex = 1;
-	} else {
-		ses.kexstate.sentnewkeys = 1;
-		TRACE(("SENTNEWKEYS=1"))
-	}
+	ses.kexstate.sentnewkeys = 1;
+	ses.kexstate.donefirstkex = 1;
+	ses.dataallowed = 1; /* we can send other packets again now */
+	gen_new_keys();
+	switch_keys();
 
-	TRACE(("-> MSG_NEWKEYS"))
 	TRACE(("leave send_msg_newkeys"))
 }
 
 /* Bring the new keys into use after a key exchange */
 void recv_msg_newkeys() {
 
-	TRACE(("<- MSG_NEWKEYS"))
 	TRACE(("enter recv_msg_newkeys"))
 
-	/* simply check if we've sent SSH_MSG_NEWKEYS, and if so,
-	 * switch to the new keys */
-	if (ses.kexstate.sentnewkeys) {
-		TRACE(("while SENTNEWKEYS=1"))
-		gen_new_keys();
-		kexinitialise(); /* we've finished with this kex */
-	    TRACE((" -> DATAALLOWED=1"))
-	    ses.dataallowed = 1; /* we can send other packets again now */
-		ses.kexstate.donefirstkex = 1;
-	} else {
-		TRACE(("RECVNEWKEYS=1"))
-		ses.kexstate.recvnewkeys = 1;
-	}
+	ses.kexstate.recvnewkeys = 1;
+	switch_keys();
 	
 	TRACE(("leave recv_msg_newkeys"))
 }
@@ -293,8 +302,7 @@
  * ses.newkeys is the new set of keys which are generated, these are only
  * taken into use after both sides have sent a newkeys message */
 
-/* Originally from kex.c, generalized for cli/svr mode --mihnea */
-void gen_new_keys() {
+static void gen_new_keys() {
 
 	unsigned char C2S_IV[MAX_IV_LEN];
 	unsigned char C2S_key[MAX_KEY_LEN];
@@ -382,11 +390,9 @@
 	gen_new_zstreams();
 #endif
 	
-	/* Switch over to the new keys */
-	m_burn(ses.keys, sizeof(struct key_context));
-	m_free(ses.keys);
-	ses.keys = ses.newkeys;
-	ses.newkeys = NULL;
+	/* Ready to switch over */
+	ses.newkeys->trans.valid = 1;
+	ses.newkeys->recv.valid = 1;
 
 	m_burn(C2S_IV, sizeof(C2S_IV));
 	m_burn(C2S_key, sizeof(C2S_key));
diff -r 24172f555f9c -r d63ef1e211ea dbutil.c
--- a/dbutil.c	Wed Apr 03 23:54:58 2013 +0800
+++ b/dbutil.c	Thu Apr 04 00:18:50 2013 +0800
@@ -138,29 +138,39 @@
 
 #ifdef DEBUG_TRACE
 void dropbear_trace(const char* format, ...) {
-
 	va_list param;
+	struct timeval tv;
 
 	if (!debug_trace) {
 		return;
 	}
 
+	gettimeofday(&tv, NULL);
+
 	va_start(param, format);
-	fprintf(stderr, "TRACE (%d): ", getpid());
+	fprintf(stderr, "TRACE  (%d) %d.%d: ", getpid(), tv.tv_sec, tv.tv_usec);
 	vfprintf(stderr, format, param);
 	fprintf(stderr, "\n");
 	va_end(param);
 }
+
 void dropbear_trace2(const char* format, ...) {
-
+	static int trace_env = -1;
 	va_list param;
+	struct timeval tv;
 
-	if (!(debug_trace && getenv("DROPBEAR_TRACE2"))) {
+	if (trace_env == -1) {
+		trace_env = getenv("DROPBEAR_TRACE2") ? 1 : 0;
+	}
+
+	if (!(debug_trace && trace_env)) {
 		return;
 	}
 
+	gettimeofday(&tv, NULL);
+
 	va_start(param, format);
-	fprintf(stderr, "TRACE2 (%d): ", getpid());
+	fprintf(stderr, "TRACE2 (%d) %d.%d: ", getpid(), tv.tv_sec, tv.tv_usec);
 	vfprintf(stderr, format, param);
 	fprintf(stderr, "\n");
 	va_end(param);
@@ -739,8 +749,6 @@
 
 	int c = EOF;
 
-	TRACE2(("enter buf_getline"))
-
 	buf_setpos(line, 0);
 	buf_setlen(line, 0);
 
@@ -764,10 +772,8 @@
 
 	/* if we didn't read anything before EOF or error, exit */
 	if (c == EOF && line->pos == 0) {
-		TRACE2(("leave buf_getline: failure"))
 		return DROPBEAR_FAILURE;
 	} else {
-		TRACE2(("leave buf_getline: success"))
 		buf_setpos(line, 0);
 		return DROPBEAR_SUCCESS;
 	}
diff -r 24172f555f9c -r d63ef1e211ea packet.c
--- a/packet.c	Wed Apr 03 23:54:58 2013 +0800
+++ b/packet.c	Thu Apr 04 00:18:50 2013 +0800
@@ -505,8 +505,6 @@
 		/* During key exchange only particular packets are allowed.
 			Since this packet_type isn't OK we just enqueue it to send 
 			after the KEX, see maybe_flush_reply_queue */
-		TRACE2(("Delay sending reply packet. dataallowed %d, type %d, sentnewkeys %d",
-					ses.dataallowed, packet_type, ses.kexstate.sentnewkeys))
 		enqueue_reply_packet();
 		return;
 	}
diff -r 24172f555f9c -r d63ef1e211ea session.h
--- a/session.h	Wed Apr 03 23:54:58 2013 +0800
+++ b/session.h	Thu Apr 04 00:18:50 2013 +0800
@@ -78,6 +78,7 @@
 #endif
 	} cipher_state;
 	unsigned char mackey[MAX_MAC_LEN];
+	int valid;
 };
 
 struct key_context {