From c6053543f288f503b39e946ef58bfcd59f935b5f Mon Sep 17 00:00:00 2001
From: Jeff King <peff@peff.net>
Date: Thu, 24 Feb 2011 09:28:15 -0500
Subject: [PATCH 1/6] trace: add trace_vprintf

This is a necessary cleanup to adding new types of trace
functions.

Signed-off-by: Jeff King <peff@peff.net>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
---
 cache.h |  1 +
 trace.c | 14 +++++++++-----
 2 files changed, 10 insertions(+), 5 deletions(-)

diff --git a/cache.h b/cache.h
index 4a758babec..08b23b2ab9 100644
--- a/cache.h
+++ b/cache.h
@@ -1067,6 +1067,7 @@ extern void alloc_report(void);
 /* trace.c */
 __attribute__((format (printf, 1, 2)))
 extern void trace_printf(const char *format, ...);
+extern void trace_vprintf(const char *format, va_list ap);
 __attribute__((format (printf, 2, 3)))
 extern void trace_argv_printf(const char **argv, const char *format, ...);
 extern void trace_repo_setup(const char *prefix);
diff --git a/trace.c b/trace.c
index eda3f6d721..623e793e4f 100644
--- a/trace.c
+++ b/trace.c
@@ -62,10 +62,9 @@ static int get_trace_fd(int *need_close)
 static const char err_msg[] = "Could not trace into fd given by "
 	"GIT_TRACE environment variable";
 
-void trace_printf(const char *fmt, ...)
+void trace_vprintf(const char *fmt, va_list ap)
 {
 	struct strbuf buf = STRBUF_INIT;
-	va_list ap;
 	int fd, need_close = 0;
 
 	fd = get_trace_fd(&need_close);
@@ -73,10 +72,7 @@ void trace_printf(const char *fmt, ...)
 		return;
 
 	set_try_to_free_routine(NULL);	/* is never reset */
-	va_start(ap, fmt);
 	strbuf_vaddf(&buf, fmt, ap);
-	va_end(ap);
-
 	write_or_whine_pipe(fd, buf.buf, buf.len, err_msg);
 	strbuf_release(&buf);
 
@@ -84,6 +80,14 @@ void trace_printf(const char *fmt, ...)
 		close(fd);
 }
 
+void trace_printf(const char *fmt, ...)
+{
+	va_list ap;
+	va_start(ap, fmt);
+	trace_vprintf(fmt, ap);
+	va_end(ap);
+}
+
 void trace_argv_printf(const char **argv, const char *fmt, ...)
 {
 	struct strbuf buf = STRBUF_INIT;

From 06796607ef557e8913f1797cca3c98ce4844c36c Mon Sep 17 00:00:00 2001
From: Jeff King <peff@peff.net>
Date: Thu, 24 Feb 2011 09:28:41 -0500
Subject: [PATCH 2/6] trace: refactor to support multiple env variables

Right now you turn all tracing off and on with GIT_TRACE. To
support new types of tracing without forcing the user to see
all of them, we will soon support turning each tracing area
on with GIT_TRACE_*.

This patch lays the groundwork by providing an interface
which does not assume GIT_TRACE. However, we still maintain
the trace_printf interface so that existing callers do not
need to be refactored.

Signed-off-by: Jeff King <peff@peff.net>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
---
 cache.h |  2 +-
 trace.c | 28 ++++++++++++++++++----------
 2 files changed, 19 insertions(+), 11 deletions(-)

diff --git a/cache.h b/cache.h
index 08b23b2ab9..2ab1bf9383 100644
--- a/cache.h
+++ b/cache.h
@@ -1067,7 +1067,7 @@ extern void alloc_report(void);
 /* trace.c */
 __attribute__((format (printf, 1, 2)))
 extern void trace_printf(const char *format, ...);
-extern void trace_vprintf(const char *format, va_list ap);
+extern void trace_vprintf(const char *key, const char *format, va_list ap);
 __attribute__((format (printf, 2, 3)))
 extern void trace_argv_printf(const char **argv, const char *format, ...);
 extern void trace_repo_setup(const char *prefix);
diff --git a/trace.c b/trace.c
index 623e793e4f..1d0e17e014 100644
--- a/trace.c
+++ b/trace.c
@@ -25,10 +25,10 @@
 #include "cache.h"
 #include "quote.h"
 
-/* Get a trace file descriptor from GIT_TRACE env variable. */
-static int get_trace_fd(int *need_close)
+/* Get a trace file descriptor from "key" env variable. */
+static int get_trace_fd(const char *key, int *need_close)
 {
-	char *trace = getenv("GIT_TRACE");
+	char *trace = getenv(key);
 
 	if (!trace || !strcmp(trace, "") ||
 	    !strcmp(trace, "0") || !strcasecmp(trace, "false"))
@@ -50,10 +50,10 @@ static int get_trace_fd(int *need_close)
 		return fd;
 	}
 
-	fprintf(stderr, "What does '%s' for GIT_TRACE mean?\n", trace);
+	fprintf(stderr, "What does '%s' for %s mean?\n", trace, key);
 	fprintf(stderr, "If you want to trace into a file, "
-		"then please set GIT_TRACE to an absolute pathname "
-		"(starting with /).\n");
+		"then please set %s to an absolute pathname "
+		"(starting with /).\n", key);
 	fprintf(stderr, "Defaulting to tracing on stderr...\n");
 
 	return STDERR_FILENO;
