From 1423f908a9ba5b92cdc1d679cf7de4b79a0feef9 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Wed, 17 Oct 2018 11:05:49 -0400
Subject: [PATCH 01/23] trace2: general cleanup/refactoring after v1

* let common-main call trace2_cmd_exit
* add subverb event
* clarify exec/exec_result events
* add trace2_is_enabled()
* split cmd_start out of initialize

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 common-main.c                 | 11 +++++--
 compat/mingw.c                | 13 +++++++--
 exec-cmd.c                    |  8 +----
 git.c                         | 14 +++++----
 run-command.c                 | 20 +++++++++++++
 t/helper/test-parse-options.c |  3 ++
 trace2.c                      | 55 ++++++++++++++++++++++++++++++-----
 trace2.h                      | 46 ++++++++++++++++++++++-------
 trace2/tr2_tgt.h              |  8 +++--
 trace2/tr2_tgt_event.c        | 23 +++++++++++++--
 trace2/tr2_tgt_normal.c       | 19 +++++++++---
 trace2/tr2_tgt_perf.c         | 22 ++++++++++++--
 12 files changed, 196 insertions(+), 46 deletions(-)

diff --git a/common-main.c b/common-main.c
index bfea45c18d82f3..6dbdc4adf272ef 100644
--- a/common-main.c
+++ b/common-main.c
@@ -25,6 +25,8 @@ static void restore_sigpipe_to_default(void)
 
 int main(int argc, const char **argv)
 {
+	int result;
+
 	/*
 	 * Always open file descriptors 0/1/2 to avoid clobbering files
 	 * in die().  It also avoids messing up when the pipes are dup'ed
@@ -33,7 +35,8 @@ int main(int argc, const char **argv)
 	sanitize_stdfds();
 	restore_sigpipe_to_default();
 
-	trace2_initialize(argv);
+	trace2_initialize();
+	trace2_cmd_start(argv);
 
 	git_resolve_executable_dir(argv[0]);
 
@@ -43,5 +46,9 @@ int main(int argc, const char **argv)
 
 	attr_start();
 
-	return cmd_main(argc, argv);
+	result = cmd_main(argc, argv);
+
+	trace2_cmd_exit(result);
+
+	return result;
 }
diff --git a/compat/mingw.c b/compat/mingw.c
index 53ad239cf03faa..c695e5a5a07c91 100644
--- a/compat/mingw.c
+++ b/compat/mingw.c
@@ -1945,6 +1945,7 @@ static int try_shell_exec(const char *cmd, char *const *argv)
 		return 0;
 	prog = path_lookup(interpr, 1);
 	if (prog) {
+		int exec_id;
 		int argc = 0;
 #ifndef _MSC_VER
 		const
@@ -1954,14 +1955,16 @@ static int try_shell_exec(const char *cmd, char *const *argv)
 		ALLOC_ARRAY(argv2, argc + 1);
 		argv2[0] = (char *)cmd;	/* full path to the script file */
 		memcpy(&argv2[1], &argv[1], sizeof(*argv) * argc);
+		exec_id = trace2_exec(prog, argv2);
 		pid = mingw_spawnv(prog, argv2, interpr);
 		if (pid >= 0) {
 			int status;
 			if (waitpid(pid, &status, 0) < 0)
 				status = 255;
-			trace2_exec_result(status);
+			trace2_exec_result(exec_id, status);
 			exit(status);
 		}
+		trace2_exec_result(exec_id, -1);
 		pid = 1;	/* indicate that we tried but failed */
 		free(prog);
 		free(argv2);
@@ -1974,13 +1977,17 @@ int mingw_execv(const char *cmd, char *const *argv)
 	/* check if git_command is a shell script */
 	if (!try_shell_exec(cmd, argv)) {
 		int pid, status;
+		int exec_id;
 
+		exec_id = trace2_exec(cmd, (const char **)argv);
 		pid = mingw_spawnv(cmd, (const char **)argv, NULL);
-		if (pid < 0)
+		if (pid < 0) {
+			trace2_exec_result(exec_id, -1);
 			return -1;
+		}
 		if (waitpid(pid, &status, 0) < 0)
 			status = 255;
-		trace2_exec_result(status);
+		trace2_exec_result(exec_id, status);
 		exit(status);
 	}
 	return -1;
diff --git a/exec-cmd.c b/exec-cmd.c
index 640003564e611c..7deeab30397cf2 100644
--- a/exec-cmd.c
+++ b/exec-cmd.c
@@ -330,22 +330,16 @@ const char **prepare_git_cmd(struct argv_array *out, const char **argv)
 int execv_git_cmd(const char **argv)
 {
 	struct argv_array nargv = ARGV_ARRAY_INIT;
-	int err;
 
 	prepare_git_cmd(&nargv, argv);
 	trace_argv_printf(nargv.argv, "trace: exec:");
-	trace2_exec("git", (const char **)nargv.argv);
 
 	/* execvp() can only ever return if it fails */
 	sane_execvp("git", (char **)nargv.argv);
 
-	err = errno;
-	trace_printf("trace: exec failed: %s\n", strerror(err));
-	trace2_exec_result(err);
+	trace_printf("trace: exec failed: %s\n", strerror(errno));
 
 	argv_array_clear(&nargv);
-
-	errno = err;
 	return -1;
 }
 
diff --git a/git.c b/git.c
index 1ac52320a424a1..fff26d3d9e9019 100644
--- a/git.c
+++ b/git.c
@@ -760,21 +760,25 @@ static void execv_dashed_external(const char **argv)
 	if (run_pre_command_hook(cmd.args.argv))
 		die("pre-command hook aborted command");
 
+	/*
+	 * The code in run_command() logs trace2 child_start/child_exit
+	 * events, so we do not need to report exec/exec_result events here.
+	 */
 	trace_argv_printf(cmd.args.argv, "trace: exec:");
-	trace2_exec(NULL, cmd.args.argv);
 
 	/*
 	 * If we fail because the command is not found, it is
 	 * OK to return. Otherwise, we just pass along the status code,
 	 * or our usual generic code if we were not even able to exec
 	 * the program.
-	 *
+	 */
+	exit_code = status = run_command(&cmd);
+
+	/*
 	 * If the child process ran and we are now going to exit, emit a
 	 * generic string as our trace2 command verb to indicate that we
 	 * launched a dashed command.
 	 */
-	exit_code = status = run_command(&cmd);
-	trace2_exec_result(status);
 	if (status >= 0) {
 		trace2_cmd_verb("_run_dashed_");
 		exit(status);
@@ -965,5 +969,5 @@ int cmd_main(int argc, const char **argv)
 	fprintf(stderr, _("failed to run command '%s': %s\n"),
 		cmd, strerror(errno));
 
-	return trace2_cmd_exit(1);
+	return 1;
 }
diff --git a/run-command.c b/run-command.c
index d51250dbf7b339..67d2fb14eaea1e 100644
--- a/run-command.c
+++ b/run-command.c
@@ -220,9 +220,29 @@ static int exists_in_PATH(const char *file)
 
 int sane_execvp(const char *file, char * const argv[])
 {
+#ifndef GIT_WINDOWS_NATIVE
+	/*
+	 * execvp() doesn't return, so we all we can do is tell trace2
+	 * what we are about to do and let it leave a hint in the log
+	 * (unless of course the execvp() fails).
+	 *
+	 * we skip this for Windows because the compat layer already
+	 * has to emulate the execvp() call anyway.
+	 */
+	int exec_id = trace2_exec(file, (const char**)argv);
+#endif
+
 	if (!execvp(file, argv))
 		return 0; /* cannot happen ;-) */
 
+#ifndef GIT_WINDOWS_NATIVE
+	{
+		int ec = errno;
+		trace2_exec_result(exec_id, ec);
+		errno = ec;
+	}
+#endif
+
 	/*
 	 * When a command can't be found because one of the directories
 	 * listed in $PATH is unsearchable, execvp reports EACCES, but
diff --git a/t/helper/test-parse-options.c b/t/helper/test-parse-options.c
index 47fee660b86a6e..5318681739d9c6 100644
--- a/t/helper/test-parse-options.c
+++ b/t/helper/test-parse-options.c
@@ -2,6 +2,7 @@
 #include "cache.h"
 #include "parse-options.h"
 #include "string-list.h"
+#include "trace2.h"
 
 static int boolean = 0;
 static int integer = 0;
@@ -153,6 +154,8 @@ int cmd__parse_options(int argc, const char **argv)
 	int i;
 	int ret = 0;
 
+	trace2_cmd_verb("_parse_");
+
 	argc = parse_options(argc, (const char **)argv, prefix, options, usage, 0);
 
 	if (length_cb.called) {
diff --git a/trace2.c b/trace2.c
index c9844bc742e597..c977a9ac1e7886 100644
--- a/trace2.c
+++ b/trace2.c
@@ -15,6 +15,7 @@
 static int trace2_enabled;
 
 static int tr2_next_child_id; /* modify under lock */
+static int tr2_next_exec_id; /* modify under lock */
 static int tr2_next_repo_id = 1; /* modify under lock. zero is reserved */
 
 /*
@@ -145,7 +146,7 @@ static void tr2main_signal_handler(int signo)
  * TODO remove this section header
  *****************************************************************/
 
-void trace2_initialize_fl(const char *file, int line, const char **argv)
+void trace2_initialize_fl(const char *file, int line)
 {
 	struct tr2_tgt *tgt_j;
 	int j;
@@ -164,11 +165,28 @@ void trace2_initialize_fl(const char *file, int line, const char **argv)
 	tr2tls_init();
 
 	/*
-	 * Emit 'version' and 'start' messages on each active builtin target.
+	 * Emit 'version' message on each active builtin target.
 	 */
 	for_each_wanted_builtin(j, tgt_j) {
 		if (tgt_j->pfn_version_fl)
 			tgt_j->pfn_version_fl(file, line);
+	}
+}
+
+int trace2_is_enabled(void)
+{
+	return trace2_enabled;
+}
+
+void trace2_cmd_start_fl(const char *file, int line, const char **argv)
+{
+	struct tr2_tgt *tgt_j;
+	int j;
+
+	if (!trace2_enabled)
+		return;
+
+	for_each_wanted_builtin(j, tgt_j) {
 		if (tgt_j->pfn_start_fl)
 			tgt_j->pfn_start_fl(file, line, argv);
 	}
@@ -246,6 +264,22 @@ void trace2_cmd_verb_fl(const char *file, int line, const char *command_verb)
 	}
 }
 
+void trace2_cmd_subverb_fl(const char *file, int line,
+			   const char *command_subverb)
+{
+	struct tr2_tgt *tgt_j;
+	int j;
+
+	if (!trace2_enabled)
+		return;
+
+	for_each_wanted_builtin(j, tgt_j) {
+		if (tgt_j->pfn_command_subverb_fl)
+			tgt_j->pfn_command_subverb_fl(file, line,
+						      command_subverb);
+	}
+}
+
 void trace2_cmd_alias_fl(const char *file, int line,
 			 const char *alias, const char **argv)
 {
@@ -332,28 +366,33 @@ void trace2_child_exit_fl(const char *file, int line,
 	}
 }
 
-void trace2_exec_fl(const char *file, int line,
-		    const char *exe, const char **argv)
+int trace2_exec_fl(const char *file, int line,
+		   const char *exe, const char **argv)
 {
 	struct tr2_tgt *tgt_j;
 	int j;
+	int exec_id;
 	uint64_t us_now;
 	uint64_t us_elapsed_absolute;
 
 	if (!trace2_enabled)
-		return;
+		return -1;
 
 	us_now = getnanotime() / 1000;
 	us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 
+	exec_id = tr2tls_locked_increment(&tr2_next_exec_id);
+
 	for_each_wanted_builtin(j, tgt_j) {
 		if (tgt_j->pfn_exec_fl)
 			tgt_j->pfn_exec_fl(file, line, us_elapsed_absolute,
-					   exe, argv);
+					   exec_id, exe, argv);
 	}
+
+	return exec_id;
 }
 
-void trace2_exec_result_fl(const char *file, int line, int code)
+void trace2_exec_result_fl(const char *file, int line, int exec_id, int code)
 {
 	struct tr2_tgt *tgt_j;
 	int j;
@@ -370,7 +409,7 @@ void trace2_exec_result_fl(const char *file, int line, int code)
 		if (tgt_j->pfn_exec_result_fl)
 			tgt_j->pfn_exec_result_fl(file, line,
 						  us_elapsed_absolute,
-						  code);
+						  exec_id, code);
 	}
 }
 
diff --git a/trace2.h b/trace2.h
index 8cb75a57305307..830930ef2ab586 100644
--- a/trace2.h
+++ b/trace2.h
@@ -18,18 +18,28 @@ struct repository;
  * [] trace2_printf*    -- legacy trace[1] messages.
  */
 
-
 /*
  * Initialize TRACE2 tracing facility if any of the builtin TRACE2
- * targets are enabled in the environment.  Emits 'version' and
- * 'start' events.
+ * targets are enabled in the environment.  Emits a 'version' event.
  *
  * Cleanup/Termination is handled automatically by a registered
  * atexit() routine.
  */
-void trace2_initialize_fl(const char *file, int line, const char **argv);
+void trace2_initialize_fl(const char *file, int line);
+
+#define trace2_initialize() trace2_initialize_fl(__FILE__, __LINE__)
+
+/*
+ * Return true if trace2 is enabled.
+ */
+int trace2_is_enabled(void);
+
+/*
+ * Emit a 'start' event with the original (unmodified) argv.
+ */
+void trace2_cmd_start_fl(const char *file, int line, const char **argv);
 
-#define trace2_initialize(argv) trace2_initialize_fl(__FILE__, __LINE__, argv)
+#define trace2_cmd_start(argv) trace2_cmd_start_fl(__FILE__, __LINE__, (argv))
 
 /*
  * Emit an 'exit' event.
@@ -76,6 +86,18 @@ void trace2_cmd_verb_fl(const char *file, int line, const char *command_verb);
 #define trace2_cmd_verb(v) \
 	trace2_cmd_verb_fl(__FILE__, __LINE__, (v))
 
+/*
+ * Emit a 'cmd_subverb' event to further describe the command being run.
+ * For example, "checkout" can checkout a single file or can checkout a
+ * different branch.  This gives post-processors a simple field to compare
+ * equivalent commands without having to parse the argv.
+ */
+void trace2_cmd_subverb_fl(const char *file, int line,
+			   const char *command_subverb);
+
+#define trace2_cmd_subverb(sv) \
+	trace2_cmd_subverb_fl(__FILE__, __LINE__, (sv))
+
 /*
  * Emit an 'alias' expansion event.
  */
