From 450756fe91fbd7d5be9c8abbc47f0d3c0886f065 Mon Sep 17 00:00:00 2001
From: Johannes Schindelin <johannes.schindelin@gmx.de>
Date: Tue, 2 Oct 2018 21:55:11 +0200
Subject: [PATCH 01/25] fixup! tests: replace mingw_test_cmp with a helper in C

The /dev/null trick does not even work... It makes `git diff --no-index`
fail because it tries to access the XDG config as
`\\.\GLOBALROOT\Device\Null/.config/git/config`, which is not even a
valid path (and therefore the `access_error_is_ok()` check fails).

Let's just use a known-missing path on Windows.

Signed-off-by: Johannes Schindelin <johannes.schindelin@gmx.de>
---
 t/helper/test-cmp.c | 10 ++++++++--
 1 file changed, 8 insertions(+), 2 deletions(-)

diff --git a/t/helper/test-cmp.c b/t/helper/test-cmp.c
index 98dd0791520fe0..1c646a54bf609b 100644
--- a/t/helper/test-cmp.c
+++ b/t/helper/test-cmp.c
@@ -5,6 +5,12 @@
 #include "parse-options.h"
 #include "run-command.h"
 
+#ifdef WIN32
+#define NO_SUCH_DIR "\\\\.\\GLOBALROOT\\invalid"
+#else
+#define NO_SUCH_DIR "/dev/null"
+#endif
+
 static int run_diff(const char *path1, const char *path2)
 {
 	const char *argv[] = {
@@ -12,8 +18,8 @@ static int run_diff(const char *path1, const char *path2)
 	};
 	const char *env[] = {
 		"GIT_PAGER=cat",
-		"GIT_DIR=/dev/null",
-		"HOME=/dev/null",
+		"GIT_DIR=" NO_SUCH_DIR,
+		"HOME=" NO_SUCH_DIR,
 		NULL
 	};
 

From 05eeede60df27e4655c5502aa8d057b754e2cc61 Mon Sep 17 00:00:00 2001
From: Johannes Schindelin <johannes.schindelin@gmx.de>
Date: Tue, 2 Oct 2018 22:05:17 +0200
Subject: [PATCH 02/25] t0001: fix on case-insensitive filesystems

On a case-insensitive filesystem, such as HFS+ or NTFS, it is possible
that the idea Bash has of the current directory differs in case from
what Git thinks it is. That's totally okay, though, and we should not
expect otherwise.

Reported by Jameson Miller.

Signed-off-by: Johannes Schindelin <johannes.schindelin@gmx.de>
---
 t/t0001-init.sh | 12 ++++++++++++
 1 file changed, 12 insertions(+)

diff --git a/t/t0001-init.sh b/t/t0001-init.sh
index 7c48ed2aba2843..7f19368fc10b43 100755
--- a/t/t0001-init.sh
+++ b/t/t0001-init.sh
@@ -307,10 +307,20 @@ test_expect_success 'init prefers command line to GIT_DIR' '
 	test_path_is_missing otherdir/refs
 '
 
+downcase_on_case_insensitive_fs () {
+	test false = "$(git config --get core.filemode)" || return 0
+	for f
+	do
+		tr A-Z a-z <"$f" >"$f".downcased &&
+		mv -f "$f".downcased "$f" || return 1
+	done
+}
+
 test_expect_success 'init with separate gitdir' '
 	rm -rf newdir &&
 	git init --separate-git-dir realgitdir newdir &&
 	echo "gitdir: $(pwd)/realgitdir" >expected &&
+	downcase_on_case_insensitive_fs expected newdir/.git &&
 	test_cmp expected newdir/.git &&
 	test_path_is_dir realgitdir/refs
 '
@@ -365,6 +375,7 @@ test_expect_success 're-init to update git link' '
 	git init --separate-git-dir ../surrealgitdir
 	) &&
 	echo "gitdir: $(pwd)/surrealgitdir" >expected &&
+	downcase_on_case_insensitive_fs expected newdir/.git &&
 	test_cmp expected newdir/.git &&
 	test_path_is_dir surrealgitdir/refs &&
 	test_path_is_missing realgitdir/refs
@@ -378,6 +389,7 @@ test_expect_success 're-init to move gitdir' '
 	git init --separate-git-dir ../realgitdir
 	) &&
 	echo "gitdir: $(pwd)/realgitdir" >expected &&
+	downcase_on_case_insensitive_fs expected newdir/.git &&
 	test_cmp expected newdir/.git &&
 	test_path_is_dir realgitdir/refs
 '