@@ -62,12 +62,12 @@ static int get_trace_fd(int *need_close)
 static const char err_msg[] = "Could not trace into fd given by "
 	"GIT_TRACE environment variable";
 
-void trace_vprintf(const char *fmt, va_list ap)
+void trace_vprintf(const char *key, const char *fmt, va_list ap)
 {
 	struct strbuf buf = STRBUF_INIT;
 	int fd, need_close = 0;
 
-	fd = get_trace_fd(&need_close);
+	fd = get_trace_fd(key, &need_close);
 	if (!fd)
 		return;
 
@@ -80,11 +80,19 @@ void trace_vprintf(const char *fmt, va_list ap)
 		close(fd);
 }
 
+void trace_printf_key(const char *key, const char *fmt, ...)
+{
+	va_list ap;
+	va_start(ap, fmt);
+	trace_vprintf(key, fmt, ap);
+	va_end(ap);
+}
+
 void trace_printf(const char *fmt, ...)
 {
 	va_list ap;
 	va_start(ap, fmt);
-	trace_vprintf(fmt, ap);
+	trace_vprintf("GIT_TRACE", fmt, ap);
 	va_end(ap);
 }
 
@@ -94,7 +102,7 @@ void trace_argv_printf(const char **argv, const char *fmt, ...)
 	va_list ap;
 	int fd, need_close = 0;
 
-	fd = get_trace_fd(&need_close);
+	fd = get_trace_fd("GIT_TRACE", &need_close);
 	if (!fd)
 		return;
 

From 39bc5e4680a1ed7192968fbe9f5784ad56ecbd36 Mon Sep 17 00:00:00 2001
From: Jeff King <peff@peff.net>
Date: Thu, 24 Feb 2011 09:28:59 -0500
Subject: [PATCH 3/6] trace: factor out "do we want to trace" logic

As we add more tracing areas, this will avoid repeated code.

Technically, trace_printf already checks this and will avoid
printing if the trace key is not set. However, callers may
want to find out early whether or not tracing is enabled so
they can avoid doing work in the common non-trace case.

Signed-off-by: Jeff King <peff@peff.net>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
---
 cache.h |  1 +
 trace.c | 14 +++++++++++---
 2 files changed, 12 insertions(+), 3 deletions(-)

diff --git a/cache.h b/cache.h
index 2ab1bf9383..211d7bb26e 100644
--- a/cache.h
+++ b/cache.h
@@ -1071,6 +1071,7 @@ extern void trace_vprintf(const char *key, const char *format, va_list ap);
 __attribute__((format (printf, 2, 3)))
 extern void trace_argv_printf(const char **argv, const char *format, ...);
 extern void trace_repo_setup(const char *prefix);