@@ -147,9 +169,11 @@ void trace2_child_exit_fl(const char *file, int line,
  * last event emitted for the current process, unless the exec
  * fails.  On Windows, exec() behaves like 'child_start' and a
  * waitpid(), so additional events may be emitted.
+ *
+ * Returns the "exec_id".
  */
-void trace2_exec_fl(const char *file, int line,
-		    const char *exe, const char **argv);
+int trace2_exec_fl(const char *file, int line,
+		   const char *exe, const char **argv);
 
 #define trace2_exec(exe, argv) \
 	trace2_exec_fl(__FILE__, __LINE__, (exe), (argv))
@@ -159,11 +183,13 @@ void trace2_exec_fl(const char *file, int line,
  * this should be called after exec() returns (which only happens
  * when there is an error starting the new process).  On Windows,
  * this should be called after the waitpid().
+ *
+ * The "exec_id" should be the value returned from trace2_exec().
  */
-void trace2_exec_result_fl(const char *file, int line, int code);
+void trace2_exec_result_fl(const char *file, int line, int exec_id, int code);
 
-#define trace2_exec_result(code) \
-	trace2_exec_result_fl(__FILE__, __LINE__, (code))
+#define trace2_exec_result(id, code) \
+	trace2_exec_result_fl(__FILE__, __LINE__, (id), (code))
 
 /*
  * Emit a 'thread_start' event.  This must be called from inside the
diff --git a/trace2/tr2_tgt.h b/trace2/tr2_tgt.h
index 9d93add2236a69..4e42dd11398999 100644
--- a/trace2/tr2_tgt.h
+++ b/trace2/tr2_tgt.h
@@ -31,6 +31,8 @@ typedef void (tr2_tgt_evt_command_path_fl_t)
 	(const char *file, int line, const char *command_path);
 typedef void (tr2_tgt_evt_command_verb_fl_t)
 	(const char *file, int line, const char *command_verb);
+typedef void (tr2_tgt_evt_command_subverb_fl_t)
+	(const char *file, int line, const char *command_subverb);
 
 typedef void (tr2_tgt_evt_alias_fl_t)
 	(const char *file, int line, const char *alias, const char **argv);
@@ -50,9 +52,10 @@ typedef void (tr2_tgt_evt_thread_exit_fl_t)
 
 typedef void (tr2_tgt_evt_exec_fl_t)
 	(const char *file, int line, uint64_t us_elapsed_absolute,
-	 const char *exe, const char **argv);
+	 int exec_id, const char *exe, const char **argv);
 typedef void (tr2_tgt_evt_exec_result_fl_t)
-	(const char *file, int line, uint64_t us_elapsed_absolute, int code);
+	(const char *file, int line, uint64_t us_elapsed_absolute,
+	 int exec_id, int code);
 
 typedef void (tr2_tgt_evt_param_fl_t)
 	(const char *file, int line, const char *param, const char *value);
@@ -97,6 +100,7 @@ struct tr2_tgt
 	tr2_tgt_evt_error_va_fl_t               *pfn_error_va_fl;
 	tr2_tgt_evt_command_path_fl_t           *pfn_command_path_fl;
 	tr2_tgt_evt_command_verb_fl_t           *pfn_command_verb_fl;
+	tr2_tgt_evt_command_subverb_fl_t        *pfn_command_subverb_fl;
 	tr2_tgt_evt_alias_fl_t                  *pfn_alias_fl;
 	tr2_tgt_evt_child_start_fl_t            *pfn_child_start_fl;
 	tr2_tgt_evt_child_exit_fl_t             *pfn_child_exit_fl;
diff --git a/trace2/tr2_tgt_event.c b/trace2/tr2_tgt_event.c
index 9e653d111b9846..7f8b299157dfb4 100644
--- a/trace2/tr2_tgt_event.c
+++ b/trace2/tr2_tgt_event.c
@@ -249,6 +249,21 @@ static void fn_command_verb_fl(const char *file, int line,
 	jw_release(&jw);
 }
 
+static void fn_command_subverb_fl(const char *file, int line,
+			       const char *command_subverb)
+{
+	const char *event_name = "cmd_subverb";
+	struct json_writer jw = JSON_WRITER_INIT;
+
+	jw_object_begin(&jw, 0);
+	event_fmt_prepare(event_name, file, line, NULL, &jw);
+	jw_object_string(&jw, "name", command_subverb);
+	jw_end(&jw);
+
+	tr2_dst_write_line(&tr2dst_event, &jw.json);
+	jw_release(&jw);
+}
+
 static void fn_alias_fl(const char *file, int line,
 			const char *alias, const char **argv)
 {
@@ -348,13 +363,14 @@ static void fn_thread_exit_fl(const char *file, int line,
 
 static void fn_exec_fl(const char *file, int line,
 		       uint64_t us_elapsed_absolute,
-		       const char *exe, const char **argv)
+		       int exec_id, const char *exe, const char **argv)
 {
 	const char *event_name = "exec";
 	struct json_writer jw = JSON_WRITER_INIT;
 
 	jw_object_begin(&jw, 0);
 	event_fmt_prepare(event_name, file, line, NULL, &jw);
+	jw_object_intmax(&jw, "exec_id", exec_id);
 	if (exe)
 		jw_object_string(&jw, "exe", exe);
 	jw_object_inline_begin_array(&jw, "argv");
@@ -367,13 +383,15 @@ static void fn_exec_fl(const char *file, int line,
 }
 
 static void fn_exec_result_fl(const char *file, int line,
-			      uint64_t us_elapsed_absolute, int code)
+			      uint64_t us_elapsed_absolute,
+			      int exec_id, int code)
 {
 	const char *event_name = "exec_result";
 	struct json_writer jw = JSON_WRITER_INIT;
 
 	jw_object_begin(&jw, 0);
 	event_fmt_prepare(event_name, file, line, NULL, &jw);
+	jw_object_intmax(&jw, "exec_id", exec_id);
 	jw_object_intmax(&jw, "code", code);
 	jw_end(&jw);
 
@@ -515,6 +533,7 @@ struct tr2_tgt tr2_tgt_event =
 	fn_error_va_fl,
 	fn_command_path_fl,
 	fn_command_verb_fl,
+	fn_command_subverb_fl,
 	fn_alias_fl,
 	fn_child_start_fl,
 	fn_child_exit_fl,
diff --git a/trace2/tr2_tgt_normal.c b/trace2/tr2_tgt_normal.c
index bab32100630273..7bac5e46d2ebc1 100644
--- a/trace2/tr2_tgt_normal.c
+++ b/trace2/tr2_tgt_normal.c
@@ -178,6 +178,16 @@ static void fn_command_verb_fl(const char *file, int line,
 	strbuf_release(&buf_payload);
 }
 
+static void fn_command_subverb_fl(const char *file, int line,
+			       const char *command_subverb)
+{
+	struct strbuf buf_payload = STRBUF_INIT;
+
+	strbuf_addf(&buf_payload, "cmd_subverb %s", command_subverb);
+	normal_io_write_fl(file, line, &buf_payload);
+	strbuf_release(&buf_payload);
+}
+
 static void fn_alias_fl(const char *file, int line, const char *alias,
 			const char **argv)
 {
@@ -232,11 +242,11 @@ static void fn_child_exit_fl(const char *file, int line,
 
 static void fn_exec_fl(const char *file, int line,
 		       uint64_t us_elapsed_absolute,
-		       const char *exe, const char **argv)
+		       int exec_id, const char *exe, const char **argv)
 {
 	struct strbuf buf_payload = STRBUF_INIT;
 
-	strbuf_addstr(&buf_payload, "exec ");
+	strbuf_addf(&buf_payload, "exec[%d] ", exec_id);
 	if (exe)
 		strbuf_addstr(&buf_payload, exe);
 	sq_quote_argv_pretty(&buf_payload, argv);
@@ -246,11 +256,11 @@ static void fn_exec_fl(const char *file, int line,
 
 static void fn_exec_result_fl(const char *file, int line,
 			      uint64_t us_elapsed_absolute,
-			      int code)
+			      int exec_id, int code)
 {
 	struct strbuf buf_payload = STRBUF_INIT;
 
-	strbuf_addf(&buf_payload, "exec_result code:%d", code);
+	strbuf_addf(&buf_payload, "exec_result[%d] code:%d", exec_id, code);
 	if (code > 0)
 		strbuf_addf(&buf_payload, " err:%s", strerror(code));
 	normal_io_write_fl(file, line, &buf_payload);
@@ -304,6 +314,7 @@ struct tr2_tgt tr2_tgt_normal =
 	fn_error_va_fl,
 	fn_command_path_fl,
 	fn_command_verb_fl,
+	fn_command_subverb_fl,
 	fn_alias_fl,
 	fn_child_start_fl,
 	fn_child_exit_fl,
diff --git a/trace2/tr2_tgt_perf.c b/trace2/tr2_tgt_perf.c
index f2b8089a8c8156..bcb271e5ba4c3f 100644
--- a/trace2/tr2_tgt_perf.c
+++ b/trace2/tr2_tgt_perf.c
@@ -277,6 +277,20 @@ static void fn_command_verb_fl(const char *file, int line,
 	strbuf_release(&buf_payload);
 }
 
+static void fn_command_subverb_fl(const char *file, int line,
+			       const char *command_subverb)
+{
+	const char *event_name = "cmd_subverb";
+	struct strbuf buf_payload = STRBUF_INIT;
+
+	strbuf_addstr(&buf_payload, command_subverb);
+
+	perf_io_write_fl(file, line, event_name, NULL,
+			 NULL, NULL, NULL,
+			 &buf_payload);
+	strbuf_release(&buf_payload);
+}
+
 static void fn_alias_fl(const char *file, int line, const char *alias,
 			const char **argv)
 {
@@ -362,11 +376,12 @@ static void fn_thread_exit_fl(const char *file, int line,
 
 static void fn_exec_fl(const char *file, int line,
 		       uint64_t us_elapsed_absolute,
-		       const char *exe, const char **argv)
+		       int exec_id, const char *exe, const char **argv)
 {
 	const char *event_name = "exec";
 	struct strbuf buf_payload = STRBUF_INIT;
 
+	strbuf_addf(&buf_payload, "id:%d ", exec_id);
 	strbuf_addstr(&buf_payload, "argv:");
 	if (exe)
 		strbuf_addf(&buf_payload, " %s", exe);
@@ -380,12 +395,12 @@ static void fn_exec_fl(const char *file, int line,
 
 static void fn_exec_result_fl(const char *file, int line,
 			      uint64_t us_elapsed_absolute,
-			      int code)
+			      int exec_id, int code)
 {
 	const char *event_name = "exec_result";
 	struct strbuf buf_payload = STRBUF_INIT;
 
-	strbuf_addf(&buf_payload, "code:%d", code);
+	strbuf_addf(&buf_payload, "id:%d code:%d", exec_id, code);
 	if (code > 0)
 		strbuf_addf(&buf_payload, " err:%s", strerror(code));
 
@@ -514,6 +529,7 @@ struct tr2_tgt tr2_tgt_perf =
 	fn_error_va_fl,
 	fn_command_path_fl,
 	fn_command_verb_fl,
+	fn_command_subverb_fl,
 	fn_alias_fl,
 	fn_child_start_fl,
 	fn_child_exit_fl,

From 2d6541481477e822369538ce6714cbb5c0a42669 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 26 Nov 2018 07:07:16 -0500
Subject: [PATCH 02/23] trace2: define macro for env var used for SID field

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 trace2/tr2_sid.c | 6 ++++--
 1 file changed, 4 insertions(+), 2 deletions(-)

diff --git a/trace2/tr2_sid.c b/trace2/tr2_sid.c
index 7fba400e9766f6..ed0d1161535579 100644
--- a/trace2/tr2_sid.c
+++ b/trace2/tr2_sid.c
@@ -5,6 +5,8 @@
  * This file contains "private/protected" routines for TRACE2.
  */
 
+#define TR2_ENVVAR_PARENT_SID "GIT_TR2_PARENT_SID"
+
 static struct strbuf tr2sid_buf = STRBUF_INIT;
 static int tr2sid_nr_git_parents;
 
@@ -28,7 +30,7 @@ static void tr2_sid_compute(void)
 	if (tr2sid_buf.len)
 		return;
 
-	parent_sid = getenv("SLOG_PARENT_SID");
+	parent_sid = getenv(TR2_ENVVAR_PARENT_SID);
 	if (parent_sid && *parent_sid) {
 		const char *p;
 		for (p = parent_sid; *p; p++)
@@ -44,7 +46,7 @@ static void tr2_sid_compute(void)
 	strbuf_addf(&tr2sid_buf, "%"PRIuMAX"-%"PRIdMAX,
 		    (uintmax_t)us_now, (intmax_t)getpid());
 
-	setenv("SLOG_PARENT_SID", tr2sid_buf.buf, 1);
+	setenv(TR2_ENVVAR_PARENT_SID, tr2sid_buf.buf, 1);
 }
 
 const char *tr2_sid_get(void)

From 62fe2f28032fc7a57852aca0010e11c6f7a5b54a Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Fri, 7 Dec 2018 19:25:13 +0000
Subject: [PATCH 03/23] trace2: fix t0001 when trace2 is enabled

Trace2 adds GIT_TR2_PARENT_SID and GIT_TR2_PARENT_VERB to the environment
for child processes to inherit.  Exclude them from the test.

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 t/t0001-init.sh | 1 +
 1 file changed, 1 insertion(+)

diff --git a/t/t0001-init.sh b/t/t0001-init.sh
index a6c5fe9e1475ae..d13aa011e00431 100755
--- a/t/t0001-init.sh
+++ b/t/t0001-init.sh
@@ -93,6 +93,7 @@ test_expect_success 'No extra GIT_* on alias scripts' '
 		sed -n \
 			-e "/^GIT_PREFIX=/d" \
 			-e "/^GIT_TEXTDOMAINDIR=/d" \
+			-e "/^GIT_TR2_PARENT/d" \
 			-e "/^GIT_/s/=.*//p" |
 		sort
 	EOF

From 67c7bcee27ceb9f07bb72495cf4c42e4731987e9 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 12 Nov 2018 07:12:22 -0500
Subject: [PATCH 04/23] trace2: use UTC for time fields in event stream rather
 than localtime

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 trace2/tr2_tbuf.c       | 18 +++++++++++++++++-
 trace2/tr2_tbuf.h       |  5 +++--
 trace2/tr2_tgt_event.c  |  2 +-
 trace2/tr2_tgt_normal.c |  2 +-
 trace2/tr2_tgt_perf.c   |  2 +-
 5 files changed, 23 insertions(+), 6 deletions(-)

diff --git a/trace2/tr2_tbuf.c b/trace2/tr2_tbuf.c
index 98c4c25770adb8..b79adcba371d97 100644
--- a/trace2/tr2_tbuf.c
+++ b/trace2/tr2_tbuf.c
@@ -1,7 +1,8 @@
 #include "cache.h"
 #include "tr2_tbuf.h"
 
-void tr2_tbuf_current_time(struct tr2_tbuf *tb)
+
+void tr2_tbuf_local_time(struct tr2_tbuf *tb)
 {
 	struct timeval tv;
 	struct tm tm;
@@ -15,3 +16,18 @@ void tr2_tbuf_current_time(struct tr2_tbuf *tb)
 		  tm.tm_hour, tm.tm_min, tm.tm_sec, (long)tv.tv_usec);
 }
 
+void tr2_tbuf_utc_time(struct tr2_tbuf *tb)
+{
+	struct timeval tv;
+	struct tm tm;
+	time_t secs;
+
+	gettimeofday(&tv, NULL);
+	secs = tv.tv_sec;
+	gmtime_r(&secs, &tm);
+
+	xsnprintf(tb->buf, sizeof(tb->buf), "%4d-%02d-%02d %02d:%02d:%02d.%06ld",
+		  tm.tm_year+1900, tm.tm_mon+1, tm.tm_mday,
+		  tm.tm_hour, tm.tm_min, tm.tm_sec, (long)tv.tv_usec);
+}
+
diff --git a/trace2/tr2_tbuf.h b/trace2/tr2_tbuf.h
index 63a035b6e9fa94..4c5626b7c5027e 100644
--- a/trace2/tr2_tbuf.h
+++ b/trace2/tr2_tbuf.h
@@ -11,9 +11,10 @@
  * argument.
  */
 struct tr2_tbuf {
-	char buf[24];
+	char buf[32];
 };
 
-void tr2_tbuf_current_time(struct tr2_tbuf *tb);
+void tr2_tbuf_local_time(struct tr2_tbuf *tb);
+void tr2_tbuf_utc_time(struct tr2_tbuf *tb);
 
 #endif /* TR2_TBUF_H */
diff --git a/trace2/tr2_tgt_event.c b/trace2/tr2_tgt_event.c
index 7f8b299157dfb4..83739ce7ed347d 100644
--- a/trace2/tr2_tgt_event.c
+++ b/trace2/tr2_tgt_event.c
@@ -81,7 +81,7 @@ static void event_fmt_prepare(const char *event_name,
 	jw_object_string(jw, "sid", tr2_sid_get());
 	jw_object_string(jw, "thread", ctx->thread_name.buf);
 
-	tr2_tbuf_current_time(&tb_now);
+	tr2_tbuf_utc_time(&tb_now);
 	jw_object_string(jw, "time", tb_now.buf);
 
 	if (file && *file) {
diff --git a/trace2/tr2_tgt_normal.c b/trace2/tr2_tgt_normal.c
index 7bac5e46d2ebc1..e97077b11c717c 100644
--- a/trace2/tr2_tgt_normal.c
+++ b/trace2/tr2_tgt_normal.c
@@ -54,7 +54,7 @@ static void normal_fmt_prepare(const char *file, int line, struct strbuf *buf)
 	if (!tr2env_normal_bare) {
 		struct tr2_tbuf tb_now;
 
-		tr2_tbuf_current_time(&tb_now);
+		tr2_tbuf_local_time(&tb_now);
 		strbuf_addstr(buf, tb_now.buf);
 		strbuf_addch(buf, ' ');
 
diff --git a/trace2/tr2_tgt_perf.c b/trace2/tr2_tgt_perf.c
index bcb271e5ba4c3f..277e6d7ead26e5 100644
--- a/trace2/tr2_tgt_perf.c
+++ b/trace2/tr2_tgt_perf.c
@@ -83,7 +83,7 @@ static void perf_fmt_prepare(
 
 		struct tr2_tbuf tb_now;
 
-		tr2_tbuf_current_time(&tb_now);
+		tr2_tbuf_local_time(&tb_now);
 		strbuf_addstr(buf, tb_now.buf);
 		strbuf_addch(buf, ' ');
 

From 72fb12bece4217653dd685156e894b85a9f64239 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 12 Nov 2018 14:24:02 -0500
Subject: [PATCH 05/23] trace2: add data_json event type

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 trace2.c                | 27 +++++++++++++++++++++++++++
 trace2.h                | 11 +++++++++++
 trace2/tr2_tgt.h        |  6 ++++++
 trace2/tr2_tgt_event.c  | 31 +++++++++++++++++++++++++++++++
 trace2/tr2_tgt_normal.c |  1 +
 trace2/tr2_tgt_perf.c   | 21 +++++++++++++++++++++
 6 files changed, 97 insertions(+)

diff --git a/trace2.c b/trace2.c
index c977a9ac1e7886..4e72ce6fb1161f 100644
--- a/trace2.c
+++ b/trace2.c
@@ -735,6 +735,33 @@ void trace2_data_intmax_fl(const char *file, int line,
 	strbuf_release(&buf_string);
 }
 
+void trace2_data_json_fl(const char *file, int line,
+			 const char *category,
+			 const struct repository *repo,
+			 const char *key,
+			 const struct json_writer *value)
+{
+	struct tr2_tgt *tgt_j;
+	int j;
+	uint64_t us_now;
+	uint64_t us_elapsed_absolute;
+	uint64_t us_elapsed_region;
+
+	if (!trace2_enabled)
+		return;
+
+	us_now = getnanotime() / 1000;
+	us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
+	us_elapsed_region = tr2tls_region_elasped_self(us_now);
+
+	for_each_wanted_builtin(j, tgt_j) {
+		if (tgt_j->pfn_data_fl)
+			tgt_j->pfn_data_json_fl(file, line, us_elapsed_absolute,
+						us_elapsed_region,
+						category, repo, key, value);
+	}
+}
+
 void trace2_printf_va_fl(const char *file, int line,
 			 const char *fmt, va_list ap)
 {
diff --git a/trace2.h b/trace2.h
index 830930ef2ab586..ce89d040b91a50 100644
--- a/trace2.h
+++ b/trace2.h
@@ -3,6 +3,7 @@
 
 struct child_process;
 struct repository;
+struct json_writer;
 
 /*
  * The public TRACE2 routines are grouped into the following groups:
@@ -352,6 +353,16 @@ void trace2_data_intmax_fl(const char *file, int line,
 	trace2_data_intmax_fl( \
 		__FILE__, __LINE__, (category), (repo), (key), (value))
 
+void trace2_data_json_fl(const char *file, int line,
+			 const char *category,
+			 const struct repository *repo,
+			 const char *key,
+			 const struct json_writer *jw);
+
+#define trace2_data_json(category, repo, key, value) \
+	trace2_data_json_fl( \
+		__FILE__, __LINE__, (category), (repo), (key), (value))
+
 /*
  * Emit a 'printf' event.
  *
diff --git a/trace2/tr2_tgt.h b/trace2/tr2_tgt.h
index 4e42dd11398999..a90944584dd06e 100644
--- a/trace2/tr2_tgt.h
+++ b/trace2/tr2_tgt.h
@@ -76,6 +76,11 @@ typedef void (tr2_tgt_evt_data_fl_t)
 	(const char *file, int line, uint64_t us_elapsed_absolute,
 	 uint64_t us_elapsed_region, const char *category,
 	 const struct repository *repo, const char *key, const char *value);
+typedef void (tr2_tgt_evt_data_json_fl_t)
+	(const char *file, int line, uint64_t us_elapsed_absolute,
+	 uint64_t us_elapsed_region, const char *category,
+	 const struct repository *repo,
+	 const char *key, const struct json_writer *value);
 
 typedef void (tr2_tgt_evt_printf_va_fl_t)
 	(const char *file, int line, uint64_t us_elapsed_absolute,
@@ -113,6 +118,7 @@ struct tr2_tgt
 	tr2_tgt_evt_region_enter_printf_va_fl_t *pfn_region_enter_printf_va_fl;
 	tr2_tgt_evt_region_leave_printf_va_fl_t *pfn_region_leave_printf_va_fl;
 	tr2_tgt_evt_data_fl_t                   *pfn_data_fl;
+	tr2_tgt_evt_data_json_fl_t              *pfn_data_json_fl;
 	tr2_tgt_evt_printf_va_fl_t              *pfn_printf_va_fl;
 };
 
diff --git a/trace2/tr2_tgt_event.c b/trace2/tr2_tgt_event.c
index 83739ce7ed347d..9975d535f02046 100644
--- a/trace2/tr2_tgt_event.c
+++ b/trace2/tr2_tgt_event.c
@@ -518,6 +518,36 @@ static void fn_data_fl(const char *file, int line,
 	}
 }
 
+static void fn_data_json_fl(const char *file, int line,
+			    uint64_t us_elapsed_absolute,
+			    uint64_t us_elapsed_region,
+			    const char *category,
+			    const struct repository *repo,
+			    const char *key,
+			    const struct json_writer *value)
+{
+	const char *event_name = "data_json";
+	struct tr2tls_thread_ctx *ctx = tr2tls_get_self();
+	if (ctx->nr_open_regions <= tr2env_event_nesting_wanted) {
+		struct json_writer jw = JSON_WRITER_INIT;
+		double t_abs = (double)us_elapsed_absolute / 1000000.0;
+		double t_rel = (double)us_elapsed_region / 1000000.0;
+
+		jw_object_begin(&jw, 0);
+		event_fmt_prepare(event_name, file, line, repo, &jw);
+		jw_object_double(&jw, "t_abs", 6, t_abs);
+		jw_object_double(&jw, "t_rel", 6, t_rel);
+		jw_object_intmax(&jw, "nesting", ctx->nr_open_regions);
+		jw_object_string(&jw, "category", category);
+		jw_object_string(&jw, "key", key);
+		jw_object_sub_jw(&jw, "value", value);
+		jw_end(&jw);
+
+		tr2_dst_write_line(&tr2dst_event, &jw.json);
+		jw_release(&jw);
+	}
+}
+
 struct tr2_tgt tr2_tgt_event =
 {
 	&tr2dst_event,
@@ -546,5 +576,6 @@ struct tr2_tgt tr2_tgt_event =
 	fn_region_enter_printf_va_fl,
 	fn_region_leave_printf_va_fl,
 	fn_data_fl,
+	fn_data_json_fl,
 	NULL, /* printf */
 };
diff --git a/trace2/tr2_tgt_normal.c b/trace2/tr2_tgt_normal.c
index e97077b11c717c..b5ed6bf82a4b88 100644
--- a/trace2/tr2_tgt_normal.c
+++ b/trace2/tr2_tgt_normal.c
@@ -327,5 +327,6 @@ struct tr2_tgt tr2_tgt_normal =
 	NULL, /* region_enter */
 	NULL, /* region_leave */
 	NULL, /* data */
+	NULL, /* data_json */
 	fn_printf_va_fl,
 };
diff --git a/trace2/tr2_tgt_perf.c b/trace2/tr2_tgt_perf.c
index 277e6d7ead26e5..8df8728ffeb607 100644
--- a/trace2/tr2_tgt_perf.c
+++ b/trace2/tr2_tgt_perf.c
@@ -3,6 +3,7 @@
 #include "run-command.h"
 #include "quote.h"
 #include "version.h"
+#include "json-writer.h"
 #include "trace2/tr2_dst.h"
 #include "trace2/tr2_sid.h"
 #include "trace2/tr2_tbuf.h"
@@ -499,6 +500,25 @@ static void fn_data_fl(const char *file, int line,
 	strbuf_release(&buf_payload);
 }
 
+static void fn_data_json_fl(const char *file, int line,
+			    uint64_t us_elapsed_absolute,
+			    uint64_t us_elapsed_region,
+			    const char *category,
+			    const struct repository *repo,
+			    const char *key,
+			    const struct json_writer *value)
+{
+	const char *event_name = "data_json";
+	struct strbuf buf_payload = STRBUF_INIT;
+
+	strbuf_addf(&buf_payload, "%s:%s", key, value->json.buf);
+
+	perf_io_write_fl(file, line, event_name, repo,
+			 &us_elapsed_absolute, &us_elapsed_region, category,
+			 &buf_payload);
+	strbuf_release(&buf_payload);
+}
+
 static void fn_printf_va_fl(const char *file, int line,
 			    uint64_t us_elapsed_absolute,
 			    const char *fmt, va_list ap)
@@ -542,5 +562,6 @@ struct tr2_tgt tr2_tgt_perf =
 	fn_region_enter_printf_va_fl,
 	fn_region_leave_printf_va_fl,
 	fn_data_fl,
+	fn_data_json_fl,
 	fn_printf_va_fl,
 };

From ab6ffefe68630e5eb2c505678520a5939d904da5 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 19 Nov 2018 15:47:30 -0500
Subject: [PATCH 06/23] trace2: add child-pid to child_exit event

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 trace2.c                | 1 +
 trace2/tr2_tgt.h        | 2 +-
 trace2/tr2_tgt_event.c  | 3 ++-
 trace2/tr2_tgt_normal.c | 6 +++---
 trace2/tr2_tgt_perf.c   | 5 +++--
 5 files changed, 10 insertions(+), 7 deletions(-)

diff --git a/trace2.c b/trace2.c
index 4e72ce6fb1161f..85d05589964d69 100644
--- a/trace2.c
+++ b/trace2.c
@@ -362,6 +362,7 @@ void trace2_child_exit_fl(const char *file, int line,
 			tgt_j->pfn_child_exit_fl(
 				file, line, us_elapsed_absolute,
 				cmd->trace2_child_id,
+				cmd->pid,
 				child_exit_code, us_elapsed_child);
 	}
 }
diff --git a/trace2/tr2_tgt.h b/trace2/tr2_tgt.h
index a90944584dd06e..f0c81d1cc5653e 100644
--- a/trace2/tr2_tgt.h
+++ b/trace2/tr2_tgt.h
@@ -42,7 +42,7 @@ typedef void (tr2_tgt_evt_child_start_fl_t)
 	 const struct child_process *cmd);
 typedef void (tr2_tgt_evt_child_exit_fl_t)
 	(const char *file, int line, uint64_t us_elapsed_absolute, int cid,
-	 int code, uint64_t us_elapsed_child);
+	 int pid, int code, uint64_t us_elapsed_child);
 
 typedef void (tr2_tgt_evt_thread_start_fl_t)
 	(const char *file, int line, uint64_t us_elapsed_absolute);
