Merge branch 'jk/trace-sifter'

* jk/trace-sifter:
  trace: give repo_setup trace its own key
  add packet tracing debug code
  trace: add trace_strbuf
  trace: factor out "do we want to trace" logic
  trace: refactor to support multiple env variables
  trace: add trace_vprintf

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);
 

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++) {

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++)

builtin/push.c

@@ -245,6 +245,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);
 

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++;

cache.h

@@ -1083,9 +1083,14 @@ 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 *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);
+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 */

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;
 }

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
 	)

trace.c

@@ -25,10 +25,10 @@
 #include "cache.h"
 #include "quote.h"
 
-/* Get a trace file descriptor from GIT_TRACE env variable. */
+/* Get a trace file descriptor from "key" env variable. */
-static int get_trace_fd(int *need_close)
+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 "
+		"then please set %s to an absolute pathname "
-		"(starting with /).\n");
+		"(starting with /).\n", key);
 	fprintf(stderr, "Defaulting to tracing on stderr...\n");
 
 	return STDERR_FILENO;
@@ -62,23 +62,44 @@ 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 *key, 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);
+	if (!trace_want(key))
-	if (!fd)
 		return;
 
 	set_try_to_free_routine(NULL);	/* is never reset */
-	va_start(ap, fmt);
 	strbuf_vaddf(&buf, fmt, ap);
-	va_end(ap);
+	trace_strbuf(key, &buf);
-
-	write_or_whine_pipe(fd, buf.buf, buf.len, err_msg);
 	strbuf_release(&buf);
+}
+
+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("GIT_TRACE", fmt, ap);
+	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);
@@ -90,7 +111,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;
 
@@ -134,12 +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];
-	char *trace = getenv("GIT_TRACE");
 
-	if (!trace || !strcmp(trace, "") ||
+	if (!trace_want(key))
-	    !strcmp(trace, "0") || !strcasecmp(trace, "false"))
 		return;
 
 	if (!getcwd(cwd, PATH_MAX))
@@ -151,8 +171,18 @@ 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_key(key, "setup: git_dir: %s\n", quote_crnl(get_git_dir()));
-	trace_printf("setup: worktree: %s\n", quote_crnl(git_work_tree));
+	trace_printf_key(key, "setup: worktree: %s\n", quote_crnl(git_work_tree));
-	trace_printf("setup: cwd: %s\n", quote_crnl(cwd));
+	trace_printf_key(key, "setup: cwd: %s\n", quote_crnl(cwd));
-	trace_printf("setup: prefix: %s\n", quote_crnl(prefix));
+	trace_printf_key(key, "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;
 }

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;