+extern int trace_want(const char *key);
 
 /* convert.c */
 /* returns 1 if *dst was used */
diff --git a/trace.c b/trace.c
index 1d0e17e014..ca0ab0448b 100644
--- a/trace.c
+++ b/trace.c
@@ -148,10 +148,8 @@ void trace_repo_setup(const char *prefix)
 {
 	const char *git_work_tree;
 	char cwd[PATH_MAX];
-	char *trace = getenv("GIT_TRACE");
 
-	if (!trace || !strcmp(trace, "") ||
-	    !strcmp(trace, "0") || !strcasecmp(trace, "false"))
+	if (!trace_want("GIT_TRACE"))
 		return;
 
 	if (!getcwd(cwd, PATH_MAX))
@@ -168,3 +166,13 @@ void trace_repo_setup(const char *prefix)
 	trace_printf("setup: cwd: %s\n", quote_crnl(cwd));
 	trace_printf("setup: prefix: %s\n", quote_crnl(prefix));
 }
+
+int trace_want(const char *key)
+{
+	const char *trace = getenv(key);
+
+	if (!trace || !strcmp(trace, "") ||
+	    !strcmp(trace, "0") || !strcasecmp(trace, "false"))
+		return 0;
+	return 1;
+}

From 94b3b3746456949d834ec7bf454da3db4eb439cf Mon Sep 17 00:00:00 2001
From: Jeff King <peff@peff.net>
Date: Thu, 24 Feb 2011 09:29:50 -0500
Subject: [PATCH 4/6] trace: add trace_strbuf

If you happen to have a strbuf, it is a little more readable
and a little more efficient to be able to print it directly
instead of jamming it through the trace_printf interface.

Signed-off-by: Jeff King <peff@peff.net>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
---
 cache.h |  1 +
 trace.c | 23 ++++++++++++++++-------
 2 files changed, 17 insertions(+), 7 deletions(-)

diff --git a/cache.h b/cache.h
index 211d7bb26e..3978112f55 100644
--- a/cache.h
+++ b/cache.h
@@ -1072,6 +1072,7 @@ __attribute__((format (printf, 2, 3)))
 extern void trace_argv_printf(const char **argv, const char *format, ...);
 extern void trace_repo_setup(const char *prefix);
 extern int trace_want(const char *key);
+extern void trace_strbuf(const char *key, const struct strbuf *buf);
 
 /* convert.c */
 /* returns 1 if *dst was used */
diff --git a/trace.c b/trace.c
index ca0ab0448b..9f39eab025 100644
--- a/trace.c
+++ b/trace.c
@@ -65,19 +65,14 @@ static const char err_msg[] = "Could not trace into fd given by "
 void trace_vprintf(const char *key, const char *fmt, va_list ap)
 {
 	struct strbuf buf = STRBUF_INIT;
-	int fd, need_close = 0;
 
-	fd = get_trace_fd(key, &need_close);
-	if (!fd)
+	if (!trace_want(key))
 		return;
 
 	set_try_to_free_routine(NULL);	/* is never reset */
 	strbuf_vaddf(&buf, fmt, ap);
-	write_or_whine_pipe(fd, buf.buf, buf.len, err_msg);
+	trace_strbuf(key, &buf);
 	strbuf_release(&buf);
-
-	if (need_close)
-		close(fd);
 }
 
 void trace_printf_key(const char *key, const char *fmt, ...)
@@ -96,6 +91,20 @@ void trace_printf(const char *fmt, ...)
 	va_end(ap);
 }
 