diff --git a/trace2/tr2_tgt_event.c b/trace2/tr2_tgt_event.c
index 9975d535f02046..a75f5c50d416bc 100644
--- a/trace2/tr2_tgt_event.c
+++ b/trace2/tr2_tgt_event.c
@@ -311,7 +311,7 @@ static void fn_child_start_fl(const char *file, int line,
 
 static void fn_child_exit_fl(const char *file, int line,
 			     uint64_t us_elapsed_absolute,
-			     int cid, int code,
+			     int cid, int pid, int code,
 			     uint64_t us_elapsed_child)
 {
 	const char *event_name = "child_exit";
@@ -321,6 +321,7 @@ static void fn_child_exit_fl(const char *file, int line,
 	jw_object_begin(&jw, 0);
 	event_fmt_prepare(event_name, file, line, NULL, &jw);
 	jw_object_intmax(&jw, "child_id", cid);
+	jw_object_intmax(&jw, "pid", pid);
 	jw_object_intmax(&jw, "code", code);
 	jw_object_double(&jw, "t_rel", 6, t_rel);
 	jw_end(&jw);
diff --git a/trace2/tr2_tgt_normal.c b/trace2/tr2_tgt_normal.c
index b5ed6bf82a4b88..1b0a98b9683ced 100644
--- a/trace2/tr2_tgt_normal.c
+++ b/trace2/tr2_tgt_normal.c
@@ -228,14 +228,14 @@ static void fn_child_start_fl(const char *file, int line,
 
 static void fn_child_exit_fl(const char *file, int line,
 			     uint64_t us_elapsed_absolute,
-			     int cid, int code,
+			     int cid, int pid, int code,
 			     uint64_t us_elapsed_child)
 {
 	struct strbuf buf_payload = STRBUF_INIT;
 	double elapsed = (double)us_elapsed_child / 1000000.0;
 
-	strbuf_addf(&buf_payload, "child_exit[%d] code:%d elapsed:%.6f",
-		    cid, code, elapsed);
+	strbuf_addf(&buf_payload, "child_exit[%d] pid:%d code:%d elapsed:%.6f",
+		    cid, pid, code, elapsed);
 	normal_io_write_fl(file, line, &buf_payload);
 	strbuf_release(&buf_payload);
 }
diff --git a/trace2/tr2_tgt_perf.c b/trace2/tr2_tgt_perf.c
index 8df8728ffeb607..e3b32993766053 100644
--- a/trace2/tr2_tgt_perf.c
+++ b/trace2/tr2_tgt_perf.c
@@ -337,12 +337,13 @@ static void fn_child_start_fl(const char *file, int line,
 
 static void fn_child_exit_fl(const char *file, int line,
 			     uint64_t us_elapsed_absolute,
-			     int cid, int code, uint64_t us_elapsed_child)
+			     int cid, int pid, int code,
+			     uint64_t us_elapsed_child)
 {
 	const char *event_name = "child_exit";
 	struct strbuf buf_payload = STRBUF_INIT;
 
-	strbuf_addf(&buf_payload, "[ch%d] code:%d", cid, code);
+	strbuf_addf(&buf_payload, "[ch%d] pid:%d code:%d", cid, pid, code);
 
 	perf_io_write_fl(file, line, event_name, NULL,
 			 &us_elapsed_absolute, &us_elapsed_child, NULL,

From e20723514e080e20fa2394420599c65f5a910bc5 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 12 Nov 2018 13:54:16 -0500
Subject: [PATCH 07/23] trace2: add optional platform process-info event

Add platform-specific "data" events with information about the
current process.

On Windows, this includes whether git.exe is running under a
debugger and information about the process ancestors.  This lets
post-processors know if git.exe was launched interactively or
in the background by an IDE or GVFS daemon, for example.

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 common-main.c           |   1 +
 compat/win32/ancestry.c | 102 ++++++++++++++++++++++++++++++++++++++++
 config.mak.uname        |   6 ++-
 trace2.h                |  13 +++++
 4 files changed, 120 insertions(+), 2 deletions(-)
 create mode 100644 compat/win32/ancestry.c

diff --git a/common-main.c b/common-main.c
index 6dbdc4adf272ef..d484aec20979ac 100644
--- a/common-main.c
+++ b/common-main.c
@@ -37,6 +37,7 @@ int main(int argc, const char **argv)
 
 	trace2_initialize();
 	trace2_cmd_start(argv);
+	trace2_collect_process_info();
 
 	git_resolve_executable_dir(argv[0]);
 
diff --git a/compat/win32/ancestry.c b/compat/win32/ancestry.c
new file mode 100644
index 00000000000000..7ed3cc66618c95
--- /dev/null
+++ b/compat/win32/ancestry.c
@@ -0,0 +1,102 @@
+#include "../../cache.h"
+#include "../../json-writer.h"
+#include <Psapi.h>
+#include <tlHelp32.h>
+
+/*
+ * Find the process data for the given PID in the given snapshot
+ * and update the PROCESSENTRY32 data.
+ */
+static int find_pid(DWORD pid, HANDLE hSnapshot, PROCESSENTRY32 *pe32)
+{
+	pe32->dwSize = sizeof(PROCESSENTRY32);
+
+	if (Process32First(hSnapshot, pe32)) {
+		do {
+			if (pe32->th32ProcessID == pid)
+				return 1;
+		} while (Process32Next(hSnapshot, pe32));
+	}
+	return 0;
+}
+
+/*
+ * Accumulate JSON array:
+ *     [
+ *         exe-name-parent,
+ *         exe-name-grand-parent,
+ *         ...
+ *     ]
+ *
+ * Note: we only report the filename of the process executable; the
+ *       only way to get its full pathname is to use OpenProcess()
+ *       and GetModuleFileNameEx() or QueryfullProcessImageName()
+ *       and that seems rather expensive (on top of the cost of
+ *       getting the snapshot).
+ */
+static void get_processes(struct json_writer *jw, HANDLE hSnapshot)
+{
+	PROCESSENTRY32 pe32;
+	DWORD pid;
+
+	pid = GetCurrentProcessId();
+
+	/* We only want parent processes, so skip self. */
+	if (!find_pid(pid, hSnapshot, &pe32))
+		return;
+	pid = pe32.th32ParentProcessID;
+
+	while (find_pid(pid, hSnapshot, &pe32)) {
+
+		jw_array_string(jw, pe32.szExeFile);
+
+		pid = pe32.th32ParentProcessID;
+	}
+}
+
+/*
+ * Emit JSON data for the current and parent processes.  Individual
+ * trace2 targets can decide how to actually print it.
+ */
+static void get_ancestry(void)
+{
+	HANDLE hSnapshot = CreateToolhelp32Snapshot(TH32CS_SNAPPROCESS, 0);
+
+	if (hSnapshot != INVALID_HANDLE_VALUE) {
+		struct json_writer jw = JSON_WRITER_INIT;
+
+		jw_array_begin(&jw, 0);
+		get_processes(&jw, hSnapshot);
+		jw_end(&jw);
+
+		trace2_data_json("process", the_repository,
+				 "windows/ancestry", &jw);
+
+		jw_release(&jw);
+		CloseHandle(hSnapshot);
+	}
+}
+
+/*
+ * Is a debugger attached to the current process?
+ *
+ * This will catch debug runs (where the debugger started the process).
+ * This is the normal case.  Since this code is called during our startup,
+ * it will not report instances where a debugger is attached dynamically
+ * to a running git process, but that is relatively rare.
+ */
+static void get_is_being_debugged(void)
+{
+	if (IsDebuggerPresent())
+		trace2_data_intmax("process", the_repository,
+			   "windows/debugger_present", 1);
+}
+
+void trace2_collect_process_info(void)
+{
+	if (!trace2_is_enabled())
+		return;
+
+	get_is_being_debugged();
+	get_ancestry();
+}
diff --git a/config.mak.uname b/config.mak.uname
index c329b2d1204095..7d8289a261f7e4 100644
--- a/config.mak.uname
+++ b/config.mak.uname
@@ -424,7 +424,8 @@ ifeq ($(uname_S),Windows)
 	BASIC_CFLAGS = -nologo -I. -Icompat/vcbuild/include -DWIN32 -D_CONSOLE -DHAVE_STRING_H -D_CRT_SECURE_NO_WARNINGS -D_CRT_NONSTDC_NO_DEPRECATE
 	COMPAT_OBJS = compat/msvc.o compat/winansi.o \
 		compat/win32/pthread.o compat/win32/syslog.o \
-		compat/win32/dirent.o compat/win32/fscache.o
+		compat/win32/dirent.o compat/win32/fscache.o \
+		compat/win32/ancestry.o
 	COMPAT_CFLAGS = -D__USE_MINGW_ACCESS -DDETECT_MSYS_TTY -DNOGDI -DHAVE_STRING_H -Icompat -Icompat/regex -Icompat/win32 -DSTRIP_EXTENSION=\".exe\"
 	BASIC_LDFLAGS = -IGNORE:4217 -IGNORE:4049 -NOLOGO -ENTRY:wmainCRTStartup -SUBSYSTEM:CONSOLE
 	# invalidcontinue.obj allows Git's source code to close the same file
@@ -586,7 +587,8 @@ ifneq (,$(findstring MINGW,$(uname_S)))
 	COMPAT_CFLAGS += -DSTRIP_EXTENSION=\".exe\"
 	COMPAT_OBJS += compat/mingw.o compat/winansi.o \
 		compat/win32/pthread.o compat/win32/syslog.o \
-		compat/win32/dirent.o compat/win32/fscache.o
+		compat/win32/dirent.o compat/win32/fscache.o \
+		compat/win32/ancestry.o
 	BASIC_CFLAGS += -DWIN32 -DPROTECT_NTFS_DEFAULT=1
 	EXTLIBS += -lws2_32
 	GITLIBS += git.res
diff --git a/trace2.h b/trace2.h
index ce89d040b91a50..1909d9d60394c9 100644
--- a/trace2.h
+++ b/trace2.h
@@ -387,4 +387,17 @@ __attribute__((format (printf, 1, 2)))
 void trace2_printf(const char *fmt, ...);
 #endif
 
+/*
+ * Optional platform-specific code to dump information about the
+ * current and any parent process(es).  This is intended to allow
+ * post-processors to know who spawned this git instance and anything
+ * else the platform may be able to tell us about the current process.
+ */
+#if defined(GIT_WINDOWS_NATIVE)
+void trace2_collect_process_info(void);
+#else
+#define trace2_collect_process_info() \
+	do {} while (0)
+#endif
+
 #endif /* TRACE2_H */

From 91c27d9bf2b948dbf6601b174984f74f6be8f990 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Thu, 11 Oct 2018 16:35:36 -0400
Subject: [PATCH 08/23] trace2: t/helper/test-trace2

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 Makefile                  |   1 +
 t/helper/test-tool.c      |   1 +
 t/helper/test-tool.h      |   1 +
 t/helper/test-trace2.c    | 273 ++++++++++++++++++++++++++++++++++++++
 t/t0210-trace2-normal.sh  | 141 ++++++++++++++++++++
 t/t0210/scrub_normal.perl |  42 ++++++
 t/t0211-trace2-perf.sh    | 162 ++++++++++++++++++++++
 t/t0211/scrub_perf.perl   |  71 ++++++++++
 t/t0212-trace2-event.sh   | 237 +++++++++++++++++++++++++++++++++
 t/t0212/parse_events.perl | 245 ++++++++++++++++++++++++++++++++++
 10 files changed, 1174 insertions(+)
 create mode 100644 t/helper/test-trace2.c
 create mode 100755 t/t0210-trace2-normal.sh
 create mode 100644 t/t0210/scrub_normal.perl
 create mode 100755 t/t0211-trace2-perf.sh
 create mode 100644 t/t0211/scrub_perf.perl
 create mode 100755 t/t0212-trace2-event.sh
 create mode 100644 t/t0212/parse_events.perl

diff --git a/Makefile b/Makefile
index 9e2a349c9106ef..347728adaa1d2e 100644
--- a/Makefile
+++ b/Makefile
@@ -756,6 +756,7 @@ TEST_BUILTINS_OBJS += test-string-list.o
 TEST_BUILTINS_OBJS += test-submodule-config.o
 TEST_BUILTINS_OBJS += test-submodule-nested-repo-config.o
 TEST_BUILTINS_OBJS += test-subprocess.o
+TEST_BUILTINS_OBJS += test-trace2.o
 TEST_BUILTINS_OBJS += test-urlmatch-normalization.o
 TEST_BUILTINS_OBJS += test-wildmatch.o
 TEST_BUILTINS_OBJS += test-windows-named-pipe.o
diff --git a/t/helper/test-tool.c b/t/helper/test-tool.c
index cfb46a720ea919..da2301e5dd0b0c 100644
--- a/t/helper/test-tool.c
+++ b/t/helper/test-tool.c
@@ -51,6 +51,7 @@ static struct test_cmd cmds[] = {
 	{ "submodule-config", cmd__submodule_config },
 	{ "submodule-nested-repo-config", cmd__submodule_nested_repo_config },
 	{ "subprocess", cmd__subprocess },
+	{ "trace2", cmd__trace2 },
 	{ "urlmatch-normalization", cmd__urlmatch_normalization },
 	{ "wildmatch", cmd__wildmatch },
 #ifdef GIT_WINDOWS_NATIVE
diff --git a/t/helper/test-tool.h b/t/helper/test-tool.h
index 955490ec9f29f1..07e8fa174ee183 100644
--- a/t/helper/test-tool.h
+++ b/t/helper/test-tool.h
@@ -46,6 +46,7 @@ int cmd__string_list(int argc, const char **argv);
 int cmd__submodule_config(int argc, const char **argv);
 int cmd__submodule_nested_repo_config(int argc, const char **argv);
 int cmd__subprocess(int argc, const char **argv);
+int cmd__trace2(int argc, const char **argv);
 int cmd__urlmatch_normalization(int argc, const char **argv);
 int cmd__wildmatch(int argc, const char **argv);
 #ifdef GIT_WINDOWS_NATIVE
diff --git a/t/helper/test-trace2.c b/t/helper/test-trace2.c
new file mode 100644
index 00000000000000..b867f58d32cb36
--- /dev/null
+++ b/t/helper/test-trace2.c
@@ -0,0 +1,273 @@
+#include "test-tool.h"
+#include "cache.h"
+#include "argv-array.h"
+#include "run-command.h"
+#include "exec-cmd.h"
+#include "config.h"
+
+typedef int (fn_unit_test)(int argc, const char **argv);
+
+struct unit_test 
+{
+	fn_unit_test *ut_fn;
+	const char   *ut_name;
+	const char   *ut_usage;
+};
+
+#define MyOk    0
+#define MyError 1
+
+static int get_i(int *p_value, const char *data)
+{
+	char *endptr;
+
+	if (!data || !*data)
+		return MyError;
+
+	*p_value = strtol(data, &endptr, 10);
+	if (*endptr || errno == ERANGE)
+		return MyError;
+
+	return MyOk;
+}
+
+/*
+ * Cause process to exit with the requested value via "return".
+ *
+ * Rely on test-tool.c:cmd_main() to call trace2_cmd_exit()
+ * with our result.
+ *
+ * Test harness can confirm:
+ * [] the process-exit value.
+ * [] the "code" field in the "exit" trace2 event.
+ * [] the "code" field in the "atexit" trace2 event.
+ * [] the "name" field in the "cmd_verb" trace2 event.
+ * [] "def_param" events for all of the "interesting" pre-defined config settings.
+ */
+static int ut_001return(int argc, const char **argv)
+{
+	int rc;
+
+	if (get_i(&rc, argv[0]))
+		die("expect <exit_code>");
+
+	return rc;
+}
+
+/*
+ * Cause the process to exit with the requested value via "exit()".
+ *
+ * Test harness can confirm:
+ * [] the "code" field in the "exit" trace2 event.
+ * [] the "code" field in the "atexit" trace2 event.
+ * [] the "name" field in the "cmd_verb" trace2 event.
+ * [] "def_param" events for all of the "interesting" pre-defined config settings.
+ */
+static int ut_002exit(int argc, const char **argv)
+{
+	int rc;
+
+	if (get_i(&rc, argv[0]))
+		die("expect <exit_code>");
+
+	exit(rc);
+}
+
+/*
+ * Send an "error" event with each value in argv.  Normally, git only issues
+ * a single "error" event immediately before issuing an "exit" event (such
+ * as in die() or BUG()), but multiple "error" events are allowed.
+ *
+ * Test harness can confirm:
+ * [] a trace2 "error" event for each value in argv.
+ * [] the "name" field in the "cmd_verb" trace2 event.
+ * [] (optional) the file:line in the "exit" event refers to this function.
+ */
+static int ut_003error(int argc, const char **argv)
+{
+	int k;
+
+	if (!argv[0] || !*argv[0])
+		die("expect <error_message>");
+
+	for (k = 0; k < argc; k++)
+		error("%s", argv[k]);
+
+	return 0;
+}
+
+/*
+ * Run a child process and wait for it to finish and exit with its return code.
+ * test-tool trace2 004child [<child-command-line>]
+ *
+ * For example:
+ * test-tool trace2 004child git version
+ * test-tool trace2 004child test-tool trace2 001return 0
+ * test-tool trace2 004child test-tool trace2 004child test-tool trace2 004child
+ * test-tool trace2 004child git -c alias.xyz=version xyz
+ *
+ * Test harness can confirm:
+ * [] the "name" field in the "cmd_verb" trace2 event.
+ * [] that the outer process has a single component SID (or depth "d0" in
+ *    the PERF stream).
+ * [] that "child_start" and "child_exit" events are generated for the child.
+ * [] if the child process is an instrumented executable:
+ *    [] that "version", "start", ..., "exit", and "atexit" events are
+ *       generated by the child process.
+ *    [] that the child process events have a multiple component SID (or
+ *       depth "dN+1" in the PERF stream).
+ * [] that the child exit code is propagated to the parent process "exit"
+ *    and "atexit" events..
+ * [] (optional) that the "t_abs" field in the child process "atexit" event
+ *    is less than the "t_rel" field in the "child_exit" event of the parent
+ *    process.
+ * [] if the child process is like the alias example above,
+ *    [] (optional) the child process attempts to run "git-xyx" as a dashed
+ *       command.
+ *    [] the child process emits an "alias" event with "xyz" => "version"
+ *    [] the child process runs "git version" as a child process.
+ *    [] the child process has a 3 component SID (or depth "d2" in the PERF
+ *       stream).
+ */
+static int ut_004child(int argc, const char **argv)
+{
+	int result;
+
+	/*
+	 * Allow empty <child_command_line> so we can do arbitrarily deep
+	 * command nesting and let the last one be null.
+	 */
+	if (!argc)
+		return 0;
+
+	result = run_command_v_opt(argv, 0);
+	exit(result);
+}
+
+/*
+ * Exec a git command.  This may either create a child process (Windows)
+ * or replace the existing process.
+ * test-tool trace2 005exec <git_command_args>
+ *
+ * For example:
+ * test-tool trace2 005exec version
+ *
+ * Test harness can confirm (on Windows):
+ * [] the "name" field in the "cmd_verb" trace2 event.
+ * [] that the outer process has a single component SID (or depth "d0" in
+ *    the PERF stream).
+ * [] that "exec" and "exec_result" events are generated for the child
+ *    process (since the Windows compatibility layer fakes an exec() with
+ *    a CreateProcess(), WaitForSingleObject(), and exit()).
+ * [] that the child process has multiple component SID (or depth "dN+1"
+ *    in the PERF stream).
+ *
+ * Test harness can confirm (on platforms with a real exec() function):
+ * [] TODO talk about process replacement and how it affects SID.
+ */ 
+static int ut_005exec(int argc, const char **argv)
+{
+	int result;
+
+	if (!argc)
+		return 0;
+
+	result = execv_git_cmd(argv);
+	return result;
+}
+
+static int ut_006data(int argc, const char **argv)
+{
+	const char *usage_error =
+		"expect <cat0> <k0> <v0> [<cat1> <k1> <v1> [...]]";
+
+	if (argc % 3 != 0)
+		die("%s", usage_error);
+
+	while (argc) {
+		if (!argv[0] || !*argv[0] ||
+		    !argv[1] || !*argv[1] ||
+		    !argv[2] || !*argv[2])
+			die("%s", usage_error);
+
+		trace2_data_string(argv[0], the_repository, argv[1], argv[2]);
+		argv += 3;
+		argc -= 3;
+	}
+
+	return 0;
+}
+
+/*
+ * Usage:
+ *     test-tool trace2 <ut_name_1> <ut_usage_1>
+ *     test-tool trace2 <ut_name_2> <ut_usage_2>
+ *     ...
+ */ 
+#define USAGE_PREFIX "test-tool trace2"
+
+static struct unit_test ut_table[] = {
+	{ ut_001return,   "001return", "<exit_code>" },
+	{ ut_002exit,     "002exit",   "<exit_code>" },
+	{ ut_003error,    "003error",  "<error_message>+" },
+	{ ut_004child,    "004child",  "[<child_command_line>]" },
+	{ ut_005exec,     "005exec",   "<git_command_args>" },
+	{ ut_006data,     "006data",   "[<category> <key> <value>]+" },
+};
+
+#define for_each_ut(k, ut_k)			\
+	for (k = 0, ut_k = &ut_table[k];	\
+	     k < ARRAY_SIZE(ut_table);		\
+	     k++, ut_k = &ut_table[k])
+
+static int print_usage(void)
+{
+	int k;
+	struct unit_test *ut_k;
+
+	fprintf(stderr, "usage:\n");
+	for_each_ut(k, ut_k) {
+		fprintf(stderr, "\t%s %s %s\n",
+			USAGE_PREFIX, ut_k->ut_name, ut_k->ut_usage);
+	}
+
+	return 129;
+}
+
+/*
+ * Issue various trace2 events for testing.
+ *
+ * We assume that these trace2 routines has already been called:
+ *    [] trace2_initialize()      [common-main.c:main()]
+ *    [] trace2_cmd_start()       [common-main.c:main()]
+ *    [] trace2_cmd_verb()        [test-tool.c:cmd_main()]
+ *    [] tracd2_cmd_list_config() [test-tool.c:cmd_main()]
+ * So that:
+ *    [] the various trace2 streams are open.
+ *    [] the process SID has been created.
+ *    [] the "version" event has been generated.
+ *    [] the "start" event has been generated.
+ *    [] the "verb" event has been generated.
+ *    [] this writes various "def_param" events for interesting config values.
+ *
+ * We further assume that if we return (rather than exit()), trace2_cmd_exit()
+ * will be called by test-tool.c:cmd_main().
+ */
+int cmd__trace2(int argc, const char **argv)
+{
+	int k;
+	struct unit_test *ut_k;
+
+	argc--;	/* skip over "trace2" arg */
+	argv++;
+
+	if (argc) {
+		for_each_ut(k, ut_k) {
+			if (!strcmp(argv[0], ut_k->ut_name))
+				return ut_k->ut_fn(argc - 1, argv + 1);
+		}
+	}
+
+	return print_usage();
+}
+
diff --git a/t/t0210-trace2-normal.sh b/t/t0210-trace2-normal.sh
new file mode 100755
index 00000000000000..985fbd710420fe
--- /dev/null
+++ b/t/t0210-trace2-normal.sh
@@ -0,0 +1,141 @@
+#!/bin/sh
+
+test_description='test trace2 facility (normal target)'
+. ./test-lib.sh
+
+# Add t/helper directory to PATH so that we can use a relative
+# path to run nested instances of test-tool.exe (see 004child).
+# This helps with HEREDOC comparisons later.
+TTDIR="$GIT_BUILD_DIR/t/helper/" && export TTDIR
+PATH="$TTDIR:$PATH" && export PATH
+
+TT="test-tool" && export TT
+
+# Warning: use of 'test_cmp' may run test-tool.exe and/or git.exe
+# Warning: to do the actual diff/comparison, so the HEREDOCs here
+# Warning: only cover our actual calls to test-tool and/or git.
+# Warning: So you may see extra lines in artifact files when
+# Warning: interactively debugging.
+
+# Turn off any inherited trace2 settings for this test.
+unset GIT_TR2 GIT_TR2_PERF GIT_TR2_EVENT
+unset GIT_TR2_BARE
+unset GIT_TR2_CONFIG_PARAMS
+
+V=$(git version | sed -e 's/^git version //') && export V
+
+# There are multiple trace2 targets: normal, perf, and event.
+# Trace2 events will/can be written to each active target (subject
+# to whatever filtering that target decides to do).
+# This script tests the normal target in isolation.
+
+# Enable "normal" trace2 target.
+GIT_TR2="$(pwd)/trace.normal" && export GIT_TR2
+# Enable "bare" feature which turns off "<clock> <file>:<line> " prefix.
+GIT_TR2_BARE=1 && export GIT_TR2_BARE
+
+# Basic tests of the trace2 normal stream.  Since this stream is used
+# primarily with printf-style debugging/tracing, we do limited testing
+# here.
+#
+# We do confirm the following API features:
+# [] the 'version <v>' event
+# [] the 'start <argv>' event
+# [] the 'cmd_path <argv[0]>' event
+# [] the 'cmd_verb <verb>' event
+# [] the 'exit <time> code:<code>' event
+# [] the 'atexit <time> code:<code>' event
+#
+# Fields of the form _FIELD_ are tokens that have been replaced (such
+# as the elapsed time).
+
+# Verb 001return
+#
+# Implicit return from cmd_<verb> function propagates <code>.
+
+test_expect_success 'normal stream, return code 0' '
+	test_when_finished "rm trace.normal actual expect" &&
+	$TT trace2 001return 0 &&
+	perl "$TEST_DIRECTORY/t0210/scrub_normal.perl" <trace.normal >actual &&
+	cat >expect <<-EOF &&
+		version $V
+		start _EXE_ trace2 001return 0
+		cmd_path _EXE_
+		cmd_verb trace2
+		exit elapsed:_TIME_ code:0
+		atexit elapsed:_TIME_ code:0
+	EOF
+	test_cmp expect actual
+'
+
+test_expect_success 'normal stream, return code 1' '
+	test_when_finished "rm trace.normal actual expect" &&
+	test_must_fail $TT trace2 001return 1 &&
+	perl "$TEST_DIRECTORY/t0210/scrub_normal.perl" <trace.normal >actual &&
+	cat >expect <<-EOF &&
+		version $V
+		start _EXE_ trace2 001return 1
+		cmd_path _EXE_
+		cmd_verb trace2
+		exit elapsed:_TIME_ code:1
+		atexit elapsed:_TIME_ code:1
+	EOF
+	test_cmp expect actual
+'
+
+# Verb 002exit
+#
+# Explicit exit(code) from within cmd_<verb> propagates <code>.
+
+test_expect_success 'normal stream, exit code 0' '
+	test_when_finished "rm trace.normal actual expect" &&
+	$TT trace2 002exit 0 &&
+	perl "$TEST_DIRECTORY/t0210/scrub_normal.perl" <trace.normal >actual &&
+	cat >expect <<-EOF &&
+		version $V
+		start _EXE_ trace2 002exit 0
+		cmd_path _EXE_
+		cmd_verb trace2
+		exit elapsed:_TIME_ code:0
+		atexit elapsed:_TIME_ code:0
+	EOF
+	test_cmp expect actual
+'
+
+test_expect_success 'normal stream, exit code 1' '
+	test_when_finished "rm trace.normal actual expect" &&
+	test_must_fail $TT trace2 002exit 1 &&
+	perl "$TEST_DIRECTORY/t0210/scrub_normal.perl" <trace.normal >actual &&
+	cat >expect <<-EOF &&
+		version $V
+		start _EXE_ trace2 002exit 1
+		cmd_path _EXE_
+		cmd_verb trace2
+		exit elapsed:_TIME_ code:1
+		atexit elapsed:_TIME_ code:1
+	EOF
+	test_cmp expect actual
+'
+
+# Verb 003error
+#
+# To the above, add multiple 'error <msg>' events
+
+test_expect_success 'normal stream, error event' '
+	test_when_finished "rm trace.normal actual expect" &&
+	$TT trace2 003error "hello world" "this is a test" &&
+	perl "$TEST_DIRECTORY/t0210/scrub_normal.perl" <trace.normal >actual &&
+	cat >expect <<-EOF &&
+		version $V
+		start _EXE_ trace2 003error '\''hello world'\'' '\''this is a test'\''
+		cmd_path _EXE_
+		cmd_verb trace2
+		error hello world
+		error this is a test
+		exit elapsed:_TIME_ code:0
+		atexit elapsed:_TIME_ code:0
+	EOF
+	test_cmp expect actual
+'
+
+test_done
diff --git a/t/t0210/scrub_normal.perl b/t/t0210/scrub_normal.perl
new file mode 100644
index 00000000000000..fc58c77cb912aa
--- /dev/null
+++ b/t/t0210/scrub_normal.perl
@@ -0,0 +1,42 @@
+#!/usr/bin/perl
+#
+# Scrub the variable fields from the normal trace2 output to
+# make testing easier.
+
+use strict;
+use warnings;
+
+my $space = '\W+';
+my $qpath = '\'[^\']*\'';
+my $string= '.*';
+my $float = '[0-9]*\.[0-9]+([eE][-+]?[0-9]+)?';
+
+my $verb;
+my $rest;
+
+# This code assumes that the trace2 data was written with bare
+# turned on (which omits the "<clock> <file>:<line>" prefix.
+
+while (<>) {
+    # Various messages include an elapsed time in the middle
+    # of the message.  Replace the time with a placeholder to
+    # simplify our HEREDOC in the test script.
+    s/elapsed:$float/elapsed:_TIME_/g;
+
+    if ($_ =~ m/^start/) {
+	# The 'start' message lists the contents of argv.  On some
+	# platforms (Windows), argv[0] is a canonical absolute path to
+	# the EXE rather than the value passed in the shell script.
+	# Replace it with a placeholder to simplify our HEREDOC in the
+	# test script.
+	($verb, $rest) = (m/^(start) $space $qpath $space ($string)/x);
+	print "$verb _EXE_ $rest\n";
+    }
+    elsif ($_ =~ m/^cmd_path/) {
+	# Likewise, the 'cmd_path' message breaks out argv[0].
+	print "cmd_path _EXE_\n";
+    }
+    else {
+	print "$_";
+    }
+}
diff --git a/t/t0211-trace2-perf.sh b/t/t0211-trace2-perf.sh
new file mode 100755
index 00000000000000..915960ff08b515
--- /dev/null
+++ b/t/t0211-trace2-perf.sh
@@ -0,0 +1,162 @@
+#!/bin/sh
+
+test_description='test trace2 facility (perf target)'
+. ./test-lib.sh
+
+# Add t/helper directory to PATH so that we can use a relative
+# path to run nested instances of test-tool.exe (see 004child).
+# This helps with HEREDOC comparisons later.
+TTDIR="$GIT_BUILD_DIR/t/helper/" && export TTDIR
+PATH="$TTDIR:$PATH" && export PATH
+
+TT="test-tool" && export TT
+
+# Warning: use of 'test_cmp' may run test-tool.exe and/or git.exe
+# Warning: to do the actual diff/comparison, so the HEREDOCs here
+# Warning: only cover our actual calls to test-tool and/or git.
+# Warning: So you may see extra lines in artifact files when
+# Warning: interactively debugging.
+
+# Turn off any inherited trace2 settings for this test.
+unset GIT_TR2 GIT_TR2_PERF GIT_TR2_EVENT
+unset GIT_TR2_BARE
+unset GIT_TR2_CONFIG_PARAMS
+
+V=$(git version | sed -e 's/^git version //') && export V
+
+# There are multiple trace2 targets: normal, perf, and event.
+# Trace2 events will/can be written to each active target (subject
+# to whatever filtering that target decides to do).
+# Test each target independently.
+
+# Enable "perf" trace2 target.
+GIT_TR2_PERF="$(pwd)/trace.perf" && export GIT_TR2_PERF
+# Enable "bare" feature which turns off the prefix:
+#     "<clock> <file>:<line> | <nr_parents> | "
+GIT_TR2_BARE=1 && export GIT_TR2_BARE
+
+# Repeat some of the t0210 tests using the perf target stream instead of
+# the normal stream.
+#
+# Tokens here of the form _FIELD_ have been replaced in the observed output.
+
+# Verb 001return
+#
+# Implicit return from cmd_<verb> function propagates <code>.
+
+test_expect_success 'perf stream, return code 0' '
+	test_when_finished "rm trace.perf actual expect" &&
+	$TT trace2 001return 0 &&
+	perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual &&
+	cat >expect <<-EOF &&
+		main|version|||||$V
+		main|start|||||_EXE_ trace2 001return 0
+		main|cmd_path|||||_EXE_
+		main|cmd_verb|||||trace2
+		main|exit||_T_ABS_|||code:0
+		main|atexit||_T_ABS_|||code:0
+	EOF
+	test_cmp expect actual
+'
+
+test_expect_success 'perf stream, return code 1' '
+	test_when_finished "rm trace.perf actual expect" &&
+	test_must_fail $TT trace2 001return 1 &&
+	perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual &&
+	cat >expect <<-EOF &&
+		main|version|||||$V
+		main|start|||||_EXE_ trace2 001return 1
+		main|cmd_path|||||_EXE_
+		main|cmd_verb|||||trace2
+		main|exit||_T_ABS_|||code:1
+		main|atexit||_T_ABS_|||code:1
+	EOF
+	test_cmp expect actual
+'
+
+# Verb 003error
+#
+# To the above, add multiple 'error <msg>' events
+
+test_expect_success 'perf stream, error event' '
+	test_when_finished "rm trace.perf actual expect" &&
+	$TT trace2 003error "hello world" "this is a test" &&
+	perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual &&
+	cat >expect <<-EOF &&
+		main|version|||||$V
+		main|start|||||_EXE_ trace2 003error '\''hello world'\'' '\''this is a test'\''
+		main|cmd_path|||||_EXE_
+		main|cmd_verb|||||trace2
+		main|error|||||hello world
+		main|error|||||this is a test
+		main|exit||_T_ABS_|||code:0
+		main|atexit||_T_ABS_|||code:0
+	EOF
+	test_cmp expect actual
+'
+
+# Verb 004child
+#
+# Test nested spawning of child processes.
+#
+# Conceptually, this looks like:
+#    P1: TT trace2 004child
+#    P2: |--- TT trace2 004child
+#    P3:      |--- TT trace2 001return 0
+#
+# Which should generate events:
+#    P1: version
+#    P1: start
+#    P1: cmd_path
+#    P1: cmd_verb
+#    P1: child_start
+#        P2: version
+#        P2: start
+#        P2: cmd_path
+#        P2: cmd_verb
+#        P2: child_start
+#            P3: version
+#            P3: start
+#            P3: cmd_path
+#            P3: cmd_verb
+#            P3: exit
+#            P3: atexit
+#        P2: child_exit
+#        P2: exit
+#        P2: atexit
+#    P1: child_exit
+#    P1: exit
+#    P1: atexit
+
+test_expect_success 'perf stream, child processes' '
+	test_when_finished "rm trace.perf actual expect" &&
+	$TT trace2 004child $TT trace2 004child $TT trace2 001return 0 &&
+	perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual &&
+	cat >expect <<-EOF &&
+		main|version|||||$V
+		main|start|||||_EXE_ trace2 004child $TT trace2 004child $TT trace2 001return 0
+		main|cmd_path|||||_EXE_
+		main|cmd_verb|||||trace2
+		main|child_start||_T_ABS_|||[ch0] class:? argv: $TT trace2 004child $TT trace2 001return 0
+		main|version|||||$V
+		main|start|||||_EXE_ trace2 004child $TT trace2 001return 0
+		main|cmd_path|||||_EXE_
+		main|cmd_verb|||||trace2
+		main|child_start||_T_ABS_|||[ch0] class:? argv: $TT trace2 001return 0
+		main|version|||||$V
+		main|start|||||_EXE_ trace2 001return 0
+		main|cmd_path|||||_EXE_
+		main|cmd_verb|||||trace2
+		main|exit||_T_ABS_|||code:0
+		main|atexit||_T_ABS_|||code:0
+		main|child_exit||_T_ABS_|_T_REL_||[ch0] pid:_PID_ code:0
+		main|exit||_T_ABS_|||code:0
+		main|atexit||_T_ABS_|||code:0
+		main|child_exit||_T_ABS_|_T_REL_||[ch0] pid:_PID_ code:0
+		main|exit||_T_ABS_|||code:0
+		main|atexit||_T_ABS_|||code:0
+	EOF
+	test_cmp expect actual
+'
+
+test_done
diff --git a/t/t0211/scrub_perf.perl b/t/t0211/scrub_perf.perl
new file mode 100644
index 00000000000000..153bc727f9c325
--- /dev/null
+++ b/t/t0211/scrub_perf.perl
@@ -0,0 +1,71 @@
+#!/usr/bin/perl
+#
+# Scrub the variable fields from the perf trace2 output to
+# make testing easier.
+
+use strict;
+use warnings;
+
+my $qpath = '\'[^\']*\'|[^ ]*';
+
+my $col_thread=0;
+my $col_verb=1;
+my $col_repo=2;
+my $col_t_abs=3;
+my $col_t_rel=4;
+my $col_category=5;
+my $col_rest=6;
+
+# This code assumes that the trace2 data was written with bare
+# turned on (which omits the "<clock> <file>:<line> | <parents>"
+# prefix.
+
+while (<>) {
+    my @tokens = split /\|/;
+
+    foreach my $col (@tokens) { $col =~ s/^\s+|\s+$//g; }
+
+    if ($tokens[$col_verb] =~ m/^start/) {
+	# The 'start' message lists the contents of argv in $col_rest.
+	# On some platforms (Windows), argv[0] is *sometimes* a canonical
+	# absolute path to the EXE rather than the value passed in the
+	# shell script.  Replace it with a placeholder to simplify our
+	# HEREDOC in the test script.
+	my $argv0;
+	my $argvRest;
+	$tokens[$col_rest] =~ s/^($qpath)\W*(.*)/_EXE_ $2/;
+    }
+    elsif ($tokens[$col_verb] =~ m/cmd_path/) {
+	# Likewise, the 'cmd_path' message breaks out argv[0].
+	$tokens[$col_rest] = "_EXE_";
+    }
+    elsif ($tokens[$col_verb] =~ m/child_exit/) {
+	$tokens[$col_rest] =~ s/ pid:\d* / pid:_PID_ /;
+    }
+    elsif ($tokens[$col_verb] =~ m/data/) {
+	if ($tokens[$col_category] =~ m/process/) {
+	    # 'data' and 'data_json' events containing 'process'
+	    # category data are assumed to be platform-specific
+	    # and highly variable.  Just omit them.
+	    goto SKIP_LINE;
+	}
+    }
+
+    # t_abs and t_rel are either blank or a float.  Replace the float
+    # with a constant for matching the HEREDOC in the test script.
+    if ($tokens[$col_t_abs] =~ m/\d/) {
+	$tokens[$col_t_abs] = "_T_ABS_";
+    }
+    if ($tokens[$col_t_rel] =~ m/\d/) {
+	$tokens[$col_t_rel] = "_T_REL_";
+    }
+
+    my $out;
+
+    $out = join('|', @tokens);
+    print "$out\n";
+
+  SKIP_LINE:
+}
+
+
diff --git a/t/t0212-trace2-event.sh b/t/t0212-trace2-event.sh
new file mode 100755
index 00000000000000..f0915c2be933ea
--- /dev/null
+++ b/t/t0212-trace2-event.sh
@@ -0,0 +1,237 @@
+#!/bin/sh
+
+test_description='test trace2 facility'
+. ./test-lib.sh
+
+# Add t/helper directory to PATH so that we can use a relative
+# path to run nested instances of test-tool.exe (see 004child).
+# This helps with HEREDOC comparisons later.
+TTDIR="$GIT_BUILD_DIR/t/helper/" && export TTDIR
+PATH="$TTDIR:$PATH" && export PATH
+
+TT="test-tool" && export TT
+
+# Warning: use of 'test_cmp' may run test-tool.exe and/or git.exe
+# Warning: to do the actual diff/comparison, so the HEREDOCs here
+# Warning: only cover our actual calls to test-tool and/or git.
+# Warning: So you may see extra lines in artifact files when
+# Warning: interactively debugging.
+
+# Turn off any inherited trace2 settings for this test.
+unset GIT_TR2 GIT_TR2_PERF GIT_TR2_EVENT
+unset GIT_TR2_BARE
+unset GIT_TR2_CONFIG_PARAMS
+
+V=$(git version | sed -e 's/^git version //') && export V
+
+# There are multiple trace2 targets: normal, perf, and event.
+# Trace2 events will/can be written to each active target (subject
+# to whatever filtering that target decides to do).
+# Test each target independently.
+
+# Enable "event" trace2 target.
+GIT_TR2_EVENT="$(pwd)/trace.event" && export GIT_TR2_EVENT
+
+# We don't bother repeating the 001return and 002exit tests, since they
+# have coverage in the normal and perf targets.
+
+# Verb 003error
+#
+# To the above, add multiple 'error <msg>' events
+
+test_expect_success 'event stream, error event' '
+	test_when_finished "rm trace.event actual expect" &&
+	$TT trace2 003error "hello world" "this is a test" &&
+	perl "$TEST_DIRECTORY/t0212/parse_events.perl" <trace.event >actual &&
+	sed -e "s/^|//" >expect <<-EOF &&
+	|VAR1 = {
+	|  "_SID0_":{
+	|    "argv":[
+	|      "_EXE_",
+	|      "trace2",
+	|      "003error",
+	|      "hello world",
+	|      "this is a test"
+	|    ],
+	|    "errors":[
+	|      "hello world",
+	|      "this is a test"
+	|    ],
+	|    "exit_code":0,
+	|    "path":"_EXE_",
+	|    "verb":"trace2",
+	|    "version":"$V"
+	|  }
+	|};
+	EOF
+	test_cmp expect actual
+'
+
+# Verb 004child
+#
+# Test nested spawning of child processes.
+#
+# Conceptually, this looks like:
+#    P1: TT trace2 004child
+#    P2: |--- TT trace2 004child
+#    P3:      |--- TT trace2 001return 0
+
+test_expect_success 'event stream, return code 0' '
+#	test_when_finished "rm trace.event actual expect" &&
+	$TT trace2 004child $TT trace2 004child $TT trace2 001return 0 &&
+	perl "$TEST_DIRECTORY/t0212/parse_events.perl" <trace.event >actual &&
+	sed -e "s/^|//" >expect <<-EOF &&
+	|VAR1 = {
+	|  "_SID0_":{
+	|    "argv":[
+	|      "_EXE_",
+	|      "trace2",
+	|      "004child",
+	|      "$TT",
+	|      "trace2",
+	|      "004child",
+	|      "$TT",
+	|      "trace2",
+	|      "001return",
+	|      "0"
+	|    ],
+	|    "child":{
+	|      "0":{
+	|        "child_argv":[
+	|          "_EXE_",
+	|          "trace2",
+	|          "004child",
+	|          "$TT",
+	|          "trace2",
+	|          "001return",
+	|          "0"
+	|        ],
+	|        "child_class":"?",
+	|        "child_code":0,
+	|        "use_shell":0
+	|      }
+	|    },
+	|    "exit_code":0,
+	|    "path":"_EXE_",
+	|    "verb":"trace2",
+	|    "version":"$V"
+	|  },
+	|  "_SID0_/_SID1_":{
+	|    "argv":[
+	|      "_EXE_",
+	|      "trace2",
+	|      "004child",
+	|      "$TT",
+	|      "trace2",
+	|      "001return",
+	|      "0"
+	|    ],
+	|    "child":{
+	|      "0":{
+	|        "child_argv":[
+	|          "_EXE_",
+	|          "trace2",
+	|          "001return",
+	|          "0"
+	|        ],
+	|        "child_class":"?",
+	|        "child_code":0,
+	|        "use_shell":0
+	|      }
+	|    },
+	|    "exit_code":0,
+	|    "path":"_EXE_",
+	|    "verb":"trace2",
+	|    "version":"$V"
+	|  },
+	|  "_SID0_/_SID1_/_SID2_":{
+	|    "argv":[
+	|      "_EXE_",
+	|      "trace2",
+	|      "001return",
+	|      "0"
+	|    ],
+	|    "exit_code":0,
+	|    "path":"_EXE_",
+	|    "verb":"trace2",
+	|    "version":"$V"
+	|  }
+	|};
+	EOF
+	test_cmp expect actual
+'
+
+# Test listing of all "interesting" config settings.
+
+test_expect_success 'event stream, list config' '
+	test_when_finished "rm trace.event actual expect" &&
+	git config --local t0212.abc 1 &&
+	git config --local t0212.def "hello world" &&
+	# delete events generated by the above config commands
+	rm trace.event &&
+	GIT_TR2_CONFIG_PARAMS="t0212.*" $TT trace2 001return 0 &&
+	perl "$TEST_DIRECTORY/t0212/parse_events.perl" <trace.event >actual &&
+	sed -e "s/^|//" >expect <<-EOF &&
+	|VAR1 = {
+	|  "_SID0_":{
+	|    "argv":[
+	|      "_EXE_",
+	|      "trace2",
+	|      "001return",
+	|      "0"
+	|    ],
+	|    "exit_code":0,
+	|    "params":[
+	|      {
+	|        "param":"t0212.abc",
+	|        "value":"1"
+	|      },
+	|      {
+	|        "param":"t0212.def",
+	|        "value":"hello world"
+	|      }
+	|    ],
+	|    "path":"_EXE_",
+	|    "verb":"trace2",
+	|    "version":"$V"
+	|  }
+	|};
+	EOF
+	test_cmp expect actual
+'
+
+test_expect_success 'basic trace2_data' '
+	test_when_finished "rm trace.event actual expect" &&
+	$TT trace2 006data test_category k1 v1 test_category k2 v2 &&
+	perl "$TEST_DIRECTORY/t0212/parse_events.perl" <trace.event >actual &&
+	sed -e "s/^|//" >expect <<-EOF &&
+	|VAR1 = {
+	|  "_SID0_":{
+	|    "argv":[
+	|      "_EXE_",
+	|      "trace2",
+	|      "006data",
+	|      "test_category",
+	|      "k1",
+	|      "v1",
+	|      "test_category",
+	|      "k2",
+	|      "v2"
+	|    ],
+	|    "data":{
+	|      "test_category":{
+	|        "k1":"v1",
+	|        "k2":"v2"
+	|      }
+	|    },
+	|    "exit_code":0,
+	|    "path":"_EXE_",
+	|    "verb":"trace2",
+	|    "version":"$V"
+	|  }
+	|};
+	EOF
+	test_cmp expect actual
+'
+
+test_done
diff --git a/t/t0212/parse_events.perl b/t/t0212/parse_events.perl
new file mode 100644
index 00000000000000..d5f64eb6bb4b3a
--- /dev/null
+++ b/t/t0212/parse_events.perl
@@ -0,0 +1,245 @@
+#!/usr/bin/perl
+#
+# Parse event stream and convert individual events into a summary
+# record for the process.
+#
+# Git.exe generates one or more "event" records for each API method,
+# such as "start <argv>" and "exit <code>", during the life of the git
+# process.  Additionally, the input may contain interleaved events
+# from multiple concurrent git processes and/or multiple threads from
+# within a git process.
+#
+# Accumulate events for each process (based on its unique SID) in a
+# dictionary and emit process summary records.
+#
+# Convert some of the variable fields (such as elapsed time) into
+# placeholders (or omit them) to make HEREDOC comparisons easier in
+# the test scripts.
+#
+# We may also omit fields not (currently) useful for testing purposes.
+
+use strict;
+use warnings;
+use JSON::PP;
+use Data::Dumper;
+use Getopt::Long;
+
+# The version of the trace2 event target format that we understand.
+# This is reported in the 'version' event in the 'evt' field.
+# It comes from the GIT_TR2_EVENT_VERSION macro in trace2/tr2_tgt_event.c
+my $evt_version = '1';
+
+my $show_children = 1;
+my $show_exec     = 1;
+my $show_threads  = 1;
+
+# A hack to generate test HEREDOC data for pasting into the test script.
+# Usage:
+#    cd "t/trash directory.t0212-trace2-event"
+#    $TT trace ... >trace.event
+#    VV=$(../../git.exe version | sed -e 's/^git version //')
+#    perl ../t0212/parse_events.perl --HEREDOC --VERSION=$VV <trace.event >heredoc
+# Then paste heredoc into your new test.
+
+my $gen_heredoc = 0;
+my $gen_version = '';
+
+GetOptions("children!" => \$show_children,
+	   "exec!"     => \$show_exec,
+	   "threads!"  => \$show_threads,
+	   "HEREDOC!"  => \$gen_heredoc,
+	   "VERSION=s" => \$gen_version    )
+    or die("Error in command line arguments\n");
+
+
+# SIDs contains timestamps and PIDs of the process and its parents.
+# This makes it difficult to match up in a HEREDOC in the test script.
+# Build a map from actual SIDs to predictable constant values and yet
+# keep the parent/child relationships.  For example:
+# {..., "sid":"1539706952458276-8652", ...}
+# {..., "sid":"1539706952458276-8652/1539706952649493-15452", ...}
+# becomes:
+# {..., "sid":"_SID1_", ...}
+# {..., "sid":"_SID1_/_SID2_", ...}
+my $sid_map;
+my $sid_count = 0;
+
+my $processes;
+
+while (<>) {
+    my $line = decode_json( $_ );
+
+    my $sid = "";
+    my $sid_sep = "";
+
+    my $raw_sid = $line->{'sid'};
+    my @raw_sid_parts = split /\//, $raw_sid;
+    foreach my $raw_sid_k (@raw_sid_parts) {
+	if (!exists $sid_map->{$raw_sid_k}) {
+	    $sid_map->{$raw_sid_k} = '_SID' . $sid_count . '_';
+	    $sid_count++;
+	}
+	$sid = $sid . $sid_sep . $sid_map->{$raw_sid_k};
+	$sid_sep = '/';
+    }
+    
+    my $event = $line->{'event'};
+
+    if ($event eq 'version') {
+	$processes->{$sid}->{'version'} = $line->{'exe'};
+	if ($gen_heredoc == 1 && $gen_version eq $line->{'exe'}) {
+	    # If we are generating data FOR the test script, replace
+	    # the reported git.exe version with a reference to an
+	    # environment variable.  When our output is pasted into
+	    # the test script, it will then be expanded in future
+	    # test runs to the THEN current version of git.exe.
+	    # We assume that the test script uses env var $V.
+	    $processes->{$sid}->{'version'} = "\$V";
+	}
+    }
+
+    elsif ($event eq 'start') {
+	$processes->{$sid}->{'argv'} = $line->{'argv'};
+	$processes->{$sid}->{'argv'}[0] = "_EXE_";
+    }
+
+    elsif ($event eq 'exit') {
+	$processes->{$sid}->{'exit_code'} = $line->{'code'};
+    }
+
+    elsif ($event eq 'atexit') {
+	$processes->{$sid}->{'exit_code'} = $line->{'code'};
+    }
+
+    elsif ($event eq 'error') {
+	# For HEREDOC purposes, use the error message format string if
+	# available, rather than the formatted message (which probably
+	# has an absolute pathname).
+	if (exists $line->{'fmt'}) {
+	    push( @{$processes->{$sid}->{'errors'}}, $line->{'fmt'} );
+	}
+	elsif (exists $line->{'msg'}) {
+	    push( @{$processes->{$sid}->{'errors'}}, $line->{'msg'} );
+	}
+    }
+
+    elsif ($event eq 'cmd_path') {
+	## $processes->{$sid}->{'path'} = $line->{'path'};
+	$processes->{$sid}->{'path'} = "_EXE_";
+    }
+    
+    elsif ($event eq 'cmd_verb') {
+	$processes->{$sid}->{'verb'} = $line->{'name'};
+    }
+
+    elsif ($event eq 'alias') {
+	$processes->{$sid}->{'alias'}->{'key'} = $line->{'alias'};
+	$processes->{$sid}->{'alias'}->{'argv'} = $line->{'argv'};
+    }
+
+    elsif ($event eq 'def_param') {
+	my $kv;
+	$kv->{'param'} = $line->{'param'};
+	$kv->{'value'} = $line->{'value'};
+	push( @{$processes->{$sid}->{'params'}}, $kv );
+    }
+
+    elsif ($event eq 'child_start') {
+	if ($show_children == 1) {
+	    $processes->{$sid}->{'child'}->{$line->{'child_id'}}->{'child_class'} = $line->{'child_class'};
+	    $processes->{$sid}->{'child'}->{$line->{'child_id'}}->{'child_argv'} = $line->{'argv'};
+	    $processes->{$sid}->{'child'}->{$line->{'child_id'}}->{'child_argv'}[0] = "_EXE_";
+	    $processes->{$sid}->{'child'}->{$line->{'child_id'}}->{'use_shell'} = $line->{'use_shell'} ? 1 : 0;
+	}
+    }
+
+    elsif ($event eq 'child_exit') {
+	if ($show_children == 1) {
+	    $processes->{$sid}->{'child'}->{$line->{'child_id'}}->{'child_code'} = $line->{'code'};
+	}
+    }
+
+    # TODO decide what information we want to test from thread events.
+
+    elsif ($event eq 'thread_start') {
+	if ($show_threads == 1) {
+	}
+    }
+
+    elsif ($event eq 'thread_exit') {
+	if ($show_threads == 1) {
+	}
+    }
+
+    # TODO decide what information we want to test from exec events.
+
+    elsif ($event eq 'exec') {
+	if ($show_exec == 1) {
+	}
+    }
+
+    elsif ($event eq 'exec_result') {
+	if ($show_exec == 1) {
+	}
+    }
+
+    elsif ($event eq 'def_param') {
+	# Accumulate parameter key/value pairs by key rather than in an array
+	# so that we get overwrite (last one wins) effects.
+	$processes->{$sid}->{'params'}->{$line->{'param'}} = $line->{'value'};
+    }
+
+    elsif ($event eq 'def_repo') {
+	# $processes->{$sid}->{'repos'}->{$line->{'repo'}} = $line->{'worktree'};
+	$processes->{$sid}->{'repos'}->{$line->{'repo'}} = "_WORKTREE_";
+    }
+
+    # A series of potentially nested and threaded region and data events
+    # is fundamentally incompatibile with the type of summary record we
+    # are building in this script.  Since they are intended for
+    # perf-trace-like analysis rather than a result summary, we ignore
+    # most of them here.
+
+    # elsif ($event eq 'region_enter') {
+    # }
+    # elsif ($event eq 'region_leave') {
+    # }
+
+    elsif ($event eq 'data') {
+	my $cat = $line->{'category'};
+	if ($cat eq 'test_category') {
+	    
+	    my $key = $line->{'key'};
+	    my $value = $line->{'value'};
+	    $processes->{$sid}->{'data'}->{$cat}->{$key} = $value;
+	}
+    }
+
+    # This trace2 target does not emit 'printf' events.
+    #
+    # elsif ($event eq 'printf') {
+    # }
+}
+
+# Dump the resulting hash into something that we can compare against
+# in the test script.  These options make Dumper output look a little
+# bit like JSON.  Also convert variable references of the form "$VAR*"
+# so that the matching HEREDOC doesn't need to escape it.
+
+$Data::Dumper::Sortkeys = 1;
+$Data::Dumper::Indent = 1;
+$Data::Dumper::Purity = 1;
+$Data::Dumper::Pair = ':';
+
+my $out = Dumper($processes);
+$out =~ s/'/"/g;
+$out =~ s/\$VAR/VAR/g;
+
+# Finally, if we're running this script to generate (manually confirmed)
+# data to add to the test script, guard the indentation.
+
+if ($gen_heredoc == 1) {
+    $out =~ s/^/\t\|/gms;
+}
+
+print $out;

From 78490586e1c5ea3cef401707fba126a0333796ff Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 5 Nov 2018 07:29:53 -0500
Subject: [PATCH 09/23] trace2: add subverb to checkout command

---
 builtin/checkout.c | 7 +++++++
 1 file changed, 7 insertions(+)

diff --git a/builtin/checkout.c b/builtin/checkout.c
index 011d5edb6d41a0..f7a289874684c7 100644
--- a/builtin/checkout.c
+++ b/builtin/checkout.c
@@ -258,6 +258,8 @@ static int checkout_paths(const struct checkout_opts *opts,
 	int errs = 0;
 	struct lock_file lock_file = LOCK_INIT;
 
+	trace2_cmd_subverb(opts->patch_mode ? "patch" : "path");
+
 	if (opts->track != BRANCH_TRACK_UNSPECIFIED)
 		die(_("'%s' cannot be used with updating paths"), "--track");
 
@@ -930,6 +932,9 @@ static int switch_branches(const struct checkout_opts *opts,
 	void *path_to_free;
 	struct object_id rev;
 	int flag, writeout_error = 0;
+
+	trace2_cmd_subverb("branch");
+
 	memset(&old_branch_info, 0, sizeof(old_branch_info));
 	old_branch_info.path = path_to_free = resolve_refdup("HEAD", 0, &rev, &flag);
 	if (old_branch_info.path)
@@ -1159,6 +1164,8 @@ static int switch_unborn_to_new_branch(const struct checkout_opts *opts)
 	int status;
 	struct strbuf branch_ref = STRBUF_INIT;
 
+	trace2_cmd_subverb("unborn");
+
 	if (!opts->new_branch)
 		die(_("You are on a branch yet to be born"));
 	strbuf_addf(&branch_ref, "refs/heads/%s", opts->new_branch);

From 07ddf0e200b4ba843d3c2da9af2834ab7b5773e2 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 5 Nov 2018 11:36:43 -0500
Subject: [PATCH 10/23] trace2: add subverb to reset command

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 builtin/reset.c | 8 ++++++++
 1 file changed, 8 insertions(+)

diff --git a/builtin/reset.c b/builtin/reset.c
index adc8e0386621bb..6af50b801c6268 100644
--- a/builtin/reset.c
+++ b/builtin/reset.c
@@ -419,6 +419,7 @@ int cmd_reset(int argc, const char **argv, const char *prefix)
 	if (patch_mode) {
 		if (reset_type != NONE)
 			die(_("--patch is incompatible with --{hard,mixed,soft}"));
+		trace2_cmd_subverb("patch-interactive");
 		return run_add_interactive(rev, "--patch=reset", &pathspec);
 	}
 
@@ -435,6 +436,13 @@ int cmd_reset(int argc, const char **argv, const char *prefix)
 	if (reset_type == NONE)
 		reset_type = MIXED; /* by default */
 
+	if (read_from_stdin)
+		trace2_cmd_subverb("path-stdin");
+	else if (pathspec.nr)
+		trace2_cmd_subverb("path");
+	else
+		trace2_cmd_subverb(reset_type_names[reset_type]);
+
 	if (reset_type != SOFT && (reset_type != MIXED || get_git_work_tree()))
 		setup_work_tree();
 

From d3851e5a355078ae8574a1bbd3130972c07941fd Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 19 Nov 2018 16:26:37 -0500
Subject: [PATCH 11/23] trace2: add vfs stats

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 virtualfilesystem.c | 9 ++++++++-
 1 file changed, 8 insertions(+), 1 deletion(-)

diff --git a/virtualfilesystem.c b/virtualfilesystem.c
index 424680b4374530..0085e82f4d2aed 100644
--- a/virtualfilesystem.c
+++ b/virtualfilesystem.c
@@ -250,6 +250,7 @@ void apply_virtualfilesystem(struct index_state *istate)
 {
 	char *buf, *entry;
 	int i;
+	int nr_tracked = 0;
 
 	if (!git_config_get_virtualfilesystem())
 		return;
@@ -278,6 +279,7 @@ void apply_virtualfilesystem(struct index_state *istate)
 					pos = -pos - 1;
 					while (pos < istate->cache_nr && !fspathncmp(istate->cache[pos]->name, entry, len)) {
 						istate->cache[pos]->ce_flags &= ~CE_SKIP_WORKTREE;
+						nr_tracked++;
 						pos++;
 					}
 				}
@@ -288,14 +290,19 @@ void apply_virtualfilesystem(struct index_state *istate)
 						ce->ce_flags &= ~CE_SKIP_WORKTREE;
 				} else {
 					int pos = index_name_pos(istate, entry, len);
-					if (pos >= 0)
+					if (pos >= 0) {
+						nr_tracked++;
 						istate->cache[pos]->ce_flags &= ~CE_SKIP_WORKTREE;
+					}
 				}
 			}
 
 			entry += len + 1;
 		}
 	}
+
+	if (nr_tracked > 0)
+		trace2_data_intmax("vfs", the_repository, "apply/tracked", nr_tracked);
 }
 
 /*

From b6305bc26a9f29d2f85a3d2cba0435d99e9fdf32 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 26 Nov 2018 07:09:42 -0500
Subject: [PATCH 12/23] trace2: define env var trace2 config param

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 trace2/tr2_cfg.c | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/trace2/tr2_cfg.c b/trace2/tr2_cfg.c
index 0f16ed09f701f1..ef5aa159c200b3 100644
--- a/trace2/tr2_cfg.c
+++ b/trace2/tr2_cfg.c
@@ -2,7 +2,7 @@
 #include "config.h"
 #include "tr2_cfg.h"
 
-#define TR2_CFG_PARAM "GIT_TR2_CONFIG_PARAMS"
+#define TR2_ENVVAR_CFG_PARAM "GIT_TR2_CONFIG_PARAMS"
 
 static struct strbuf **tr2_cfg_patterns;
 static int tr2_cfg_count_patterns;
@@ -21,7 +21,7 @@ static int tr2_cfg_load_patterns(void)
 		return tr2_cfg_count_patterns;
 	tr2_cfg_loaded = 1;
 
-	envvar = getenv(TR2_CFG_PARAM);
+	envvar = getenv(TR2_ENVVAR_CFG_PARAM);
 	if (!envvar || !*envvar)
 		return tr2_cfg_count_patterns;
 

From 2fb631f86280812eeea1c91b9e0f106a03e4fa9d Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 26 Nov 2018 07:13:18 -0500
Subject: [PATCH 13/23] trace2: clarify env var macros used in tr2_tgt_event.c

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 trace2/tr2_tgt_event.c | 8 ++++----
 1 file changed, 4 insertions(+), 4 deletions(-)

diff --git a/trace2/tr2_tgt_event.c b/trace2/tr2_tgt_event.c
index a75f5c50d416bc..331aa575a02a21 100644
--- a/trace2/tr2_tgt_event.c
+++ b/trace2/tr2_tgt_event.c
@@ -22,7 +22,7 @@ static struct tr2_dst tr2dst_event  = { "GIT_TR2_EVENT", 0, 0, 0 };
  * to update this if you just add another call to one of the existing
  * TRACE2 API methods.
  */
-#define GIT_TR2_EVENT_VERSION "1"
+#define TR2_EVENT_VERSION "1"
 
 /*
  * Region nesting limit for messages written to the event target.
@@ -35,7 +35,7 @@ static struct tr2_dst tr2dst_event  = { "GIT_TR2_EVENT", 0, 0, 0 };
  * event target.  Set this environment variable to a larger integer for
  * more detail in the event target.
  */
-#define GIT_TR2_EVENT_NESTING "GIT_TR2_EVENT_NESTING"
+#define TR2_ENVVAR_EVENT_NESTING "GIT_TR2_EVENT_NESTING"
 static int tr2env_event_nesting_wanted = 2;
 
 static int fn_init(void)
@@ -47,7 +47,7 @@ static int fn_init(void)
 	if (!want)
 		return want;
 
-	nesting = getenv(GIT_TR2_EVENT_NESTING);
+	nesting = getenv(TR2_ENVVAR_EVENT_NESTING);
 	if (nesting && ((want_nesting = atoi(nesting)) > 0))
 		tr2env_event_nesting_wanted = want_nesting;
 
@@ -100,7 +100,7 @@ static void fn_version_fl(const char *file, int line)
 
 	jw_object_begin(&jw, 0);
 	event_fmt_prepare(event_name, file, line, NULL, &jw);
-	jw_object_string(&jw, "evt", GIT_TR2_EVENT_VERSION);
+	jw_object_string(&jw, "evt", TR2_EVENT_VERSION);
 	jw_object_string(&jw, "exe", git_version_string);
 	jw_end(&jw);
 

From 94137f20e8d75ed02702927e0eeae32380aaaa5c Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 26 Nov 2018 07:16:43 -0500
Subject: [PATCH 14/23] trace2: clarify env var macros used in tr2_tgt_perf and
 tr2_tgt_normal

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 trace2/tr2_tgt_normal.c | 4 ++--
 trace2/tr2_tgt_perf.c   | 4 ++--
 2 files changed, 4 insertions(+), 4 deletions(-)

diff --git a/trace2/tr2_tgt_normal.c b/trace2/tr2_tgt_normal.c
index 1b0a98b9683ced..1953e8fa809026 100644
--- a/trace2/tr2_tgt_normal.c
+++ b/trace2/tr2_tgt_normal.c
@@ -20,7 +20,7 @@ static struct tr2_dst tr2dst_normal = { "GIT_TR2", 0, 0, 0 };
  *
  * Unit tests may want to use this to help with testing.
  */
-#define GIT_TR2_NORMAL_BARE "GIT_TR2_BARE"
+#define TR2_ENVVAR_NORMAL_BARE "GIT_TR2_BARE"
 static int tr2env_normal_bare;
 
 #define TR2FMT_NORMAL_FL_WIDTH       (50)
@@ -34,7 +34,7 @@ static int fn_init(void)
 	if (!want)
 		return want;
 
-	bare = getenv(GIT_TR2_NORMAL_BARE);
+	bare = getenv(TR2_ENVVAR_NORMAL_BARE);
 	if (bare && *bare &&
 	    ((want_bare = git_parse_maybe_bool(bare)) != -1))
 		tr2env_normal_bare = want_bare;
diff --git a/trace2/tr2_tgt_perf.c b/trace2/tr2_tgt_perf.c
index e3b32993766053..96bfa7197fd978 100644
--- a/trace2/tr2_tgt_perf.c
+++ b/trace2/tr2_tgt_perf.c
@@ -22,7 +22,7 @@ static struct tr2_dst tr2dst_perf   = { "GIT_TR2_PERF", 0, 0, 0 };
  *
  * Unit tests may want to use this to help with testing.
  */
-#define GIT_TR2_PERF_BARE "GIT_TR2_BARE"
+#define TR2_ENVVAR_PERF_BARE "GIT_TR2_BARE"
 static int tr2env_perf_bare;
 
 #define TR2FMT_PERF_FL_WIDTH       (50)
@@ -47,7 +47,7 @@ static int fn_init(void)
 
 	strbuf_addchars(&dots, '.', TR2_DOTS_BUFFER_SIZE);
 
-	bare = getenv(GIT_TR2_PERF_BARE);
+	bare = getenv(TR2_ENVVAR_PERF_BARE);
 	if (bare && *bare &&
 	    ((want_bare = git_parse_maybe_bool(bare)) != -1))
 		tr2env_perf_bare = want_bare;

From ee545a914f293c24f21cfd67507b8a1603315947 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 26 Nov 2018 09:03:45 -0500
Subject: [PATCH 15/23] trace2: extend verb event with hierarchy information

Extend verb event from a git process to include verb
information about its parent git processes.

For example, when "git fetch" launches a child "git gc",
command, the child process will emit a verb message
containing:
    "name":"gc",
    "hierarchy":"fetch/gc",

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 Makefile                  |  1 +
 t/t0210-trace2-normal.sh  | 10 +++++-----
 t/t0212-trace2-event.sh   |  6 ++++++
 t/t0212/parse_events.perl |  1 +
 trace2.c                  |  9 ++++++++-
 trace2/tr2_tgt.h          |  3 ++-
 trace2/tr2_tgt_event.c    |  5 ++++-
 trace2/tr2_tgt_normal.c   |  5 ++++-
 trace2/tr2_tgt_perf.c     |  3 ++-
 trace2/tr2_verb.c         | 34 ++++++++++++++++++++++++++++++++++
 trace2/tr2_verb.h         | 28 ++++++++++++++++++++++++++++
 11 files changed, 95 insertions(+), 10 deletions(-)
 create mode 100644 trace2/tr2_verb.c
 create mode 100644 trace2/tr2_verb.h

diff --git a/Makefile b/Makefile
index 347728adaa1d2e..97b356565cb8ff 100644
--- a/Makefile
+++ b/Makefile
@@ -1010,6 +1010,7 @@ LIB_OBJS += trace2/tr2_tgt_event.o
 LIB_OBJS += trace2/tr2_tgt_normal.o
 LIB_OBJS += trace2/tr2_tgt_perf.o
 LIB_OBJS += trace2/tr2_tls.o
+LIB_OBJS += trace2/tr2_verb.o
 LIB_OBJS += trailer.o
 LIB_OBJS += transport.o
 LIB_OBJS += transport-helper.o
diff --git a/t/t0210-trace2-normal.sh b/t/t0210-trace2-normal.sh
index 985fbd710420fe..63088db55c56f4 100755
--- a/t/t0210-trace2-normal.sh
+++ b/t/t0210-trace2-normal.sh
@@ -61,7 +61,7 @@ test_expect_success 'normal stream, return code 0' '
 		version $V
 		start _EXE_ trace2 001return 0
 		cmd_path _EXE_
-		cmd_verb trace2
+		cmd_verb trace2 (trace2)
 		exit elapsed:_TIME_ code:0
 		atexit elapsed:_TIME_ code:0
 	EOF
@@ -76,7 +76,7 @@ test_expect_success 'normal stream, return code 1' '
 		version $V
 		start _EXE_ trace2 001return 1
 		cmd_path _EXE_
-		cmd_verb trace2
+		cmd_verb trace2 (trace2)
 		exit elapsed:_TIME_ code:1
 		atexit elapsed:_TIME_ code:1
 	EOF
@@ -95,7 +95,7 @@ test_expect_success 'normal stream, exit code 0' '
 		version $V
 		start _EXE_ trace2 002exit 0
 		cmd_path _EXE_
-		cmd_verb trace2
+		cmd_verb trace2 (trace2)
 		exit elapsed:_TIME_ code:0
 		atexit elapsed:_TIME_ code:0
 	EOF
@@ -110,7 +110,7 @@ test_expect_success 'normal stream, exit code 1' '
 		version $V
 		start _EXE_ trace2 002exit 1
 		cmd_path _EXE_
-		cmd_verb trace2
+		cmd_verb trace2 (trace2)
 		exit elapsed:_TIME_ code:1
 		atexit elapsed:_TIME_ code:1
 	EOF
@@ -129,7 +129,7 @@ test_expect_success 'normal stream, error event' '
 		version $V
 		start _EXE_ trace2 003error '\''hello world'\'' '\''this is a test'\''
 		cmd_path _EXE_
-		cmd_verb trace2
+		cmd_verb trace2 (trace2)
 		error hello world
 		error this is a test
 		exit elapsed:_TIME_ code:0
diff --git a/t/t0212-trace2-event.sh b/t/t0212-trace2-event.sh
index f0915c2be933ea..3fdf65f68b57e4 100755
--- a/t/t0212-trace2-event.sh
+++ b/t/t0212-trace2-event.sh
@@ -60,6 +60,7 @@ test_expect_success 'event stream, error event' '
 	|    "exit_code":0,
 	|    "path":"_EXE_",
 	|    "verb":"trace2",
+	|    "verb_hierarchy":"trace2",
 	|    "version":"$V"
 	|  }
 	|};
@@ -114,6 +115,7 @@ test_expect_success 'event stream, return code 0' '
 	|    "exit_code":0,
 	|    "path":"_EXE_",
 	|    "verb":"trace2",
+	|    "verb_hierarchy":"trace2",
 	|    "version":"$V"
 	|  },
 	|  "_SID0_/_SID1_":{
@@ -142,6 +144,7 @@ test_expect_success 'event stream, return code 0' '
 	|    "exit_code":0,
 	|    "path":"_EXE_",
 	|    "verb":"trace2",
+	|    "verb_hierarchy":"trace2/trace2",
 	|    "version":"$V"
 	|  },
 	|  "_SID0_/_SID1_/_SID2_":{
@@ -154,6 +157,7 @@ test_expect_success 'event stream, return code 0' '
 	|    "exit_code":0,
 	|    "path":"_EXE_",
 	|    "verb":"trace2",
+	|    "verb_hierarchy":"trace2/trace2/trace2",
 	|    "version":"$V"
 	|  }
 	|};
@@ -193,6 +197,7 @@ test_expect_success 'event stream, list config' '
 	|    ],
 	|    "path":"_EXE_",
 	|    "verb":"trace2",
