Move the more verbose TRACE() statements into TRACE2()

13 files changed, 64 insertions, 51 deletions

diff --git a/buffer.c b/buffer.c
index 13fa1ce..facee24 100644
--- a/buffer.c
+++ b/buffer.c
@@ -282,7 +282,7 @@ void buf_putbytes(buffer *buf, const unsigned char *bytes, unsigned int len) {
 void buf_putmpint(buffer* buf, mp_int * mp) {
 
 	unsigned int len, pad = 0;
-	TRACE(("enter buf_putmpint"))
+	TRACE2(("enter buf_putmpint"))
 
 	dropbear_assert(mp != NULL);
 
@@ -318,7 +318,7 @@ void buf_putmpint(buffer* buf, mp_int * mp) {
 		buf_incrwritepos(buf, len-pad);
 	}
 
-	TRACE(("leave buf_putmpint"))
+	TRACE2(("leave buf_putmpint"))
 }
 
 /* Retrieve an mp_int from the buffer.
diff --git a/cli-kex.c b/cli-kex.c
index 9dadb3c..e039071 100644
--- a/cli-kex.c
+++ b/cli-kex.c
@@ -246,7 +246,7 @@ static void checkhostkey(unsigned char* keyblob, unsigned int keybloblen) {
 		/* Compare hostnames */
 		if (strncmp(cli_opts.remotehost, buf_getptr(line, hostlen),
 					hostlen) != 0) {
-			TRACE(("hosts don't match"))
+			TRACE2(("hosts don't match"))
 			continue;
 		}
 
diff --git a/cli-session.c b/cli-session.c
index 81aa8c9..3adec73 100644
--- a/cli-session.c
+++ b/cli-session.c
@@ -172,7 +172,7 @@ static void recv_msg_service_accept(void) {
  * service, userauth and channel requests */
 static void cli_sessionloop() {
 
-	TRACE(("enter cli_sessionloop"))
+	TRACE2(("enter cli_sessionloop"))
 
 	if (ses.lastpacket == SSH_MSG_KEXINIT && cli_ses.kex_state == KEX_NOTHING) {
 		cli_ses.kex_state = KEXINIT_RCVD;
@@ -286,7 +286,7 @@ static void cli_sessionloop() {
 		break;
 	}
 
-	TRACE(("leave cli_sessionloop: fell out"))
+	TRACE2(("leave cli_sessionloop: fell out"))
 
 }
 
diff --git a/common-channel.c b/common-channel.c
index 05b9d11..331ea60 100644
--- a/common-channel.c
+++ b/common-channel.c
@@ -273,10 +273,10 @@ static unsigned int write_pending(struct Channel * channel) {
 static void check_close(struct Channel *channel) {
 	int close_allowed = 0;
 
-	TRACE(("check_close: writefd %d, readfd %d, errfd %d, sent_close %d, recv_close %d",
+	TRACE2(("check_close: writefd %d, readfd %d, errfd %d, sent_close %d, recv_close %d",
 				channel->writefd, channel->readfd,
 				channel->errfd, channel->sent_close, channel->recv_close))
-	TRACE(("writebuf size %d extrabuf size %d",
+	TRACE2(("writebuf size %d extrabuf size %d",
 				channel->writebuf ? cbuf_getused(channel->writebuf) : 0,
 				channel->extrabuf ? cbuf_getused(channel->extrabuf) : 0))
 
diff --git a/dbutil.c b/dbutil.c
index 044388a..8c48a24 100644
--- a/dbutil.c
+++ b/dbutil.c
@@ -151,6 +151,20 @@ void dropbear_trace(const char* format, ...) {
 	fprintf(stderr, "\n");
 	va_end(param);
 }
+void dropbear_trace2(const char* format, ...) {
+
+	va_list param;
+
+	if (!(debug_trace && getenv("DROPBEAR_TRACE2"))) {
+		return;
+	}
+
+	va_start(param, format);
+	fprintf(stderr, "TRACE2 (%d): ", getpid());
+	vfprintf(stderr, format, param);
+	fprintf(stderr, "\n");
+	va_end(param);
+}
 #endif /* DEBUG_TRACE */
 
 static void set_sock_priority(int sock) {
@@ -725,7 +739,7 @@ int buf_getline(buffer * line, FILE * authfile) {
 
 	int c = EOF;
 
-	TRACE(("enter buf_getline"))
+	TRACE2(("enter buf_getline"))
 
 	buf_setpos(line, 0);
 	buf_setlen(line, 0);
@@ -750,10 +764,10 @@ out:
 
 	/* if we didn't read anything before EOF or error, exit */
 	if (c == EOF && line->pos == 0) {
-		TRACE(("leave buf_getline: failure"))
+		TRACE2(("leave buf_getline: failure"))
 		return DROPBEAR_FAILURE;
 	} else {
-		TRACE(("leave buf_getline: success"))
+		TRACE2(("leave buf_getline: success"))
 		buf_setpos(line, 0);
 		return DROPBEAR_SUCCESS;
 	}
diff --git a/dbutil.h b/dbutil.h
index 0f16bf3..fc01251 100644
--- a/dbutil.h
+++ b/dbutil.h
@@ -57,6 +57,7 @@ void fail_assert(const char* expr, const char* file, int line) ATTRIB_NORETURN;
 
 #ifdef DEBUG_TRACE
 void dropbear_trace(const char* format, ...) ATTRIB_PRINTF(1,2);
+void dropbear_trace2(const char* format, ...) ATTRIB_PRINTF(1,2);
 void printhex(const char * label, const unsigned char * buf, int len);
 extern int debug_trace;
 #endif
diff --git a/debug.h b/debug.h
index b20e685..289c577 100644
--- a/debug.h
+++ b/debug.h
@@ -39,7 +39,7 @@
  * Caution: Don't use this in an unfriendly environment (ie unfirewalled),
  * since the printing may not sanitise strings etc. This will add a reasonable
  * amount to your executable size. */
-/*#define DEBUG_TRACE */
+/* #define DEBUG_TRACE */
 
 /* All functions writing to the cleartext payload buffer call
  * CHECKCLEARTOWRITE() before writing. This is only really useful if you're
@@ -63,8 +63,10 @@
 /* you don't need to touch this block */
 #ifdef DEBUG_TRACE
 #define TRACE(X) dropbear_trace X;
+#define TRACE2(X) dropbear_trace2 X;
 #else /*DEBUG_TRACE*/
 #define TRACE(X)
+#define TRACE2(X)
 #endif /*DEBUG_TRACE*/
 
 /* To debug with GDB it is easier to run with no forking of child processes.
diff --git a/dss.c b/dss.c
index d984669..75dc0d0 100644
--- a/dss.c
+++ b/dss.c
@@ -101,9 +101,9 @@ int buf_get_dss_priv_key(buffer* buf, dropbear_dss_key *key) {
 /* Clear and free the memory used by a public or private key */
 void dss_key_free(dropbear_dss_key *key) {
 
-	TRACE(("enter dsa_key_free"))
+	TRACE2(("enter dsa_key_free"))
 	if (key == NULL) {
-		TRACE(("enter dsa_key_free: key == NULL"))
+		TRACE2(("enter dsa_key_free: key == NULL"))
 		return;
 	}
 	if (key->p) {
@@ -127,7 +127,7 @@ void dss_key_free(dropbear_dss_key *key) {
 		m_free(key->x);
 	}
 	m_free(key);
-	TRACE(("leave dsa_key_free"))
+	TRACE2(("leave dsa_key_free"))
 }
 
 /* put the dss public key into the buffer in the required format:
diff --git a/packet.c b/packet.c
index 5cd60c2..4a3a53a 100644
--- a/packet.c
+++ b/packet.c
@@ -62,7 +62,7 @@ void write_packet() {
 	struct Link *l;
 #endif
 	
-	TRACE(("enter write_packet"))
+	TRACE2(("enter write_packet"))
 	dropbear_assert(!isempty(&ses.writequeue));
 
 #ifdef HAVE_WRITEV
@@ -81,7 +81,7 @@ void write_packet() {
 	if (written < 0) {
 		if (errno == EINTR) {
 			m_free(iov);
-			TRACE(("leave writepacket: EINTR"))
+			TRACE2(("leave writepacket: EINTR"))
 			return;
 		} else {
 			dropbear_exit("Error writing");
@@ -122,7 +122,7 @@ void write_packet() {
 
 	if (written < 0) {
 		if (errno == EINTR) {
-			TRACE(("leave writepacket: EINTR"))
+			TRACE2(("leave writepacket: EINTR"))
 			return;
 		} else {
 			dropbear_exit("Error writing");
@@ -152,7 +152,7 @@ void write_packet() {
 		ses.last_packet_time = now;
 	}
 
-	TRACE(("leave write_packet"))
+	TRACE2(("leave write_packet"))
 }
 
 /* Non-blocking function reading available portion of a packet into the
@@ -164,7 +164,7 @@ void read_packet() {
 	unsigned int maxlen;
 	unsigned char blocksize;
 
-	TRACE(("enter read_packet"))
+	TRACE2(("enter read_packet"))
 	blocksize = ses.keys->recv.algo_crypt->blocksize;
 	
 	if (ses.readbuf == NULL || ses.readbuf->len < blocksize) {
@@ -177,7 +177,7 @@ void read_packet() {
 
 		if (ret == DROPBEAR_FAILURE) {
 			/* didn't read enough to determine the length */
-			TRACE(("leave read_packet: packetinit done"))
+			TRACE2(("leave read_packet: packetinit done"))
 			return;
 		}
 	}
@@ -199,7 +199,7 @@ void read_packet() {
 
 		if (len < 0) {
 			if (errno == EINTR || errno == EAGAIN) {
-				TRACE(("leave read_packet: EINTR or EAGAIN"))
+				TRACE2(("leave read_packet: EINTR or EAGAIN"))
 				return;
 			} else {
 				dropbear_exit("Error reading: %s", strerror(errno));
@@ -215,7 +215,7 @@ void read_packet() {
 		/* The main select() loop process_packet() to
 		 * handle the packet contents... */
 	}
-	TRACE(("leave read_packet"))
+	TRACE2(("leave read_packet"))
 }
 
 /* Function used to read the initial portion of a packet, and determine the
@@ -249,7 +249,7 @@ static int read_packet_init() {
 	}
 	if (slen < 0) {
 		if (errno == EINTR) {
-			TRACE(("leave read_packet_init: EINTR"))
+			TRACE2(("leave read_packet_init: EINTR"))
 			return DROPBEAR_FAILURE;
 		}
 		dropbear_exit("Error reading: %s", strerror(errno));
@@ -273,7 +273,7 @@ static int read_packet_init() {
 	}
 	len = buf_getint(ses.readbuf) + 4 + macsize;
 
-	TRACE(("packet size is %d, block %d mac %d", len, blocksize, macsize))
+	TRACE2(("packet size is %d, block %d mac %d", len, blocksize, macsize))
 
 
 	/* check packet length */
@@ -299,7 +299,7 @@ void decrypt_packet() {
 	unsigned int padlen;
 	unsigned int len;
 
-	TRACE(("enter decrypt_packet"))
+	TRACE2(("enter decrypt_packet"))
 	blocksize = ses.keys->recv.algo_crypt->blocksize;
 	macsize = ses.keys->recv.algo_mac->hashsize;
 
@@ -356,7 +356,7 @@ void decrypt_packet() {
 
 	ses.recvseq++;
 
-	TRACE(("leave decrypt_packet"))
+	TRACE2(("leave decrypt_packet"))
 }
 
 /* Checks the mac at the end of a decrypted readbuf.
@@ -455,7 +455,7 @@ static void enqueue_reply_packet() {
 		ses.reply_queue_head = new_item;
 	}
 	ses.reply_queue_tail = new_item;
-	TRACE(("leave enqueue_reply_packet"))
+	TRACE2(("leave enqueue_reply_packet"))
 }
 
 void maybe_flush_reply_queue() {
@@ -492,13 +492,13 @@ void encrypt_packet() {
 	unsigned int len, encrypt_buf_size;
 	unsigned char mac_bytes[MAX_MAC_LEN];
 	
-	TRACE(("enter encrypt_packet()"))
+	TRACE2(("enter encrypt_packet()"))
 
 	buf_setpos(ses.writepayload, 0);
 	packet_type = buf_getbyte(ses.writepayload);
 	buf_setpos(ses.writepayload, 0);
 
-	TRACE(("encrypt_packet type is %d", packet_type))
+	TRACE2(("encrypt_packet type is %d", packet_type))
 	
 	if ((!ses.dataallowed && !packet_is_okay_kex(packet_type))
 			|| ses.kexstate.sentnewkeys) {
@@ -611,7 +611,7 @@ void encrypt_packet() {
 	ses.kexstate.datatrans += writebuf->len;
 	ses.transseq++;
 
-	TRACE(("leave encrypt_packet()"))
+	TRACE2(("leave encrypt_packet()"))
 }
 
 
@@ -624,8 +624,6 @@ static void make_mac(unsigned int seqno, const struct key_context_directional *
 	unsigned long bufsize;
 	hmac_state hmac;
 
-	TRACE(("enter writemac"))
-
 	if (key_state->algo_mac->hashsize > 0) {
 		/* calculate the mac */
 		if (hmac_init(&hmac, 
@@ -654,7 +652,7 @@ static void make_mac(unsigned int seqno, const struct key_context_directional *
 			dropbear_exit("HMAC error");
 		}
 	}
-	TRACE(("leave writemac"))
+	TRACE2(("leave writemac"))
 }
 
 #ifndef DISABLE_ZLIB
@@ -665,7 +663,7 @@ static void buf_compress(buffer * dest, buffer * src, unsigned int len) {
 	unsigned int endpos = src->pos + len;
 	int result;
 
-	TRACE(("enter buf_compress"))
+	TRACE2(("enter buf_compress"))
 
 	while (1) {
 
@@ -699,6 +697,6 @@ static void buf_compress(buffer * dest, buffer * src, unsigned int len) {
 		buf_resize(dest, dest->size + ZLIB_COMPRESS_INCR);
 
 	}
-	TRACE(("leave buf_compress"))
+	TRACE2(("leave buf_compress"))
 }
 #endif
diff --git a/process-packet.c b/process-packet.c
index 2ae410d..384e449 100644
--- a/process-packet.c
+++ b/process-packet.c
@@ -45,7 +45,7 @@ void process_packet() {
 	unsigned char type;
 	unsigned int i;
 
-	TRACE(("enter process_packet"))
+	TRACE2(("enter process_packet"))
 
 	type = buf_getbyte(ses.payload);
 	TRACE(("process_packet: packet type = %d", type))
@@ -123,7 +123,7 @@ out:
 	buf_free(ses.payload);
 	ses.payload = NULL;
 
-	TRACE(("leave process_packet"))
+	TRACE2(("leave process_packet"))
 }
 
 
diff --git a/queue.c b/queue.c
index 7a80124..9d00808 100644
--- a/queue.c
+++ b/queue.c
@@ -70,7 +70,6 @@ void enqueue(struct Queue* queue, void* item) {
 
 	struct Link* newlink;
 
-	TRACE(("enter enqueue"))
 	newlink = (struct Link*)m_malloc(sizeof(struct Link));
 
 	newlink->item = item;
@@ -85,5 +84,4 @@ void enqueue(struct Queue* queue, void* item) {
 		queue->head = newlink;
 	}
 	queue->count++;
-	TRACE(("leave enqueue"))
 }
diff --git a/rsa.c b/rsa.c
index 91bf59d..520ad84 100644
--- a/rsa.c
+++ b/rsa.c
@@ -139,10 +139,10 @@ out:
 /* Clear and free the memory used by a public or private key */
 void rsa_key_free(dropbear_rsa_key *key) {
 
-	TRACE(("enter rsa_key_free"))
+	TRACE2(("enter rsa_key_free"))
 
 	if (key == NULL) {
-		TRACE(("leave rsa_key_free: key == NULL"))
+		TRACE2(("leave rsa_key_free: key == NULL"))
 		return;
 	}
 	if (key->d) {
@@ -166,7 +166,7 @@ void rsa_key_free(dropbear_rsa_key *key) {
 		m_free(key->q);
 	}
 	m_free(key);
-	TRACE(("leave rsa_key_free"))
+	TRACE2(("leave rsa_key_free"))
 }
 
 /* Put the public rsa key into the buffer in the required format:
diff --git a/signkey.c b/signkey.c
index 1d908f4..f647990 100644
--- a/signkey.c
+++ b/signkey.c
@@ -98,7 +98,7 @@ int buf_get_pub_key(buffer *buf, sign_key *key, int *type) {
 	int keytype;
 	int ret = DROPBEAR_FAILURE;
 
-	TRACE(("enter buf_get_pub_key"))
+	TRACE2(("enter buf_get_pub_key"))
 
 	ident = buf_getstring(buf, &len);
 	keytype = signkey_type_from_name(ident, len);
@@ -109,7 +109,7 @@ int buf_get_pub_key(buffer *buf, sign_key *key, int *type) {
 		return DROPBEAR_FAILURE;
 	}
 	
-	TRACE(("buf_get_pub_key keytype is %d", keytype))
+	TRACE2(("buf_get_pub_key keytype is %d", keytype))
 
 	*type = keytype;
 
@@ -137,7 +137,7 @@ int buf_get_pub_key(buffer *buf, sign_key *key, int *type) {
 	}
 #endif
 
-	TRACE(("leave buf_get_pub_key"))
+	TRACE2(("leave buf_get_pub_key"))
 
 	return ret;
 	
@@ -153,7 +153,7 @@ int buf_get_priv_key(buffer *buf, sign_key *key, int *type) {
 	int keytype;
 	int ret = DROPBEAR_FAILURE;
 
-	TRACE(("enter buf_get_priv_key"))
+	TRACE2(("enter buf_get_priv_key"))
 
 	ident = buf_getstring(buf, &len);
 	keytype = signkey_type_from_name(ident, len);
@@ -190,7 +190,7 @@ int buf_get_priv_key(buffer *buf, sign_key *key, int *type) {
 	}
 #endif
 
-	TRACE(("leave buf_get_priv_key"))
+	TRACE2(("leave buf_get_priv_key"))
 
 	return ret;
 	
@@ -201,7 +201,7 @@ void buf_put_pub_key(buffer* buf, sign_key *key, int type) {
 
 	buffer *pubkeys;
 
-	TRACE(("enter buf_put_pub_key"))
+	TRACE2(("enter buf_put_pub_key"))
 	pubkeys = buf_new(MAX_PUBKEY_SIZE);
 	
 #ifdef DROPBEAR_DSS
@@ -223,7 +223,7 @@ void buf_put_pub_key(buffer* buf, sign_key *key, int type) {
 			pubkeys->len);
 	
 	buf_free(pubkeys);
-	TRACE(("leave buf_put_pub_key"))
+	TRACE2(("leave buf_put_pub_key"))
 }
 
 /* type is either DROPBEAR_SIGNKEY_DSS or DROPBEAR_SIGNKEY_RSA */
@@ -251,7 +251,7 @@ void buf_put_priv_key(buffer* buf, sign_key *key, int type) {
 
 void sign_key_free(sign_key *key) {
 
-	TRACE(("enter sign_key_free"))
+	TRACE2(("enter sign_key_free"))
 
 #ifdef DROPBEAR_DSS
 	dss_key_free(key->dsskey);
@@ -265,7 +265,7 @@ void sign_key_free(sign_key *key) {
 	m_free(key->filename);
 
 	m_free(key);
-	TRACE(("leave sign_key_free"))
+	TRACE2(("leave sign_key_free"))
 }
 
 static char hexdig(unsigned char x) {