+void trace_strbuf(const char *key, const struct strbuf *buf)
+{
+	int fd, need_close = 0;
+
+	fd = get_trace_fd(key, &need_close);
+	if (!fd)
+		return;
+
+	write_or_whine_pipe(fd, buf->buf, buf->len, err_msg);
+
+	if (need_close)
+		close(fd);
+}
+
 void trace_argv_printf(const char **argv, const char *fmt, ...)
 {
 	struct strbuf buf = STRBUF_INIT;

From bbc30f996380eacd71ca061675d5d0c5f21c45d2 Mon Sep 17 00:00:00 2001
From: Jeff King <peff@peff.net>
Date: Thu, 24 Feb 2011 09:30:19 -0500
Subject: [PATCH 5/6] add packet tracing debug code

This shows a trace of all packets coming in or out of a given
program. This can help with debugging object negotiation or
other protocol issues.

To keep the code changes simple, we operate at the lowest
level, meaning we don't necessarily understand what's in the
packets. The one exception is a packet starting with "PACK",
which causes us to skip that packet and turn off tracing
(since the gigantic pack data will not be interesting to
read, at least not in the trace format).

We show both written and read packets. In the local case,
this may mean you will see packets twice (written by the
sender and read by the receiver). However, for cases where
the other end is remote, this allows you to see the full
conversation.

Packet tracing can be enabled with GIT_TRACE_PACKET=<foo>,
where <foo> takes the same arguments as GIT_TRACE.

Signed-off-by: Jeff King <peff@peff.net>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
---
 builtin/clone.c        |  1 +
 builtin/fetch-pack.c   |  2 ++
 builtin/fetch.c        |  2 ++
 builtin/push.c         |  1 +
 builtin/receive-pack.c |  2 ++
 cache.h                |  2 ++
 pkt-line.c             | 55 +++++++++++++++++++++++++++++++++++++++++-
 upload-pack.c          |  1 +
 8 files changed, 65 insertions(+), 1 deletion(-)

diff --git a/builtin/clone.c b/builtin/clone.c
index 60d9a64280..38b4b71cd2 100644
--- a/builtin/clone.c
+++ b/builtin/clone.c
@@ -383,6 +383,7 @@ int cmd_clone(int argc, const char **argv, const char *prefix)
 
 	junk_pid = getpid();
 
+	packet_trace_identity("clone");
 	argc = parse_options(argc, argv, prefix, builtin_clone_options,
 			     builtin_clone_usage, 0);
 
diff --git a/builtin/fetch-pack.c b/builtin/fetch-pack.c
index b999413934..272bc383d6 100644
--- a/builtin/fetch-pack.c
+++ b/builtin/fetch-pack.c
@@ -804,6 +804,8 @@ int cmd_fetch_pack(int argc, const char **argv, const char *prefix)
 	char **pack_lockfile_ptr = NULL;
 	struct child_process *conn;
 
+	packet_trace_identity("fetch-pack");
+
 	nr_heads = 0;
 	heads = NULL;
 	for (i = 1; i < argc; i++) {
diff --git a/builtin/fetch.c b/builtin/fetch.c
index 357f3cdbbf..e94e0015c9 100644
--- a/builtin/fetch.c
+++ b/builtin/fetch.c
@@ -906,6 +906,8 @@ int cmd_fetch(int argc, const char **argv, const char *prefix)
 	struct remote *remote;
 	int result = 0;
 
+	packet_trace_identity("fetch");
+
 	/* Record the command line for the reflog */
 	strbuf_addstr(&default_rla, "fetch");
 	for (i = 1; i < argc; i++)
diff --git a/builtin/push.c b/builtin/push.c
index e655eb7695..26171ff50f 100644
--- a/builtin/push.c
+++ b/builtin/push.c
@@ -228,6 +228,7 @@ int cmd_push(int argc, const char **argv, const char *prefix)
 		OPT_END()
 	};
 
+	packet_trace_identity("push");
 	git_config(git_default_config, NULL);
 	argc = parse_options(argc, argv, prefix, options, push_usage, 0);
 
diff --git a/builtin/receive-pack.c b/builtin/receive-pack.c
index 760817dbd7..5fa4be8fb4 100644
--- a/builtin/receive-pack.c
+++ b/builtin/receive-pack.c
@@ -778,6 +778,8 @@ int cmd_receive_pack(int argc, const char **argv, const char *prefix)
 	char *dir = NULL;
 	struct command *commands;
 
+	packet_trace_identity("receive-pack");
+
 	argv++;
 	for (i = 1; i < argc; i++) {
 		const char *arg = *argv++;
diff --git a/cache.h b/cache.h
index 3978112f55..2e59aae179 100644
--- a/cache.h
+++ b/cache.h
@@ -1074,6 +1074,8 @@ extern void trace_repo_setup(const char *prefix);
 extern int trace_want(const char *key);
 extern void trace_strbuf(const char *key, const struct strbuf *buf);
 
+void packet_trace_identity(const char *prog);
+
 /* convert.c */
 /* returns 1 if *dst was used */
 extern int convert_to_git(const char *path, const char *src, size_t len,
diff --git a/pkt-line.c b/pkt-line.c
index 295ba2b16c..cd1bd26413 100644
--- a/pkt-line.c
+++ b/pkt-line.c
@@ -1,6 +1,51 @@
 #include "cache.h"
 #include "pkt-line.h"
 
+const char *packet_trace_prefix = "git";
+static const char trace_key[] = "GIT_TRACE_PACKET";
+
+void packet_trace_identity(const char *prog)
+{
+	packet_trace_prefix = xstrdup(prog);
+}
+
+static void packet_trace(const char *buf, unsigned int len, int write)
+{
+	int i;
+	struct strbuf out;
+
+	if (!trace_want(trace_key))
+		return;
+
+	/* +32 is just a guess for header + quoting */
+	strbuf_init(&out, len+32);
+
+	strbuf_addf(&out, "packet: %12s%c ",
+		    packet_trace_prefix, write ? '>' : '<');
+
+	if ((len >= 4 && !prefixcmp(buf, "PACK")) ||
+	    (len >= 5 && !prefixcmp(buf+1, "PACK"))) {
+		strbuf_addstr(&out, "PACK ...");
+		unsetenv(trace_key);
+	}
+	else {
+		/* XXX we should really handle printable utf8 */
+		for (i = 0; i < len; i++) {
+			/* suppress newlines */
+			if (buf[i] == '\n')
+				continue;
+			if (buf[i] >= 0x20 && buf[i] <= 0x7e)
+				strbuf_addch(&out, buf[i]);
+			else
+				strbuf_addf(&out, "\\%o", buf[i]);
+		}
+	}
+
+	strbuf_addch(&out, '\n');
+	trace_strbuf(trace_key, &out);
+	strbuf_release(&out);
+}
+
 /*
  * Write a packetized stream, where each line is preceded by
  * its length (including the header) as a 4-byte hex number.
@@ -39,11 +84,13 @@ ssize_t safe_write(int fd, const void *buf, ssize_t n)
  */
 void packet_flush(int fd)
 {
+	packet_trace("0000", 4, 1);
 	safe_write(fd, "0000", 4);
 }
 
 void packet_buf_flush(struct strbuf *buf)
 {
+	packet_trace("0000", 4, 1);
 	strbuf_add(buf, "0000", 4);
 }
 
@@ -62,6 +109,7 @@ static unsigned format_packet(const char *fmt, va_list args)
 	buffer[1] = hex(n >> 8);
 	buffer[2] = hex(n >> 4);
 	buffer[3] = hex(n);
+	packet_trace(buffer+4, n-4, 1);
 	return n;
 }
 
@@ -130,13 +178,16 @@ int packet_read_line(int fd, char *buffer, unsigned size)
 	len = packet_length(linelen);
 	if (len < 0)
 		die("protocol error: bad line length character: %.4s", linelen);
-	if (!len)
+	if (!len) {
+		packet_trace("0000", 4, 0);
 		return 0;
+	}
 	len -= 4;
 	if (len >= size)
 		die("protocol error: bad line length %d", len);
 	safe_read(fd, buffer, len);
 	buffer[len] = 0;
+	packet_trace(buffer, len, 0);
 	return len;
 }
 
@@ -153,6 +204,7 @@ int packet_get_line(struct strbuf *out,
 	if (!len) {
 		*src_buf += 4;
 		*src_len -= 4;
+		packet_trace("0000", 4, 0);
 		return 0;
 	}
 	if (*src_len < len)
@@ -165,5 +217,6 @@ int packet_get_line(struct strbuf *out,
 	strbuf_add(out, *src_buf, len);
 	*src_buf += len;
 	*src_len -= len;
+	packet_trace(out->buf, out->len, 0);
 	return len;
 }
diff --git a/upload-pack.c b/upload-pack.c
index b40a43f27d..0c87bc00f0 100644
--- a/upload-pack.c
+++ b/upload-pack.c
@@ -682,6 +682,7 @@ int main(int argc, char **argv)
 	int i;
 	int strict = 0;
 
+	packet_trace_identity("upload-pack");
 	git_extract_argv0_path(argv[0]);
 	read_replace_refs = 0;
 

From 7e2342d0987f7f78bc8582e97bbfbafd80d327ef Mon Sep 17 00:00:00 2001
From: Jeff King <peff@peff.net>
Date: Thu, 24 Feb 2011 09:30:30 -0500
Subject: [PATCH 6/6] trace: give repo_setup trace its own key

You no longer get this output with GIT_TRACE=1; instead, you
can do GIT_TRACE_SETUP=1.

Signed-off-by: Jeff King <peff@peff.net>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
---
 t/t1510-repo-setup.sh |  2 +-
 trace.c               | 11 ++++++-----
 2 files changed, 7 insertions(+), 6 deletions(-)

diff --git a/t/t1510-repo-setup.sh b/t/t1510-repo-setup.sh
index 15101d5e03..ec50a9ad70 100755
--- a/t/t1510-repo-setup.sh
+++ b/t/t1510-repo-setup.sh
@@ -57,7 +57,7 @@ test_repo () {
 			export GIT_WORK_TREE
 		fi &&
 		rm -f trace &&
-		GIT_TRACE="$(pwd)/trace" git symbolic-ref HEAD >/dev/null &&
+		GIT_TRACE_SETUP="$(pwd)/trace" git symbolic-ref HEAD >/dev/null &&
 		grep '^setup: ' trace >result &&
 		test_cmp expected result
 	)
diff --git a/trace.c b/trace.c
index 9f39eab025..8390bf7cbb 100644
--- a/trace.c
+++ b/trace.c
@@ -155,10 +155,11 @@ static const char *quote_crnl(const char *path)
 /* FIXME: move prefix to startup_info struct and get rid of this arg */
 void trace_repo_setup(const char *prefix)
 {
+	static const char *key = "GIT_TRACE_SETUP";
 	const char *git_work_tree;
 	char cwd[PATH_MAX];
 
-	if (!trace_want("GIT_TRACE"))
+	if (!trace_want(key))
 		return;
 
 	if (!getcwd(cwd, PATH_MAX))
@@ -170,10 +171,10 @@ void trace_repo_setup(const char *prefix)
 	if (!prefix)
 		prefix = "(null)";
 
-	trace_printf("setup: git_dir: %s\n", quote_crnl(get_git_dir()));
-	trace_printf("setup: worktree: %s\n", quote_crnl(git_work_tree));
-	trace_printf("setup: cwd: %s\n", quote_crnl(cwd));
-	trace_printf("setup: prefix: %s\n", quote_crnl(prefix));
+	trace_printf_key(key, "setup: git_dir: %s\n", quote_crnl(get_git_dir()));
+	trace_printf_key(key, "setup: worktree: %s\n", quote_crnl(git_work_tree));
+	trace_printf_key(key, "setup: cwd: %s\n", quote_crnl(cwd));
+	trace_printf_key(key, "setup: prefix: %s\n", quote_crnl(prefix));
 }
 
 int trace_want(const char *key)