+	|    "verb_hierarchy":"trace2",
 	|    "version":"$V"
 	|  }
 	|};
@@ -227,6 +232,7 @@ test_expect_success 'basic trace2_data' '
 	|    "exit_code":0,
 	|    "path":"_EXE_",
 	|    "verb":"trace2",
+	|    "verb_hierarchy":"trace2",
 	|    "version":"$V"
 	|  }
 	|};
diff --git a/t/t0212/parse_events.perl b/t/t0212/parse_events.perl
index d5f64eb6bb4b3a..86efe0971cd67c 100644
--- a/t/t0212/parse_events.perl
+++ b/t/t0212/parse_events.perl
@@ -130,6 +130,7 @@
     
     elsif ($event eq 'cmd_verb') {
 	$processes->{$sid}->{'verb'} = $line->{'name'};
+	$processes->{$sid}->{'verb_hierarchy'} = $line->{'hierarchy'};
     }
 
     elsif ($event eq 'alias') {
diff --git a/trace2.c b/trace2.c
index 85d05589964d69..66c0fcfd23fc86 100644
--- a/trace2.c
+++ b/trace2.c
@@ -11,6 +11,7 @@
 #include "trace2/tr2_sid.h"
 #include "trace2/tr2_tgt.h"
 #include "trace2/tr2_tls.h"
+#include "trace2/tr2_verb.h"
 
 static int trace2_enabled;
 
@@ -118,6 +119,7 @@ static void tr2main_atexit_handler(void)
 
 	tr2tls_release();
 	tr2_sid_release();
+	tr2_verb_release();
 	tr2_cfg_free_patterns();
 
 	trace2_enabled = 0;
@@ -253,14 +255,19 @@ void trace2_cmd_path_fl(const char *file, int line, const char *pathname)
 void trace2_cmd_verb_fl(const char *file, int line, const char *command_verb)
 {
 	struct tr2_tgt *tgt_j;
+	const char *hierarchy;
 	int j;
 
 	if (!trace2_enabled)
 		return;
 
+	tr2_verb_append_hierarchy(command_verb);
+	hierarchy = tr2_verb_get_hierarchy();
+
 	for_each_wanted_builtin(j, tgt_j) {
 		if (tgt_j->pfn_command_verb_fl)
-			tgt_j->pfn_command_verb_fl(file, line, command_verb);
+			tgt_j->pfn_command_verb_fl(file, line, command_verb,
+						   hierarchy);
 	}
 }
 
diff --git a/trace2/tr2_tgt.h b/trace2/tr2_tgt.h
index f0c81d1cc5653e..e2140611624add 100644
--- a/trace2/tr2_tgt.h
+++ b/trace2/tr2_tgt.h
@@ -30,7 +30,8 @@ typedef void (tr2_tgt_evt_error_va_fl_t)
 typedef void (tr2_tgt_evt_command_path_fl_t)
 	(const char *file, int line, const char *command_path);
 typedef void (tr2_tgt_evt_command_verb_fl_t)
-	(const char *file, int line, const char *command_verb);
+	(const char *file, int line, const char *command_verb,
+	 const char *hierarchy);
 typedef void (tr2_tgt_evt_command_subverb_fl_t)
 	(const char *file, int line, const char *command_subverb);
 
diff --git a/trace2/tr2_tgt_event.c b/trace2/tr2_tgt_event.c
index 331aa575a02a21..eca1e32ea206a2 100644
--- a/trace2/tr2_tgt_event.c
+++ b/trace2/tr2_tgt_event.c
@@ -235,7 +235,8 @@ static void fn_command_path_fl(const char *file, int line,
 }
 
 static void fn_command_verb_fl(const char *file, int line,
-			       const char *command_verb)
+			       const char *command_verb,
+			       const char *verb_hierarchy)
 {
 	const char *event_name = "cmd_verb";
 	struct json_writer jw = JSON_WRITER_INIT;
@@ -243,6 +244,8 @@ static void fn_command_verb_fl(const char *file, int line,
 	jw_object_begin(&jw, 0);
 	event_fmt_prepare(event_name, file, line, NULL, &jw);
 	jw_object_string(&jw, "name", command_verb);
+	if (verb_hierarchy && *verb_hierarchy)
+		jw_object_string(&jw, "hierarchy", verb_hierarchy);
 	jw_end(&jw);
 
 	tr2_dst_write_line(&tr2dst_event, &jw.json);
diff --git a/trace2/tr2_tgt_normal.c b/trace2/tr2_tgt_normal.c
index 1953e8fa809026..b09ae3f994cca1 100644
--- a/trace2/tr2_tgt_normal.c
+++ b/trace2/tr2_tgt_normal.c
@@ -169,11 +169,14 @@ static void fn_command_path_fl(const char *file, int line,
 }
 
 static void fn_command_verb_fl(const char *file, int line,
-			       const char *command_verb)
+			       const char *command_verb,
+			       const char *verb_hierarchy)
 {
 	struct strbuf buf_payload = STRBUF_INIT;
 
 	strbuf_addf(&buf_payload, "cmd_verb %s", command_verb);
+	if (verb_hierarchy && *verb_hierarchy)
+		strbuf_addf(&buf_payload, " (%s)", verb_hierarchy);
 	normal_io_write_fl(file, line, &buf_payload);
 	strbuf_release(&buf_payload);
 }
diff --git a/trace2/tr2_tgt_perf.c b/trace2/tr2_tgt_perf.c
index 96bfa7197fd978..7f4360e8b3f750 100644
--- a/trace2/tr2_tgt_perf.c
+++ b/trace2/tr2_tgt_perf.c
@@ -265,7 +265,8 @@ static void fn_command_path_fl(const char *file, int line,
 }
 
 static void fn_command_verb_fl(const char *file, int line,
-			       const char *command_verb)
+			       const char *command_verb,
+			       const char *verb_hierarchy)
 {
 	const char *event_name = "cmd_verb";
 	struct strbuf buf_payload = STRBUF_INIT;
diff --git a/trace2/tr2_verb.c b/trace2/tr2_verb.c
new file mode 100644
index 00000000000000..674e3b973bcff6
--- /dev/null
+++ b/trace2/tr2_verb.c
@@ -0,0 +1,34 @@
+#include "cache.h"
+#include "trace2/tr2_verb.h"
+
+/*
+ * This file contains "private/protected" routines for TRACE2.
+ */
+
+#define TR2_ENVVAR_PARENT_VERB "GIT_TR2_PARENT_VERB"
+
+static struct strbuf tr2verb_hierarchy = STRBUF_INIT;
+
+void tr2_verb_append_hierarchy(const char *verb)
+{
+	const char *parent_verb = getenv(TR2_ENVVAR_PARENT_VERB);
+
+	strbuf_reset(&tr2verb_hierarchy);
+	if (parent_verb && *parent_verb) {
+		strbuf_addstr(&tr2verb_hierarchy, parent_verb);
+		strbuf_addch(&tr2verb_hierarchy, '/');
+	}
+	strbuf_addstr(&tr2verb_hierarchy, verb);
+
+	setenv(TR2_ENVVAR_PARENT_VERB, tr2verb_hierarchy.buf, 1);
+}
+
+const char *tr2_verb_get_hierarchy(void)
+{
+	return tr2verb_hierarchy.buf;
+}
+
+void tr2_verb_release(void)
+{
+	strbuf_release(&tr2verb_hierarchy);
+}
diff --git a/trace2/tr2_verb.h b/trace2/tr2_verb.h
new file mode 100644
index 00000000000000..44f11e02e7b1c8
--- /dev/null
+++ b/trace2/tr2_verb.h
@@ -0,0 +1,28 @@
+#ifndef TR2_VERB_H
+#define TR2_VERB_H
+
+/*
+ * This file contains "private/protected" routines for TRACE2.
+ */
+
+/*
+ * Append the current git command's "verb" to the list being maintained
+ * in the environment.
+ *
+ * The hierarchy for a top-level git command is just the current verb.
+ * For a child git process, the hierarchy lists the verbs of the parent
+ * git processes (much like the SID).
+ *
+ * The hierarchy for the current process will be exported to the environment
+ * and inherited by child processes.
+ */
+void tr2_verb_append_hierarchy(const char *verb);
+
+/*
+ * Get the verb hierarchy for the current process.
+ */
+const char *tr2_verb_get_hierarchy(void);
+
+void tr2_verb_release(void);
+
+#endif /* TR2_VERB_H */

From 3dfe4994ee613ec5f438996113d1a7bf95256742 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 26 Nov 2018 14:45:57 -0500
Subject: [PATCH 16/23] trace2: classify hook child processes

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 builtin/am.c           |  1 +
 builtin/receive-pack.c |  4 ++++
 builtin/worktree.c     |  1 +
 run-command.c          |  1 +
 run-command.h          |  1 +
 sequencer.c            |  2 ++
 trace2/tr2_tgt_event.c | 11 ++++++++---
 trace2/tr2_tgt_perf.c  | 13 +++++++++----
 transport.c            |  1 +
 9 files changed, 28 insertions(+), 7 deletions(-)

diff --git a/builtin/am.c b/builtin/am.c
index 8f27f3375b1e92..0c4cb2495cf5f6 100644
--- a/builtin/am.c
+++ b/builtin/am.c
@@ -468,6 +468,7 @@ static int run_post_rewrite_hook(const struct am_state *state)
 
 	cp.in = xopen(am_path(state, "rewritten"), O_RDONLY);
 	cp.stdout_to_stderr = 1;
+	cp.trace2_hook_name = "post-rewrite";
 
 	ret = run_command(&cp);
 
diff --git a/builtin/receive-pack.c b/builtin/receive-pack.c
index 33187bd8e90252..6eef8575b96a2b 100644
--- a/builtin/receive-pack.c
+++ b/builtin/receive-pack.c
@@ -694,6 +694,8 @@ static int run_and_feed_hook(const char *hook_name, feed_fn feed,
 	proc.argv = argv;
 	proc.in = -1;
 	proc.stdout_to_stderr = 1;
+	proc.trace2_hook_name = hook_name;
+
 	if (feed_state->push_options) {
 		int i;
 		for (i = 0; i < feed_state->push_options->nr; i++)
@@ -807,6 +809,7 @@ static int run_update_hook(struct command *cmd)
 	proc.stdout_to_stderr = 1;
 	proc.err = use_sideband ? -1 : 0;
 	proc.argv = argv;
+	proc.trace2_hook_name = "update";
 
 	code = start_command(&proc);
 	if (code)
@@ -1190,6 +1193,7 @@ static void run_update_post_hook(struct command *commands)
 	proc.no_stdin = 1;
 	proc.stdout_to_stderr = 1;
 	proc.err = use_sideband ? -1 : 0;
+	proc.trace2_hook_name = "post-update";
 
 	if (!start_command(&proc)) {
 		if (use_sideband)
diff --git a/builtin/worktree.c b/builtin/worktree.c
index 5e8402617727f9..32e6f1b3418f65 100644
--- a/builtin/worktree.c
+++ b/builtin/worktree.c
@@ -401,6 +401,7 @@ static int add_worktree(const char *path, const char *refname,
 			cp.dir = path;
 			cp.env = env;
 			cp.argv = NULL;
+			cp.trace2_hook_name = "post-checkout";
 			argv_array_pushl(&cp.args, absolute_path(hook),
 					 oid_to_hex(&null_oid),
 					 oid_to_hex(&commit->object.oid),
diff --git a/run-command.c b/run-command.c
index 67d2fb14eaea1e..6977dde2d6d7dc 100644
--- a/run-command.c
+++ b/run-command.c
@@ -1415,6 +1415,7 @@ int run_hook_argv(const char *const *env, const char *name,
 	hook.env = env;
 	hook.no_stdin = 1;
 	hook.stdout_to_stderr = 1;
+	hook.trace2_hook_name = name;
 
 	return run_command(&hook);
 }
diff --git a/run-command.h b/run-command.h
index 36576d790fde68..5ad1357ae5d6a3 100644
--- a/run-command.h
+++ b/run-command.h
@@ -14,6 +14,7 @@ struct child_process {
 	int trace2_child_id;
 	uint64_t trace2_child_us_start;
 	const char *trace2_child_class;
+	const char *trace2_hook_name;
 
 	/*
 	 * Using .in, .out, .err:
diff --git a/sequencer.c b/sequencer.c
index e3883a0ed8b0bf..4eaa265cc4161c 100644
--- a/sequencer.c
+++ b/sequencer.c
@@ -1093,6 +1093,7 @@ static int run_rewrite_hook(const struct object_id *oldoid,
 	proc.argv = argv;
 	proc.in = -1;
 	proc.stdout_to_stderr = 1;
+	proc.trace2_hook_name = "post-rewrite";
 
 	code = start_command(&proc);
 	if (code)
@@ -3730,6 +3731,7 @@ static int pick_commits(struct todo_list *todo_list, struct replay_opts *opts)
 				hook.in = open(rebase_path_rewritten_list(),
 					O_RDONLY);
 				hook.stdout_to_stderr = 1;
+				hook.trace2_hook_name = "post-rewrite";
 				argv_array_push(&hook.args, post_rewrite_hook);
 				argv_array_push(&hook.args, "rebase");
 				/* we don't care if this hook failed */
diff --git a/trace2/tr2_tgt_event.c b/trace2/tr2_tgt_event.c
index eca1e32ea206a2..2cee2e24e64ba4 100644
--- a/trace2/tr2_tgt_event.c
+++ b/trace2/tr2_tgt_event.c
@@ -291,13 +291,18 @@ static void fn_child_start_fl(const char *file, int line,
 {
 	const char *event_name = "child_start";
 	struct json_writer jw = JSON_WRITER_INIT;
-	const char *child_class = ((cmd->trace2_child_class) ?
-				   cmd->trace2_child_class : "?");
 
 	jw_object_begin(&jw, 0);
 	event_fmt_prepare(event_name, file, line, NULL, &jw);
 	jw_object_intmax(&jw, "child_id", cmd->trace2_child_id);
-	jw_object_string(&jw, "child_class", child_class);
+	if (cmd->trace2_hook_name) {
+		jw_object_string(&jw, "child_class", "hook");
+		jw_object_string(&jw, "hook_name", cmd->trace2_hook_name);
+	} else {
+		const char *child_class = ((cmd->trace2_child_class) ?
+					   cmd->trace2_child_class : "?");
+		jw_object_string(&jw, "child_class", child_class);
+	}
 	if (cmd->dir)
 		jw_object_string(&jw, "cd", cmd->dir);
 	jw_object_bool(&jw, "use_shell", cmd->use_shell);
diff --git a/trace2/tr2_tgt_perf.c b/trace2/tr2_tgt_perf.c
index 7f4360e8b3f750..d613bcb2f300de 100644
--- a/trace2/tr2_tgt_perf.c
+++ b/trace2/tr2_tgt_perf.c
@@ -314,11 +314,16 @@ static void fn_child_start_fl(const char *file, int line,
 {
 	const char *event_name = "child_start";
 	struct strbuf buf_payload = STRBUF_INIT;
-	const char *child_class = ((cmd->trace2_child_class) ?
-				   cmd->trace2_child_class : "?");
 
-	strbuf_addf(&buf_payload, "[ch%d] class:%s",
-		    cmd->trace2_child_id, child_class);
+	if (cmd->trace2_hook_name) {
+		strbuf_addf(&buf_payload, "[ch%d] class:hook hook:%s",
+			    cmd->trace2_child_id, cmd->trace2_hook_name);
+	} else {
+		const char *child_class = ((cmd->trace2_child_class) ?
+					   cmd->trace2_child_class : "?");
+		strbuf_addf(&buf_payload, "[ch%d] class:%s",
+			    cmd->trace2_child_id, child_class);
+	}
 
 	if (cmd->dir) {
 		strbuf_addstr(&buf_payload, " cd:");
diff --git a/transport.c b/transport.c
index 5a74b609ffad51..2bf1c367e3f325 100644
--- a/transport.c
+++ b/transport.c
@@ -1061,6 +1061,7 @@ static int run_pre_push_hook(struct transport *transport,
 
 	proc.argv = argv;
 	proc.in = -1;
+	proc.trace2_hook_name = "pre-push";
 
 	if (start_command(&proc)) {
 		finish_command(&proc);

From f55467c545379b7e0b183c69727a40b137bb1a6b Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Fri, 12 Oct 2018 13:16:58 -0400
Subject: [PATCH 17/23] DROPME: keep inherited GIT_TR2 env vars when running
 test suite

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 t/test-lib.sh | 1 +
 1 file changed, 1 insertion(+)

diff --git a/t/test-lib.sh b/t/test-lib.sh
index 51f502b1614167..fca8f4b837b59a 100644
--- a/t/test-lib.sh
+++ b/t/test-lib.sh
@@ -146,6 +146,7 @@ unset VISUAL EMAIL LANGUAGE COLUMNS $(env | sed -n \
 	-e '/^GIT_PERF_/d' \
 	-e '/^GIT_CURL_VERBOSE/d' \
 	-e '/^GIT_TRACE_CURL/d' \
+	-e '/^GIT_TR2_*/d' \
 	-e 's/^\(GIT_[^=]*\)=.*/\1/p')
 unset XDG_CACHE_HOME
 unset XDG_CONFIG_HOME

From 01b2b399d02bc9e7bc9242e2d7f32dc7c207cf41 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Tue, 4 Dec 2018 22:25:18 +0000
Subject: [PATCH 18/23] trace2: fixup t0210 on linux

---
 t/t0210-trace2-normal.sh  |  6 ------
 t/t0210/scrub_normal.perl | 40 ++++++++++++++++++++++-----------------
 2 files changed, 23 insertions(+), 23 deletions(-)

diff --git a/t/t0210-trace2-normal.sh b/t/t0210-trace2-normal.sh
index 63088db55c56f4..d53a66a3bbe78e 100755
--- a/t/t0210-trace2-normal.sh
+++ b/t/t0210-trace2-normal.sh
@@ -41,7 +41,6 @@ GIT_TR2_BARE=1 && export GIT_TR2_BARE
 # We do confirm the following API features:
 # [] the 'version <v>' event
 # [] the 'start <argv>' event
-# [] the 'cmd_path <argv[0]>' event
 # [] the 'cmd_verb <verb>' event
 # [] the 'exit <time> code:<code>' event
 # [] the 'atexit <time> code:<code>' event
@@ -60,7 +59,6 @@ test_expect_success 'normal stream, return code 0' '
 	cat >expect <<-EOF &&
 		version $V
 		start _EXE_ trace2 001return 0
-		cmd_path _EXE_
 		cmd_verb trace2 (trace2)
 		exit elapsed:_TIME_ code:0
 		atexit elapsed:_TIME_ code:0
@@ -75,7 +73,6 @@ test_expect_success 'normal stream, return code 1' '
 	cat >expect <<-EOF &&
 		version $V
 		start _EXE_ trace2 001return 1
-		cmd_path _EXE_
 		cmd_verb trace2 (trace2)
 		exit elapsed:_TIME_ code:1
 		atexit elapsed:_TIME_ code:1
@@ -94,7 +91,6 @@ test_expect_success 'normal stream, exit code 0' '
 	cat >expect <<-EOF &&
 		version $V
 		start _EXE_ trace2 002exit 0
-		cmd_path _EXE_
 		cmd_verb trace2 (trace2)
 		exit elapsed:_TIME_ code:0
 		atexit elapsed:_TIME_ code:0
@@ -109,7 +105,6 @@ test_expect_success 'normal stream, exit code 1' '
 	cat >expect <<-EOF &&
 		version $V
 		start _EXE_ trace2 002exit 1
-		cmd_path _EXE_
 		cmd_verb trace2 (trace2)
 		exit elapsed:_TIME_ code:1
 		atexit elapsed:_TIME_ code:1
@@ -128,7 +123,6 @@ test_expect_success 'normal stream, error event' '
 	cat >expect <<-EOF &&
 		version $V
 		start _EXE_ trace2 003error '\''hello world'\'' '\''this is a test'\''
-		cmd_path _EXE_
 		cmd_verb trace2 (trace2)
 		error hello world
 		error this is a test
diff --git a/t/t0210/scrub_normal.perl b/t/t0210/scrub_normal.perl
index fc58c77cb912aa..c65d1a815ea3d8 100644
--- a/t/t0210/scrub_normal.perl
+++ b/t/t0210/scrub_normal.perl
@@ -6,14 +6,8 @@
 use strict;
 use warnings;
 
-my $space = '\W+';
-my $qpath = '\'[^\']*\'';
-my $string= '.*';
 my $float = '[0-9]*\.[0-9]+([eE][-+]?[0-9]+)?';
 
-my $verb;
-my $rest;
-
 # This code assumes that the trace2 data was written with bare
 # turned on (which omits the "<clock> <file>:<line>" prefix.
 
@@ -23,20 +17,32 @@
     # simplify our HEREDOC in the test script.
     s/elapsed:$float/elapsed:_TIME_/g;
 
-    if ($_ =~ m/^start/) {
-	# The 'start' message lists the contents of argv.  On some
-	# platforms (Windows), argv[0] is a canonical absolute path to
-	# the EXE rather than the value passed in the shell script.
-	# Replace it with a placeholder to simplify our HEREDOC in the
-	# test script.
-	($verb, $rest) = (m/^(start) $space $qpath $space ($string)/x);
-	print "$verb _EXE_ $rest\n";
+    my $line = $_;
+
+    # we expect:
+    #    start <argv0> [<argv1> [<argv2> [...]]]
+    #
+    # where argv0 might be a relative or absolute path, with
+    # or without quotes, and platform dependent.  Replace argv0
+    # with a token for HEREDOC matching in the test script.
+
+    if ($line =~ m/^start/) {
+	$line =~ /^start\s+(.*)/;
+	my $argv = $1;
+	$argv =~ m/(\'[^\']*\'|[^ ]+)\s+(.*)/;
+	my $argv_0 = $1;
+	my $argv_rest = $2;
+
+	print "start _EXE_ $argv_rest\n";
     }
-    elsif ($_ =~ m/^cmd_path/) {
+    elsif ($line =~ m/^cmd_path/) {
 	# Likewise, the 'cmd_path' message breaks out argv[0].
-	print "cmd_path _EXE_\n";
+	#
+	# This line is only emitted when RUNTIME_PREFIX is defined,
+	# so just omit it for testing purposes.
+	# print "cmd_path _EXE_\n";
     }
     else {
-	print "$_";
+	print "$line";
     }
 }

From 4085dcd6c1e3104bf36a3e92de8a81a365d0cba6 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Tue, 4 Dec 2018 22:28:16 +0000
Subject: [PATCH 19/23] trace2: fixup t0211 for linux

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 t/t0211-trace2-perf.sh  | 9 ---------
 t/t0211/scrub_perf.perl | 6 +++++-
 2 files changed, 5 insertions(+), 10 deletions(-)

diff --git a/t/t0211-trace2-perf.sh b/t/t0211-trace2-perf.sh
index 915960ff08b515..24b3aff76a8cb9 100755
--- a/t/t0211-trace2-perf.sh
+++ b/t/t0211-trace2-perf.sh
@@ -51,7 +51,6 @@ test_expect_success 'perf stream, return code 0' '
 	cat >expect <<-EOF &&
 		main|version|||||$V
 		main|start|||||_EXE_ trace2 001return 0
-		main|cmd_path|||||_EXE_
 		main|cmd_verb|||||trace2
 		main|exit||_T_ABS_|||code:0
 		main|atexit||_T_ABS_|||code:0
@@ -66,7 +65,6 @@ test_expect_success 'perf stream, return code 1' '
 	cat >expect <<-EOF &&
 		main|version|||||$V
 		main|start|||||_EXE_ trace2 001return 1
-		main|cmd_path|||||_EXE_
 		main|cmd_verb|||||trace2
 		main|exit||_T_ABS_|||code:1
 		main|atexit||_T_ABS_|||code:1
@@ -85,7 +83,6 @@ test_expect_success 'perf stream, error event' '
 	cat >expect <<-EOF &&
 		main|version|||||$V
 		main|start|||||_EXE_ trace2 003error '\''hello world'\'' '\''this is a test'\''
-		main|cmd_path|||||_EXE_
 		main|cmd_verb|||||trace2
 		main|error|||||hello world
 		main|error|||||this is a test
@@ -107,17 +104,14 @@ test_expect_success 'perf stream, error event' '
 # Which should generate events:
 #    P1: version
 #    P1: start
-#    P1: cmd_path
 #    P1: cmd_verb
 #    P1: child_start
 #        P2: version
 #        P2: start
-#        P2: cmd_path
 #        P2: cmd_verb
 #        P2: child_start
 #            P3: version
 #            P3: start
-#            P3: cmd_path
 #            P3: cmd_verb
 #            P3: exit
 #            P3: atexit
@@ -135,17 +129,14 @@ test_expect_success 'perf stream, child processes' '
 	cat >expect <<-EOF &&
 		main|version|||||$V
 		main|start|||||_EXE_ trace2 004child $TT trace2 004child $TT trace2 001return 0
-		main|cmd_path|||||_EXE_
 		main|cmd_verb|||||trace2
 		main|child_start||_T_ABS_|||[ch0] class:? argv: $TT trace2 004child $TT trace2 001return 0
 		main|version|||||$V
 		main|start|||||_EXE_ trace2 004child $TT trace2 001return 0
-		main|cmd_path|||||_EXE_
 		main|cmd_verb|||||trace2
 		main|child_start||_T_ABS_|||[ch0] class:? argv: $TT trace2 001return 0
 		main|version|||||$V
 		main|start|||||_EXE_ trace2 001return 0
-		main|cmd_path|||||_EXE_
 		main|cmd_verb|||||trace2
 		main|exit||_T_ABS_|||code:0
 		main|atexit||_T_ABS_|||code:0
diff --git a/t/t0211/scrub_perf.perl b/t/t0211/scrub_perf.perl
index 153bc727f9c325..8d79f32b4ac34a 100644
--- a/t/t0211/scrub_perf.perl
+++ b/t/t0211/scrub_perf.perl
@@ -37,7 +37,11 @@
     }
     elsif ($tokens[$col_verb] =~ m/cmd_path/) {
 	# Likewise, the 'cmd_path' message breaks out argv[0].
-	$tokens[$col_rest] = "_EXE_";
+	#
+	# This line is only emitted when RUNTIME_PREFIX is defined,
+	# so just omit it for testing purposes.
+	# $tokens[$col_rest] = "_EXE_";
+	goto SKIP_LINE;
     }
     elsif ($tokens[$col_verb] =~ m/child_exit/) {
 	$tokens[$col_rest] =~ s/ pid:\d* / pid:_PID_ /;

From 6fe828bd4e423f6f7bba82ef719e9b63422eb2db Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Tue, 4 Dec 2018 22:38:11 +0000
Subject: [PATCH 20/23] trace2: fixup t0212 for linux

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 t/t0212-trace2-event.sh   | 10 ++--------
 t/t0212/parse_events.perl |  7 ++++++-
 2 files changed, 8 insertions(+), 9 deletions(-)

diff --git a/t/t0212-trace2-event.sh b/t/t0212-trace2-event.sh
index 3fdf65f68b57e4..5a9527c34f317a 100755
--- a/t/t0212-trace2-event.sh
+++ b/t/t0212-trace2-event.sh
@@ -54,11 +54,10 @@ test_expect_success 'event stream, error event' '
 	|      "this is a test"
 	|    ],
 	|    "errors":[
-	|      "hello world",
-	|      "this is a test"
+	|      "%s",
+	|      "%s"
 	|    ],
 	|    "exit_code":0,
-	|    "path":"_EXE_",
 	|    "verb":"trace2",
 	|    "verb_hierarchy":"trace2",
 	|    "version":"$V"
@@ -113,7 +112,6 @@ test_expect_success 'event stream, return code 0' '
 	|      }
 	|    },
 	|    "exit_code":0,
-	|    "path":"_EXE_",
 	|    "verb":"trace2",
 	|    "verb_hierarchy":"trace2",
 	|    "version":"$V"
@@ -142,7 +140,6 @@ test_expect_success 'event stream, return code 0' '
 	|      }
 	|    },
 	|    "exit_code":0,
-	|    "path":"_EXE_",
 	|    "verb":"trace2",
 	|    "verb_hierarchy":"trace2/trace2",
 	|    "version":"$V"
@@ -155,7 +152,6 @@ test_expect_success 'event stream, return code 0' '
 	|      "0"
 	|    ],
 	|    "exit_code":0,
-	|    "path":"_EXE_",
 	|    "verb":"trace2",
 	|    "verb_hierarchy":"trace2/trace2/trace2",
 	|    "version":"$V"
@@ -195,7 +191,6 @@ test_expect_success 'event stream, list config' '
 	|        "value":"hello world"
 	|      }
 	|    ],
-	|    "path":"_EXE_",
 	|    "verb":"trace2",
 	|    "verb_hierarchy":"trace2",
 	|    "version":"$V"
@@ -230,7 +225,6 @@ test_expect_success 'basic trace2_data' '
 	|      }
 	|    },
 	|    "exit_code":0,
-	|    "path":"_EXE_",
 	|    "verb":"trace2",
 	|    "verb_hierarchy":"trace2",
 	|    "version":"$V"
diff --git a/t/t0212/parse_events.perl b/t/t0212/parse_events.perl
index 86efe0971cd67c..0e38fa6db66c82 100644
--- a/t/t0212/parse_events.perl
+++ b/t/t0212/parse_events.perl
@@ -125,7 +125,12 @@
 
     elsif ($event eq 'cmd_path') {
 	## $processes->{$sid}->{'path'} = $line->{'path'};
-	$processes->{$sid}->{'path'} = "_EXE_";
+	#
+	# Like in the 'start' event, we need to replace the value of
+	# argv[0] with a token for HEREDOC purposes.  However, the
+	# event is only emitted when RUNTIME_PREFIX is defined, so
+	# just omit it for testing purposes.
+	# $processes->{$sid}->{'path'} = "_EXE_";
     }
     
     elsif ($event eq 'cmd_verb') {

From c45c0db93c3140842d46e4ac011bf8f057771106 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 5 Nov 2018 10:12:56 -0500
Subject: [PATCH 21/23] gvfs:trace2: add subverb events to status for
 serialization

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 builtin/commit.c | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/builtin/commit.c b/builtin/commit.c
index 03dfd4043442a9..590d2076c313fc 100644
--- a/builtin/commit.c
+++ b/builtin/commit.c
@@ -1595,6 +1595,7 @@ int cmd_status(int argc, const char **argv, const char *prefix)
 		if (s.relative_paths)
 			s.prefix = prefix;
 
+		trace2_cmd_subverb("deserialize");
 		result = wt_status_deserialize(&s, deserialize_path, dw);
 		if (result == DESERIALIZE_OK)
 			return 0;
@@ -1612,6 +1613,7 @@ int cmd_status(int argc, const char **argv, const char *prefix)
 			fd = -1;
 	}
 
+	trace2_cmd_subverb("collect");
 	wt_status_collect(&s);
 
 	if (0 <= fd)
@@ -1626,6 +1628,7 @@ int cmd_status(int argc, const char **argv, const char *prefix)
 		if (fd_serialize < 0)
 			die_errno(_("could not serialize to '%s'"),
 				  serialize_path);
+		trace2_cmd_subverb("serialize");
 		wt_status_serialize_v1(fd_serialize, &s);
 		close(fd_serialize);
 	}

From 1d645524a4b4f8273764c2e46c53dc7ada306ba9 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 12 Nov 2018 17:44:58 -0500
Subject: [PATCH 22/23] gvfs:trace2: add status cache deserialization failure
 reasons

---
 builtin/commit.c        | 16 ++++++++++++++-
 wt-status-deserialize.c | 43 ++++++++++++++++++++++++++++++++++++++++-
 wt-status.h             |  2 ++
 3 files changed, 59 insertions(+), 2 deletions(-)

diff --git a/builtin/commit.c b/builtin/commit.c
index 590d2076c313fc..3e863ae1b631e8 100644
--- a/builtin/commit.c
+++ b/builtin/commit.c
@@ -145,6 +145,7 @@ static int opt_parse_porcelain(const struct option *opt, const char *arg, int un
 static int do_serialize = 0;
 static char *serialize_path = NULL;
 
+static int reject_implicit = 0;
 static int do_implicit_deserialize = 0;
 static int do_explicit_deserialize = 0;
 static char *deserialize_path = NULL;
@@ -202,7 +203,7 @@ static int opt_parse_deserialize(const struct option *opt, const char *arg, int
 		if (arg) /* override config or stdin */
 			deserialize_path = xstrdup(arg);
 		if (deserialize_path && *deserialize_path
-		    && (access(deserialize_path, R_OK) != 0))
+		    && (wt_status_deserialize_access(deserialize_path, R_OK) != 0))
 			die("cannot find serialization file '%s'",
 			    deserialize_path);
 
@@ -1396,6 +1397,8 @@ static int git_status_config(const char *k, const char *v, void *cb)
 		if (v && *v && access(v, R_OK) == 0) {
 			do_implicit_deserialize = 1;
 			deserialize_path = xstrdup(v);
+		} else {
+			reject_implicit = 1;
 		}
 		return 0;
 	}
@@ -1552,6 +1555,17 @@ int cmd_status(int argc, const char **argv, const char *prefix)
 			   (do_implicit_deserialize || do_explicit_deserialize));
 	if (try_deserialize)
 		goto skip_init;
+	/*
+	 * If we implicitly received a status cache pathname from the config
+	 * and the file does not exist, we silently reject it and do the normal
+	 * status "collect".  Fake up some trace2 messages to reflect this and
+	 * assist post-processors know this case is different.
+	 */
+	if (!do_serialize && reject_implicit) {
+		trace2_cmd_subverb("implicit-deserialize");
+		trace2_data_string("status", the_repository, "deserialize/reject",
+				   "status-cache/access");
+	}
 
 	enable_fscache(0);
 	if (status_format != STATUS_FORMAT_PORCELAIN &&
diff --git a/wt-status-deserialize.c b/wt-status-deserialize.c
index 8647ed3ab23cbb..c8a059bf2aa715 100644
--- a/wt-status-deserialize.c
+++ b/wt-status-deserialize.c
@@ -3,6 +3,22 @@
 #include "pkt-line.h"
 #include "trace.h"
 
+static void set_deserialize_reject_reason(const char *reason)
+{
+	trace2_data_string("status", the_repository, "deserialize/reject",
+			   reason);
+}
+
+int wt_status_deserialize_access(const char *path, int mode)
+{
+	int a = access(path, mode);
+
+	if (a != 0)
+		set_deserialize_reject_reason("status-cache/access");
+
+	return a;
+}
+
 static struct trace_key trace_deserialize = TRACE_KEY_INIT(DESERIALIZE);
 
 enum deserialize_parse_strategy {
@@ -49,6 +65,7 @@ static int my_validate_index(const struct cache_time *mtime_reported)
 	struct cache_time mtime_observed_on_disk;
 
 	if (lstat(path, &st)) {
+		set_deserialize_reject_reason("index/not-found");
 		trace_printf_key(&trace_deserialize, "could not stat index");
 		return DESERIALIZE_ERR;
 	}
@@ -56,6 +73,7 @@ static int my_validate_index(const struct cache_time *mtime_reported)
 	mtime_observed_on_disk.nsec = ST_MTIME_NSEC(st);
 	if ((mtime_observed_on_disk.sec != mtime_reported->sec) ||
 	    (mtime_observed_on_disk.nsec != mtime_reported->nsec)) {
+		set_deserialize_reject_reason("index/mtime-changed");
 		trace_printf_key(&trace_deserialize,
 				 "index mtime changed [des %d %d][obs %d %d]",
 			     mtime_reported->sec, mtime_reported->nsec,
@@ -81,10 +99,12 @@ static int my_validate_excludes(const char *path, const char *key, const char *l
 
 	r = (strcmp(line, sb.buf) ? DESERIALIZE_ERR : DESERIALIZE_OK);
 
-	if (r == DESERIALIZE_ERR)
+	if (r == DESERIALIZE_ERR) {
+		set_deserialize_reject_reason("excludes/changed");
 		trace_printf_key(&trace_deserialize,
 				 "%s changed [cached '%s'][observed '%s']",
 				 key, line, sb.buf);
+	}
 
 	strbuf_release(&sb);
 	return r;
@@ -140,6 +160,7 @@ static int wt_deserialize_v1_header(struct wt_status *s, int fd)
 					   &index_mtime.sec,
 					   &index_mtime.nsec);
 			if (nr_fields != 2) {
+				set_deserialize_reject_reason("v1-header/invalid-index-mtime");
 				trace_printf_key(&trace_deserialize, "invalid index_mtime (%d) '%s'",
 					     nr_fields, line);
 				return DESERIALIZE_ERR;
@@ -223,6 +244,7 @@ static int wt_deserialize_v1_header(struct wt_status *s, int fd)
 		/* status_format */
 		if (skip_prefix(line, "sha1_commit ", &arg)) {
 			if (get_sha1_hex(arg, s->sha1_commit)) {
+				set_deserialize_reject_reason("v1-header/invalid-commit-sha");
 				trace_printf_key(&trace_deserialize, "invalid sha1_commit");
 				return DESERIALIZE_ERR;
 			}
@@ -238,19 +260,23 @@ static int wt_deserialize_v1_header(struct wt_status *s, int fd)
 		}
 		/* prefix */
 
+		set_deserialize_reject_reason("v1-header/unexpected-line");
 		trace_printf_key(&trace_deserialize, "unexpected line '%s'", line);
 		return DESERIALIZE_ERR;
 	}
 
 	if (!have_required_index_mtime) {
+		set_deserialize_reject_reason("v1-header/missing-index-mtime");
 		trace_printf_key(&trace_deserialize, "missing '%s'", "index_mtime");
 		return DESERIALIZE_ERR;
 	}
 	if (!have_required_core_excludes) {
+		set_deserialize_reject_reason("v1-header/missing-core-excludes");
 		trace_printf_key(&trace_deserialize, "missing '%s'", "core_excludes");
 		return DESERIALIZE_ERR;
 	}
 	if (!have_required_repo_excludes) {
+		set_deserialize_reject_reason("v1-header/missing-repo-excludes");
 		trace_printf_key(&trace_deserialize, "missing '%s'", "repo_excludes");
 		return DESERIALIZE_ERR;
 	}
@@ -336,6 +362,7 @@ static int wt_deserialize_v1_changed_items(const struct wt_status *cmd_s,
 			 * So we reject the status cache and let the fallback
 			 * code run.
 			 */
+			set_deserialize_reject_reason("v1-data/unmerged");
 			trace_printf_key(
 				&trace_deserialize,
 				"reject: V2 format and umerged file: %s",
@@ -471,6 +498,7 @@ static int wt_deserialize_v1(const struct wt_status *cmd_s, struct wt_status *s,
 	 * the serialized data
 	*/
 	if (validate_untracked_files_arg(cmd_s->show_untracked_files, s->show_untracked_files, &untracked_strategy)) {
+		set_deserialize_reject_reason("args/untracked-files");
 		trace_printf_key(&trace_deserialize, "reject: show_untracked_file: command: %d, serialized : %d",
 				cmd_s->show_untracked_files,
 				s->show_untracked_files);
@@ -478,6 +506,7 @@ static int wt_deserialize_v1(const struct wt_status *cmd_s, struct wt_status *s,
 	}
 
 	if (validate_ignored_files_arg(cmd_s->show_ignored_mode, s->show_ignored_mode, &ignored_strategy)) {
+		set_deserialize_reject_reason("args/ignored-mode");
 		trace_printf_key(&trace_deserialize, "reject: show_ignored_mode: command: %d, serialized: %d",
 				cmd_s->show_ignored_mode,
 				s->show_ignored_mode);
@@ -511,6 +540,7 @@ static int wt_deserialize_v1(const struct wt_status *cmd_s, struct wt_status *s,
 				return DESERIALIZE_ERR;
 			continue;
 		}
+		set_deserialize_reject_reason("v1-data/unexpected-line");
 		trace_printf_key(&trace_deserialize, "unexpected line '%s'", line);
 		return DESERIALIZE_ERR;
 	}
@@ -532,6 +562,7 @@ static int wt_deserialize_parse(const struct wt_status *cmd_s, struct wt_status
 		if (version == 1)
 			return wt_deserialize_v1(cmd_s, s, fd);
 	}
+	set_deserialize_reject_reason("status-cache/unsupported-version");
 	trace_printf_key(&trace_deserialize, "missing/unsupported version");
 	return DESERIALIZE_ERR;
 }
@@ -552,6 +583,7 @@ static int wt_deserialize_fd(const struct wt_status *cmd_s, struct wt_status *de
 	 * Check the path spec on the current command
 	 */
 	if (cmd_s->pathspec.nr > 1) {
+		set_deserialize_reject_reason("args/multiple-pathspecs");
 		trace_printf_key(&trace_deserialize, "reject: multiple pathspecs");
 		return DESERIALIZE_ERR;
 	}
@@ -562,6 +594,7 @@ static int wt_deserialize_fd(const struct wt_status *cmd_s, struct wt_status *de
 	 */
 	if (cmd_s->pathspec.nr == 1 &&
 		my_strcmp_null(cmd_s->pathspec.items[0].match, "")) {
+		set_deserialize_reject_reason("args/root-pathspec");
 		trace_printf_key(&trace_deserialize, "reject: pathspec");
 		return DESERIALIZE_ERR;
 	}
@@ -578,20 +611,24 @@ static int wt_deserialize_fd(const struct wt_status *cmd_s, struct wt_status *de
 	 * or "--ignored" settings).
 	 */
 	if (cmd_s->is_initial != des_s->is_initial) {
+		set_deserialize_reject_reason("args/is-initial-changed");
 		trace_printf_key(&trace_deserialize, "reject: is_initial");
 		return DESERIALIZE_ERR;
 	}
 	if (my_strcmp_null(cmd_s->branch, des_s->branch)) {
+		set_deserialize_reject_reason("args/branch-changed");
 		trace_printf_key(&trace_deserialize, "reject: branch");
 		return DESERIALIZE_ERR;
 	}
 	if (my_strcmp_null(cmd_s->reference, des_s->reference)) {
+		set_deserialize_reject_reason("args/reference-changed");
 		trace_printf_key(&trace_deserialize, "reject: reference");
 		return DESERIALIZE_ERR;
 	}
 	/* verbose */
 	/* amend */
 	if (cmd_s->whence != des_s->whence) {
+		set_deserialize_reject_reason("args/whence-changed");
 		trace_printf_key(&trace_deserialize, "reject: whence");
 		return DESERIALIZE_ERR;
 	}
@@ -625,19 +662,23 @@ static int wt_deserialize_fd(const struct wt_status *cmd_s, struct wt_status *de
 	/* hints */
 	/* ahead_behind_flags */
 	if (cmd_s->detect_rename != des_s->detect_rename) {
+		set_deserialize_reject_reason("args/detect-rename-changed");
 		trace_printf_key(&trace_deserialize, "reject: detect_rename");
 		return DESERIALIZE_ERR;
 	}
 	if (cmd_s->rename_score != des_s->rename_score) {
+		set_deserialize_reject_reason("args/rename-score-changed");
 		trace_printf_key(&trace_deserialize, "reject: rename_score");
 		return DESERIALIZE_ERR;
 	}
 	if (cmd_s->rename_limit != des_s->rename_limit) {
+		set_deserialize_reject_reason("args/rename-limit-changed");
 		trace_printf_key(&trace_deserialize, "reject: rename_limit");
 		return DESERIALIZE_ERR;
 	}
 	/* status_format */
 	if (hashcmp(cmd_s->sha1_commit, des_s->sha1_commit)) {
+		set_deserialize_reject_reason("args/commit-changed");
 		trace_printf_key(&trace_deserialize, "reject: sha1_commit");
 		return DESERIALIZE_ERR;
 	}
diff --git a/wt-status.h b/wt-status.h
index ca0ac6fab38c6b..5245178d7fba03 100644
--- a/wt-status.h
+++ b/wt-status.h
@@ -210,6 +210,8 @@ int wt_status_deserialize(const struct wt_status *cmd_s,
 			  const char *path,
 			  enum wt_status_deserialize_wait dw);
 
+int wt_status_deserialize_access(const char *path, int mode);
+
 /*
  * A helper routine for serialize and deserialize to compute
  * metadata for the user-global and repo-local excludes files.

From dc3c45657529d1b9e813174a11c54d2b5e92534c Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Fri, 21 Dec 2018 10:26:09 -0500
Subject: [PATCH 23/23] trace2: add subverb for rebase

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 builtin/rebase.c | 19 +++++++++++++++++++
 1 file changed, 19 insertions(+)

diff --git a/builtin/rebase.c b/builtin/rebase.c
index ab321b33f96ea4..5d3be749739351 100644
--- a/builtin/rebase.c
+++ b/builtin/rebase.c
@@ -1009,6 +1009,16 @@ int cmd_rebase(int argc, const char **argv, const char *prefix)
 		ACTION_EDIT_TODO,
 		ACTION_SHOW_CURRENT_PATCH,
 	} action = NO_ACTION;
+	static const char *action_names[] = {
+		N_("undefined"),
+		N_("continue"),
+		N_("skip"),
+		N_("abort"),
+		N_("quit"),
+		N_("edit_todo"),
+		N_("show_current_patch"),
+		NULL
+	};
 	const char *gpg_sign = NULL;
 	struct string_list exec = STRING_LIST_INIT_NODUP;
 	const char *rebase_merges = NULL;
@@ -1195,6 +1205,15 @@ int cmd_rebase(int argc, const char **argv, const char *prefix)
 		die(_("The --edit-todo action can only be used during "
 		      "interactive rebase."));
 
+	if (trace2_is_enabled()) {
+		if (is_interactive(&options))
+			trace2_cmd_subverb("interactive");
+		else if (exec.nr)
+			trace2_cmd_subverb("interactive-exec");
+		else
+			trace2_cmd_subverb(action_names[action]);
+	}
+
 	switch (action) {
 	case ACTION_CONTINUE: {
 		struct object_id head;