From 4aee99aac2947c34f2061fd1466051922267cafa Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Wed, 17 Oct 2018 11:05:49 -0400
Subject: [PATCH 03/25] 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 ac4c1beecf05a3..4c58534be4c264 100644
--- a/compat/mingw.c
+++ b/compat/mingw.c
@@ -1957,6 +1957,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
@@ -1966,14 +1967,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);
@@ -1986,13 +1989,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 a85c48508e6c48..d378381edeeb0d 100644
--- a/git.c
+++ b/git.c
@@ -752,21 +752,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);
@@ -935,5 +939,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 1c5a6c224ecf43..e746afa3dd0a39 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 630c76d1275485..a176235db25589 100644
--- a/t/helper/test-parse-options.c
+++ b/t/helper/test-parse-options.c
@@ -1,6 +1,7 @@
 #include "cache.h"
 #include "parse-options.h"
 #include "string-list.h"
+#include "trace2.h"
 
 static int boolean = 0;
 static int integer = 0;
@@ -152,6 +153,8 @@ int cmd_main(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 5d414e6f34c9b31aae3b5932c17d972ad1ae10b1 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 26 Nov 2018 07:07:16 -0500
Subject: [PATCH 04/25] 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 84ba198c31ebd95757d4250268c63c12b3e45f35 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Fri, 7 Dec 2018 19:25:13 +0000
Subject: [PATCH 05/25] 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 7f19368fc10b43..530184689fd552 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 6394d75d57d1909bf72d7df764624d2825756771 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 12 Nov 2018 07:12:22 -0500
Subject: [PATCH 06/25] 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 63180c07fe9b6add830ea8228b88f81806522c62 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 12 Nov 2018 14:24:02 -0500
Subject: [PATCH 07/25] 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 a7746dfb59abd3a7846854b6a043402d105ba112 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 19 Nov 2018 15:47:30 -0500
Subject: [PATCH 08/25] 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 a08386229e131aacd0adb9a207d718c784c33e55 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 12 Nov 2018 13:54:16 -0500
Subject: [PATCH 09/25] 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 fded5c253012bf..fa399e14b454e6 100644
--- a/config.mak.uname
+++ b/config.mak.uname
@@ -427,7 +427,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 -SUBSYSTEM:CONSOLE
 	# invalidcontinue.obj allows Git's source code to close the same file
@@ -591,7 +592,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 d90532199e3655a76a9624f667fee8a62661cfb0 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Thu, 11 Oct 2018 16:35:36 -0400
Subject: [PATCH 10/25] 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 b8b0942d96ab8c..bd1e55d8a87f9d 100644
--- a/Makefile
+++ b/Makefile
@@ -740,6 +740,7 @@ TEST_BUILTINS_OBJS += test-strcmp-offset.o
 TEST_BUILTINS_OBJS += test-string-list.o
 TEST_BUILTINS_OBJS += test-submodule-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 1ac1e29d8a2851..e5342b1422464c 100644
--- a/t/helper/test-tool.c
+++ b/t/helper/test-tool.c
@@ -45,6 +45,7 @@ static struct test_cmd cmds[] = {
 	{ "string-list", cmd__string_list },
 	{ "submodule-config", cmd__submodule_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 55a90fbd12a1c8..12b99f367a3072 100644
--- a/t/helper/test-tool.h
+++ b/t/helper/test-tool.h
@@ -40,6 +40,7 @@ int cmd__strcmp_offset(int argc, const char **argv);
 int cmd__string_list(int argc, const char **argv);
 int cmd__submodule_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 669b5d7f1c21003bbf58359a1ba6b53ce8fbe2c6 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 5 Nov 2018 07:29:53 -0500
Subject: [PATCH 11/25] 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 1968e64ac6c03e..e2def410d8a668 100644
--- a/builtin/checkout.c
+++ b/builtin/checkout.c
@@ -256,6 +256,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");
 
@@ -927,6 +929,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)
@@ -1142,6 +1147,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 3c5e144a542969fb366f413981717740d7beb3f7 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 5 Nov 2018 11:36:43 -0500
Subject: [PATCH 12/25] 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 ba65e45cb40439..d0ccfbd0ae9d2d 100644
--- a/builtin/reset.c
+++ b/builtin/reset.c
@@ -415,6 +415,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);
 	}
 
@@ -431,6 +432,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 f89164fff9a7a81681217d7853c6cf0e971c0493 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 5 Nov 2018 16:59:47 -0500
Subject: [PATCH 13/25] trace2: add subverb for rebase

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

diff --git a/builtin/rebase.c b/builtin/rebase.c
index 3d2db0369c91dd..dbeb5913b523bf 100644
--- a/builtin/rebase.c
+++ b/builtin/rebase.c
@@ -954,6 +954,11 @@ 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
+	};
 	int committer_date_is_author_date = 0;
 	int ignore_date = 0;
 	int ignore_whitespace = 0;
