Merge pull request #152 from HansH111/tracelevel2

13 files changed, 126 insertions, 66 deletions

diff --git a/cli-auth.c b/cli-auth.c
index 49b5ed8..9f9639d 100644
--- a/cli-auth.c
+++ b/cli-auth.c
@@ -85,32 +85,31 @@ void recv_msg_userauth_banner() {
 	banner = buf_getstring(ses.payload, &bannerlen);
 	buf_eatstring(ses.payload); /* The language string */
 
-	if (cli_opts.quiet == 0) {
-		if (bannerlen > MAX_BANNER_SIZE) {
-			TRACE(("recv_msg_userauth_banner: bannerlen too long: %d", bannerlen))
-			truncated = 1;
-		} else {
-			cleantext(banner);
-
-			/* Limit to 24 lines */
-			linecount = 1;
-			for (i = 0; i < bannerlen; i++) {
-				if (banner[i] == '\n') {
-					if (linecount >= MAX_BANNER_LINES) {
-						banner[i] = '\0';
-						truncated = 1;
-						break;
-					}
-					linecount++;
+	if (bannerlen > MAX_BANNER_SIZE) {
+		TRACE(("recv_msg_userauth_banner: bannerlen too long: %d", bannerlen))
+		truncated = 1;
+	} else {
+		cleantext(banner);
+
+		/* Limit to 24 lines */
+		linecount = 1;
+		for (i = 0; i < bannerlen; i++) {
+			if (banner[i] == '\n') {
+				if (linecount >= MAX_BANNER_LINES) {
+					banner[i] = '\0';
+					truncated = 1;
+					break;
 				}
+				linecount++;
 			}
-			fprintf(stderr, "%s\n", banner);
 		}
+		fprintf(stderr, "%s\n", banner);
+	}
 
-		if (truncated) {
-			fprintf(stderr, "[Banner from the server is too long]\n");
-		}
+	if (truncated) {
+		fprintf(stderr, "[Banner from the server is too long]\n");
 	}
+
 	m_free(banner);
 	TRACE(("leave recv_msg_userauth_banner"))
 }
@@ -261,7 +260,7 @@ void recv_msg_userauth_success() {
 	/* This function can validly get called multiple times
 	if DROPBEAR_CLI_IMMEDIATE_AUTH is set */
 
-	TRACE(("received msg_userauth_success"))
+	DEBUG1(("received msg_userauth_success"))
 	if (cli_opts.disable_trivial_auth && cli_ses.is_trivial_auth) {
 		dropbear_exit("trivial authentication not allowed");
 	}
diff --git a/cli-authpasswd.c b/cli-authpasswd.c
index a24d43e..91790ce 100644
--- a/cli-authpasswd.c
+++ b/cli-authpasswd.c
@@ -120,7 +120,7 @@ void cli_auth_password() {
 	char* password = NULL;
 	char prompt[80];
 
-	TRACE(("enter cli_auth_password"))
+	DEBUG1(("enter cli_auth_password"))
 	CHECKCLEARTOWRITE();
 
 	snprintf(prompt, sizeof(prompt), "%s@%s's password: ", 
diff --git a/cli-authpubkey.c b/cli-authpubkey.c
index c0da77f..975d3bd 100644
--- a/cli-authpubkey.c
+++ b/cli-authpubkey.c
@@ -147,7 +147,7 @@ static void send_msg_userauth_pubkey(sign_key *key, enum signature_type sigtype,
 	buffer* sigbuf = NULL;
 	enum signkey_type keytype = signkey_type_from_signature(sigtype);
 
-	TRACE(("enter send_msg_userauth_pubkey sigtype %d", sigtype))
+	DEBUG1(("enter send_msg_userauth_pubkey %s", signature_name_from_type(sigtype, NULL)))
 	CHECKCLEARTOWRITE();
 
 	buf_putbyte(ses.writepayload, SSH_MSG_USERAUTH_REQUEST);
diff --git a/cli-main.c b/cli-main.c
index b571b90..065fd76 100644
--- a/cli-main.c
+++ b/cli-main.c
@@ -65,8 +65,12 @@ int main(int argc, char ** argv) {
 	}
 #endif
 
-	TRACE(("user='%s' host='%s' port='%s' bind_address='%s' bind_port='%s'", cli_opts.username,
-				cli_opts.remotehost, cli_opts.remoteport, cli_opts.bind_address, cli_opts.bind_port))
+        if (cli_opts.bind_address) {
+		DEBUG1(("connect to: user=%s host=%s/%s bind_address=%s:%s", cli_opts.username,
+			cli_opts.remotehost, cli_opts.remoteport, cli_opts.bind_address, cli_opts.bind_port))
+	} else {
+		DEBUG1(("connect to: user=%s host=%s/%s",cli_opts.username,cli_opts.remotehost,cli_opts.remoteport))
+	}
 
 	if (signal(SIGPIPE, SIG_IGN) == SIG_ERR) {
 		dropbear_exit("signal() error");
@@ -135,6 +139,7 @@ static void cli_proxy_cmd(int *sock_in, int *sock_out, pid_t *pid_out) {
 
 	ret = spawn_command(exec_proxy_cmd, ex_cmd,
 			sock_out, sock_in, NULL, pid_out);
+	DEBUG1(("cmd: %s  pid=%d", ex_cmd,*pid_out))
 	m_free(ex_cmd);
 	if (ret == DROPBEAR_FAILURE) {
 		dropbear_exit("Failed running proxy command");
diff --git a/cli-runopts.c b/cli-runopts.c
index cbd15b3..c91f668 100644
--- a/cli-runopts.c
+++ b/cli-runopts.c
@@ -96,7 +96,7 @@ static void printhelp() {
 					"-b    [bind_address][:bind_port]\n"
 					"-V    Version\n"
 #if DEBUG_TRACE
-					"-v    verbose (compiled with DEBUG_TRACE)\n"
+					"-v    verbose (repeat for more verbose)\n"
 #endif
 					,DROPBEAR_VERSION, cli_opts.progname,
 #if DROPBEAR_CLI_PUBKEY_AUTH
@@ -302,7 +302,7 @@ void cli_getopts(int argc, char ** argv) {
 #endif
 #if DEBUG_TRACE
 				case 'v':
-					debug_trace = 1;
+					debug_trace++;
 					break;
 #endif
 				case 'F':
diff --git a/cli-session.c b/cli-session.c
index 2044b46..5981b24 100644
--- a/cli-session.c
+++ b/cli-session.c
@@ -102,7 +102,7 @@ void cli_connected(int result, int sock, void* userdata, const char *errstring)
 		dropbear_exit("Connect failed: %s", errstring);
 	}
 	myses->sock_in = myses->sock_out = sock;
-	TRACE(("cli_connected"))
+	DEBUG1(("cli_connected"))
 	ses.socket_prio = DROPBEAR_PRIO_NORMAL;
 	/* switches to lowdelay */
 	update_channel_prio();
diff --git a/common-algo.c b/common-algo.c
index abb7335..275969e 100644
--- a/common-algo.c
+++ b/common-algo.c
@@ -463,7 +463,7 @@ algo_type * buf_match_algo(buffer* buf, algo_type localalgos[],
 
 	/* get the comma-separated list from the buffer ie "algo1,algo2,algo3" */
 	algolist = buf_getstring(buf, &len);
-	TRACE(("buf_match_algo: %s", algolist))
+	DEBUG3(("buf_match_algo: %s", algolist))
 	remotecount = MAX_PROPOSED_ALGO;
 	get_algolist(algolist, len, remotenames, &remotecount);
 
diff --git a/common-kex.c b/common-kex.c
index 39d916b..41384d0 100644
--- a/common-kex.c
+++ b/common-kex.c
@@ -869,7 +869,7 @@ static void read_kex_algos() {
 		goto error;
 	}
 	TRACE(("kexguess2 %d", kexguess2))
-	TRACE(("kex algo %s", algo->name))
+	DEBUG3(("kex algo %s", algo->name))
 	ses.newkeys->algo_kex = algo->data;
 
 	/* server_host_key_algorithms */
@@ -879,7 +879,7 @@ static void read_kex_algos() {
 		erralgo = "hostkey";
 		goto error;
 	}
-	TRACE(("signature algo %s", algo->name))
+	DEBUG2(("hostkey algo %s", algo->name))
 	ses.newkeys->algo_signature = algo->val;
 	ses.newkeys->algo_hostkey = signkey_type_from_signature(ses.newkeys->algo_signature);
 
@@ -889,7 +889,7 @@ static void read_kex_algos() {
 		erralgo = "enc c->s";
 		goto error;
 	}
-	TRACE(("enc c2s is  %s", c2s_cipher_algo->name))
+	DEBUG2(("enc  c2s is %s", c2s_cipher_algo->name))
 
 	/* encryption_algorithms_server_to_client */
 	s2c_cipher_algo = buf_match_algo(ses.payload, sshciphers, 0, NULL);
@@ -897,7 +897,7 @@ static void read_kex_algos() {
 		erralgo = "enc s->c";
 		goto error;
 	}
-	TRACE(("enc s2c is  %s", s2c_cipher_algo->name))
+	DEBUG2(("enc  s2c is %s", s2c_cipher_algo->name))
 
 	/* mac_algorithms_client_to_server */
 	c2s_hash_algo = buf_match_algo(ses.payload, sshhashes, 0, NULL);
@@ -910,7 +910,7 @@ static void read_kex_algos() {
 		erralgo = "mac c->s";
 		goto error;
 	}
-	TRACE(("hash c2s is  %s", c2s_hash_algo ? c2s_hash_algo->name : "<implicit>"))
+	DEBUG2(("hmac c2s is %s", c2s_hash_algo ? c2s_hash_algo->name : "<implicit>"))
 
 	/* mac_algorithms_server_to_client */
 	s2c_hash_algo = buf_match_algo(ses.payload, sshhashes, 0, NULL);
@@ -923,7 +923,7 @@ static void read_kex_algos() {
 		erralgo = "mac s->c";
 		goto error;
 	}
-	TRACE(("hash s2c is  %s", s2c_hash_algo ? s2c_hash_algo->name : "<implicit>"))
+	DEBUG2(("hmac s2c is %s", s2c_hash_algo ? s2c_hash_algo->name : "<implicit>"))
 
 	/* compression_algorithms_client_to_server */
 	c2s_comp_algo = buf_match_algo(ses.payload, ses.compress_algos, 0, NULL);
@@ -931,7 +931,7 @@ static void read_kex_algos() {
 		erralgo = "comp c->s";
 		goto error;
 	}
-	TRACE(("hash c2s is  %s", c2s_comp_algo->name))
+	DEBUG2(("comp c2s is %s", c2s_comp_algo->name))
 
 	/* compression_algorithms_server_to_client */
 	s2c_comp_algo = buf_match_algo(ses.payload, ses.compress_algos, 0, NULL);
@@ -939,7 +939,7 @@ static void read_kex_algos() {
 		erralgo = "comp s->c";
 		goto error;
 	}
-	TRACE(("hash s2c is  %s", s2c_comp_algo->name))
+	DEBUG2(("comp s2c is %s", s2c_comp_algo->name))
 
 	/* languages_client_to_server */
 	buf_eatstring(ses.payload);
diff --git a/common-session.c b/common-session.c
index 3d406b1..5b61920 100644
--- a/common-session.c
+++ b/common-session.c
@@ -404,7 +404,7 @@ static void read_session_identification() {
 		dropbear_exit("Incompatible remote version '%s'", ses.remoteident);
 	}
 
-	TRACE(("remoteident: %s", ses.remoteident))
+	DEBUG1(("remoteident: %s", ses.remoteident))
 
 }
 
diff --git a/dbutil.c b/dbutil.c
index adb87c5..1bd753c 100644
--- a/dbutil.c
+++ b/dbutil.c
@@ -155,7 +155,7 @@ void dropbear_log(int priority, const char* format, ...) {
 }
 
 
-#if DEBUG_TRACE
+#if DEBUG_TRACE 
 
 static double debug_start_time = -1;
 
@@ -185,39 +185,63 @@ static double time_since_start()
 	return nowf - debug_start_time;
 }
 
-void dropbear_trace(const char* format, ...) {
-	va_list param;
-
-	if (!debug_trace) {
+static void dropbear_tracelevel(int level, const char *format, va_list param)
+{
+	if (debug_trace == 0 || debug_trace < level) {
 		return;
 	}
 
-	va_start(param, format);
-	fprintf(stderr, "TRACE  (%d) %f: ", getpid(), time_since_start());
+	fprintf(stderr, "TRACE%d (%d) %f: ", level, getpid(), time_since_start());
 	vfprintf(stderr, format, param);
 	fprintf(stderr, "\n");
-	va_end(param);
 }
+#if (DEBUG_TRACE>=1)
+void dropbear_trace1(const char* format, ...) {
+	va_list param;
 
+	va_start(param, format);
+	dropbear_tracelevel(1, format, param);
+	va_end(param);
+}
+#endif
+#if (DEBUG_TRACE>=2)
 void dropbear_trace2(const char* format, ...) {
-	static int trace_env = -1;
 	va_list param;
 
-	if (trace_env == -1) {
-		trace_env = getenv("DROPBEAR_TRACE2") ? 1 : 0;
-	}
+	va_start(param, format);
+	dropbear_tracelevel(2, format, param);
+	va_end(param);
+}
+#endif
+#if (DEBUG_TRACE>=3)
+void dropbear_trace3(const char* format, ...) {
+	va_list param;
 
-	if (!(debug_trace && trace_env)) {
-		return;
-	}
+	va_start(param, format);
+	dropbear_tracelevel(3, format, param);
+	va_end(param);
+}
+#endif
+#if (DEBUG_TRACE>=4)
+void dropbear_trace4(const char* format, ...) {
+	va_list param;
 
 	va_start(param, format);
-	fprintf(stderr, "TRACE2 (%d) %f: ", getpid(), time_since_start());
-	vfprintf(stderr, format, param);
-	fprintf(stderr, "\n");
+	dropbear_tracelevel(4, format, param);
 	va_end(param);
 }
-#endif /* DEBUG_TRACE */
+#endif
+#if (DEBUG_TRACE>=5)
+void dropbear_trace5(const char* format, ...) {
+	va_list param;
+
+	va_start(param, format);
+	dropbear_tracelevel(5, format, param);
+	va_end(param);
+}
+#endif
+#endif
+
 
 /* Connect to a given unix socket. The socket is blocking */
 #if ENABLE_CONNECT_UNIX
diff --git a/dbutil.h b/dbutil.h
index 87cd69d..c2d384a 100644
--- a/dbutil.h
+++ b/dbutil.h
@@ -47,8 +47,11 @@ void dropbear_log(int priority, const char* format, ...) ATTRIB_PRINTF(2,3) ;
 void fail_assert(const char* expr, const char* file, int line) ATTRIB_NORETURN;
 
 #if DEBUG_TRACE
-void dropbear_trace(const char* format, ...) ATTRIB_PRINTF(1,2);
+void dropbear_trace1(const char* format, ...) ATTRIB_PRINTF(1,2);
 void dropbear_trace2(const char* format, ...) ATTRIB_PRINTF(1,2);
+void dropbear_trace3(const char* format, ...) ATTRIB_PRINTF(1,2);
+void dropbear_trace4(const char* format, ...) ATTRIB_PRINTF(1,2);
+void dropbear_trace5(const char* format, ...) ATTRIB_PRINTF(1,2);
 void printhex(const char * label, const unsigned char * buf, int len);
 void printmpint(const char *label, mp_int *mp);
 void debug_start_net(void);
diff --git a/debug.h b/debug.h
index e1739e8..fcc0367 100644
--- a/debug.h
+++ b/debug.h
@@ -48,15 +48,41 @@
 /*#define DEBUG_KEXHASH*/
 /*#define DEBUG_RSA*/
 
-/* you don't need to touch this block */
+
 #if DEBUG_TRACE
 extern int debug_trace;
-#define TRACE(X) dropbear_trace X;
-#define TRACE2(X) dropbear_trace2 X;
-#else /*DEBUG_TRACE*/
+#endif
+
+/* Enable debug trace levels.
+   We can't use __VA_ARGS_ here because Dropbear supports 
+   old ~C89 compilers */
+/* Default is to discard output ... */
+#define DEBUG1(X)
+#define DEBUG2(X)
+#define DEBUG3(X)
 #define TRACE(X)
 #define TRACE2(X)
-#endif /*DEBUG_TRACE*/
+/* ... unless DEBUG_TRACE is high enough */
+#if (DEBUG_TRACE>=1)
+#undef DEBUG1
+#define DEBUG1(X) dropbear_trace1 X;
+#endif
+#if (DEBUG_TRACE>=2)
+#undef DEBUG2
+#define DEBUG2(X) dropbear_trace2 X;
+#endif
+#if (DEBUG_TRACE>=3)
+#undef DEBUG3
+#define DEBUG3(X) dropbear_trace3 X;
+#endif
+#if (DEBUG_TRACE>=4)
+#undef TRACE
+#define TRACE(X) dropbear_trace4 X;
+#endif
+#if (DEBUG_TRACE>=5)
+#undef TRACE2
+#define TRACE2(X) dropbear_trace5 X;
+#endif
 
 /* To debug with GDB it is easier to run with no forking of child processes.
    You will need to pass "-F" as well. */
diff --git a/default_options.h b/default_options.h
index aa9df78..d37b1d8 100644
--- a/default_options.h
+++ b/default_options.h
@@ -44,8 +44,11 @@ IMPORTANT: Some options will require "make clean" after changes */
    This option is ignored on non-Linux platforms at present */
 #define DROPBEAR_REEXEC 1
 
-/* Include verbose debug output, enabled with -v at runtime.
- * This will add a reasonable amount to your executable size. */
+/* Include verbose debug output, enabled with -v at runtime (repeat to increase).
+ * define which level of debug output you compile in
+ * TRACE1 - TRACE3 = approx 4 Kb (connection, remote identity, algos, auth type info)
+ * TRACE4 = approx 17 Kb (detailed before connection)
+ * TRACE5 = approx 8 Kb (detailed after connection) */
 #define DEBUG_TRACE 0
 
 /* Set this if you want to use the DROPBEAR_SMALL_CODE option. This can save