@@ -1142,6 +1147,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;

From 3d9b394b804209f6ea0a78983f66d80af71c6d89 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 5 Nov 2018 10:12:56 -0500
Subject: [PATCH 14/25] 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 4ef879b3d4681b..20a907f402c44f 100644
--- a/builtin/commit.c
+++ b/builtin/commit.c
@@ -1582,6 +1582,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;
@@ -1599,6 +1600,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)
@@ -1613,6 +1615,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 df37f27437fa0afa836f85ed83638403a9034b9b Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 12 Nov 2018 17:44:58 -0500
Subject: [PATCH 15/25] 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 20a907f402c44f..dbf008f25bbaec 100644
--- a/builtin/commit.c
+++ b/builtin/commit.c
@@ -143,6 +143,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;
@@ -200,7 +201,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);
 
@@ -1389,6 +1390,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;
 	}
@@ -1544,6 +1547,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(1);
 	read_cache_preload(&s.pathspec);
diff --git a/wt-status-deserialize.c b/wt-status-deserialize.c
index ba277e95e5e3df..81626773a14def 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 bd7a41c25a1491..e1b05ed9380ef2 100644
--- a/wt-status.h
+++ b/wt-status.h
@@ -208,6 +208,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 cf4e62b03423c4d66741fc82ed1719b69b23b92f Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 19 Nov 2018 16:26:37 -0500
Subject: [PATCH 16/25] 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 d70f10c310fa99..bb256280127095 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 4f3fe0f9d158dfd0895be9aaf099aba6942d7f64 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 26 Nov 2018 07:09:42 -0500
Subject: [PATCH 17/25] 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 9ddf620ddbda5304b3b03a8c7e79754275f3955b Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 26 Nov 2018 07:13:18 -0500
Subject: [PATCH 18/25] 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 dae4e20683e9c8f04b251c29434bdf705f86967d Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 26 Nov 2018 07:16:43 -0500
Subject: [PATCH 19/25] 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 2890c7bb09b3883f19e42792f4d40f652f624c9c Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 26 Nov 2018 09:03:45 -0500
Subject: [PATCH 20/25] 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 bd1e55d8a87f9d..245ea0bf20b95d 100644
--- a/Makefile
+++ b/Makefile
@@ -992,6 +992,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 70314049c3758d000130f0ecd8bd7423f26a8fd7 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Mon, 26 Nov 2018 14:45:57 -0500
Subject: [PATCH 21/25] 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 5e866d17c7c7b4..5fb5d966883be3 100644
--- a/builtin/am.c
+++ b/builtin/am.c
@@ -520,6 +520,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 c17ce94e12ee34..d974680a274c5f 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)
@@ -1184,6 +1187,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 41e7714396dc33..59e9fc319fa6c3 100644
--- a/builtin/worktree.c
+++ b/builtin/worktree.c
@@ -353,6 +353,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 e746afa3dd0a39..14ecaf83efbec7 100644
--- a/run-command.c
+++ b/run-command.c
@@ -1391,6 +1391,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 e71ddd65afe5e1..3572b17223d5d2 100644
--- a/run-command.h
+++ b/run-command.h
@@ -16,6 +16,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 f312ce123e8abb..75a7458d817652 100644
--- a/sequencer.c
+++ b/sequencer.c
@@ -1039,6 +1039,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)
@@ -3648,6 +3649,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 06ffea277460d6..91b5b66a51c17e 100644
--- a/transport.c
+++ b/transport.c
@@ -1028,6 +1028,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 f2d43cba2e10aa75d90dbe87f0a0d352394b7f8a Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Fri, 12 Oct 2018 13:16:58 -0400
Subject: [PATCH 22/25] 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 917d31831122fd..0e5b37eb07cb0a 100644
--- a/t/test-lib.sh
+++ b/t/test-lib.sh
@@ -131,6 +131,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 b8de12d386b9e3c0b42479fcf6f1c83d08de9643 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Tue, 4 Dec 2018 22:25:18 +0000
Subject: [PATCH 23/25] 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 151668e11553b330e6e7112db6d8766cef8d9368 Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Tue, 4 Dec 2018 22:28:16 +0000
Subject: [PATCH 24/25] 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 afeca83fe761bf232df742e0ce6d1731cd7a696d Mon Sep 17 00:00:00 2001
From: Jeff Hostetler <jeffhost@microsoft.com>
Date: Tue, 4 Dec 2018 22:38:11 +0000
Subject: [PATCH 25/25] 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') {