(Experimental) Trace2 base plus GVFS extensions

Makefile

@@ -741,6 +741,7 @@ TEST_BUILTINS_OBJS += test-submodule-config.o
 TEST_BUILTINS_OBJS += test-subprocess.o
 TEST_BUILTINS_OBJS += test-urlmatch-normalization.o
 TEST_BUILTINS_OBJS += test-wildmatch.o
+TEST_BUILTINS_OBJS += test-windows-named-pipe.o
 TEST_BUILTINS_OBJS += test-write-cache.o
 
 TEST_PROGRAMS_NEED_X += test-dump-fsmonitor
@@ -980,6 +981,15 @@ LIB_OBJS += tag.o
 LIB_OBJS += tempfile.o
 LIB_OBJS += tmp-objdir.o
 LIB_OBJS += trace.o
+LIB_OBJS += trace2.o
+LIB_OBJS += trace2/tr2_cfg.o
+LIB_OBJS += trace2/tr2_dst.o
+LIB_OBJS += trace2/tr2_sid.o
+LIB_OBJS += trace2/tr2_tbuf.o
+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 += trailer.o
 LIB_OBJS += transport.o
 LIB_OBJS += transport-helper.o

cache.h

@@ -9,6 +9,7 @@
 #include "gettext.h"
 #include "convert.h"
 #include "trace.h"
+#include "trace2.h"
 #include "string-list.h"
 #include "pack-revindex.h"
 #include "hash.h"

common-main.c

@@ -31,6 +31,9 @@ int main(int argc, const char **argv)
 	 * onto stdin/stdout/stderr in the child processes we spawn.
 	 */
 	sanitize_stdfds();
+	restore_sigpipe_to_default();
+
+	trace2_initialize(argv);
 
 	git_resolve_executable_dir(argv[0]);
 
@@ -40,7 +43,5 @@ int main(int argc, const char **argv)
 
 	attr_start();
 
-	restore_sigpipe_to_default();
-
 	return cmd_main(argc, argv);
 }

compat/mingw.c

@@ -557,6 +557,19 @@ int mingw_mkdir(const char *path, int mode)
 	return ret;
 }
 
+/*
+ * Calling CreateFile() using FILE_APPEND_DATA and without FILE_WRITE_DATA
+ * is documented in [1] as opening a writable file handle in append mode.
+ * (It is believed that) this is atomic since it is maintained by the
+ * kernel unlike the O_APPEND flag which is racily maintained by the CRT.
+ *
+ * [1] https://docs.microsoft.com/en-us/windows/desktop/fileio/file-access-rights-constants
+ *
+ * This trick does not appear to work for named pipes.  Instead it creates
+ * a named pipe client handle that cannot be written to.  Callers should
+ * just use the regular _wopen() for them.  (And since client handle gets
+ * bound to a unique server handle, it isn't really an issue.)
+ */
 static int mingw_open_append(wchar_t const *wfilename, int oflags, ...)
 {
 	HANDLE handle;
@@ -576,17 +589,36 @@ static int mingw_open_append(wchar_t const *wfilename, int oflags, ...)
 			NULL, create, FILE_ATTRIBUTE_NORMAL, NULL);
 	if (handle == INVALID_HANDLE_VALUE)
 		return errno = err_win_to_posix(GetLastError()), -1;
+
 	/*
 	 * No O_APPEND here, because the CRT uses it only to reset the
-	 * file pointer to EOF on write(); but that is not necessary
-	 * for a file created with FILE_APPEND_DATA.
+	 * file pointer to EOF before each write(); but that is not
+	 * necessary (and may lead to races) for a file created with
+	 * FILE_APPEND_DATA.
 	 */
 	fd = _open_osfhandle((intptr_t)handle, O_BINARY);
 	if (fd < 0)
 		CloseHandle(handle);
 	return fd;
 }
 
+#define IS_SBS(ch) (((ch) == '/') || ((ch) == '\\'))
+/*
+ * Does the pathname map to the local named pipe filesystem?
+ * That is, does it have a "//./pipe/" prefix?
+ */
+static int mingw_is_local_named_pipe_path(const char *filename)
+{
+	return (IS_SBS(filename[0]) &&
+		IS_SBS(filename[1]) &&
+		filename[2] == '.'  &&
+		IS_SBS(filename[3]) &&
+		!strncasecmp(filename+4, "pipe", 4) &&
+		IS_SBS(filename[8]) &&
+		filename[9]);
+}
+#undef IS_SBS
+
 int mingw_open (const char *filename, int oflags, ...)
 {
 	typedef int (*open_fn_t)(wchar_t const *wfilename, int oflags, ...);
@@ -603,7 +635,7 @@ int mingw_open (const char *filename, int oflags, ...)
 	if (filename && !strcmp(filename, "/dev/null"))
 		filename = "nul";
 
-	if (oflags & O_APPEND)
+	if ((oflags & O_APPEND) && !mingw_is_local_named_pipe_path(filename))
 		open_fn = mingw_open_append;
 	else
 		open_fn = _wopen;
@@ -1939,6 +1971,7 @@ static int try_shell_exec(const char *cmd, char *const *argv)
 			int status;
 			if (waitpid(pid, &status, 0) < 0)
 				status = 255;
+			trace2_exec_result(status);
 			exit(status);
 		}
 		pid = 1;	/* indicate that we tried but failed */
@@ -1959,6 +1992,7 @@ int mingw_execv(const char *cmd, char *const *argv)
 			return -1;
 		if (waitpid(pid, &status, 0) < 0)
 			status = 255;
+		trace2_exec_result(status);
 		exit(status);
 	}
 	return -1;

compat/mingw.h

@@ -146,8 +146,7 @@ static inline int fcntl(int fd, int cmd, ...)
 	errno = EINVAL;
 	return -1;
 }
-/* bash cannot reliably detect negative return codes as failure */
-#define exit(code) exit((code) & 0xff)
+
 #define sigemptyset(x) (void)0
 static inline int sigaddset(sigset_t *set, int signum)
 { return 0; }

config.c

@@ -2682,6 +2682,8 @@ int git_config_set_gently(const char *key, const char *value)
 void git_config_set(const char *key, const char *value)
 {
 	git_config_set_multivar(key, value, NULL, 0);
+
+	trace2_cmd_set_config(key, value);
 }
 
 /*

connect.c

@@ -1255,6 +1255,7 @@ struct child_process *git_connect(int fd[2], const char *url,
 		conn = NULL;
 	} else if (protocol == PROTO_GIT) {
 		conn = git_connect_git(fd, hostandport, path, prog, version, flags);
+		conn->trace2_child_class = "transport/git";
 	} else {
 		struct strbuf cmd = STRBUF_INIT;
 		const char *const *var;
@@ -1297,9 +1298,11 @@ struct child_process *git_connect(int fd[2], const char *url,
 				strbuf_release(&cmd);
 				return NULL;
 			}
+			conn->trace2_child_class = "transport/ssh";
 			fill_ssh_args(conn, ssh_host, port, version, flags);
 		} else {
 			transport_check_allowed("file");
+			conn->trace2_child_class = "transport/file";
 			if (version > 0) {
 				argv_array_pushf(&conn->env_array, GIT_PROTOCOL_ENVIRONMENT "=version=%d",
 						 version);

editor.c

@@ -78,6 +78,7 @@ static int launch_specified_editor(const char *editor, const char *path,
 		p.argv = args;
 		p.env = env;
 		p.use_shell = 1;
+		p.trace2_child_class = "editor";
 		if (start_command(&p) < 0)
 			return error("unable to start editor '%s'", editor);
 

exec-cmd.c

@@ -209,6 +209,8 @@ static int git_get_exec_path(struct strbuf *buf, const char *argv0)
 		return -1;
 	}
 
+	trace2_cmd_path(buf->buf);
+
 	return 0;
 }
 
@@ -328,16 +330,22 @@ 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);
 
-	trace_printf("trace: exec failed: %s\n", strerror(errno));
+	err = errno;
+	trace_printf("trace: exec failed: %s\n", strerror(err));
+	trace2_exec_result(err);
 
 	argv_array_clear(&nargv);
+
+	errno = err;
 	return -1;
 }
 

git-compat-util.h

@@ -1296,6 +1296,13 @@ static inline int is_missing_file_error(int errno_)
 
 extern int cmd_main(int, const char **);
 
+/*
+ * Intercept all calls to exit() and route them to trace2 to
+ * optionally emit a message before calling the real exit().
+ */
+int trace2_cmd_exit_fl(const char *file, int line, int code);
+#define exit(code) exit(trace2_cmd_exit_fl(__FILE__, __LINE__, (code)))
+
 /*
  * You can mark a stack variable with UNLEAK(var) to avoid it being
  * reported as a leak by tools like LSAN or valgrind. The argument

git.c

@@ -147,16 +147,20 @@ static int handle_options(const char ***argv, int *argc, int *envchanged)
 				git_set_exec_path(cmd + 1);
 			else {
 				puts(git_exec_path());
+				trace2_cmd_verb("_query_");
 				exit(0);
 			}
 		} else if (!strcmp(cmd, "--html-path")) {
 			puts(system_path(GIT_HTML_PATH));
+			trace2_cmd_verb("_query_");
 			exit(0);
 		} else if (!strcmp(cmd, "--man-path")) {
 			puts(system_path(GIT_MAN_PATH));
+			trace2_cmd_verb("_query_");
 			exit(0);
 		} else if (!strcmp(cmd, "--info-path")) {
 			puts(system_path(GIT_INFO_PATH));
+			trace2_cmd_verb("_query_");
 			exit(0);
 		} else if (!strcmp(cmd, "-p") || !strcmp(cmd, "--paginate")) {
 			use_pager = 1;
@@ -285,6 +289,7 @@ static int handle_options(const char ***argv, int *argc, int *envchanged)
 			(*argv)++;
 			(*argc)--;
 		} else if (skip_prefix(cmd, "--list-cmds=", &cmd)) {
+			trace2_cmd_verb("_query_");
 			if (!strcmp(cmd, "parseopt")) {
 				struct string_list list = STRING_LIST_INIT_DUP;
 				int i;
@@ -329,9 +334,14 @@ static int handle_alias(int *argcp, const char ***argv)
 			commit_pager_choice();
 
 			child.use_shell = 1;
+			child.trace2_child_class = "shell_alias";
 			argv_array_push(&child.args, alias_string + 1);
 			argv_array_pushv(&child.args, (*argv) + 1);
 
+			trace2_cmd_alias(alias_command, child.args.argv);
+			trace2_cmd_list_config();
+			trace2_cmd_verb("_run_shell_alias_");
+
 			ret = run_command(&child);
 			if (ret >= 0)   /* normal exit */
 				exit(ret);
@@ -366,6 +376,9 @@ static int handle_alias(int *argcp, const char ***argv)
 		/* insert after command name */
 		memcpy(new_argv + count, *argv + 1, sizeof(char *) * *argcp);
 
+		trace2_cmd_alias(alias_command, new_argv);
+		trace2_cmd_list_config();
+
 		*argv = new_argv;
 		*argcp += count - 1;
 
@@ -475,6 +488,8 @@ static int run_builtin(struct cmd_struct *p, int argc, const char **argv)
 		die("pre-command hook aborted command");
 
 	trace_argv_printf(argv, "trace: built-in: git");
+	trace2_cmd_verb(p->cmd);
+	trace2_cmd_list_config();
 
 	validate_cache_entries(&the_index);
 	exit_code = status = p->fn(argc, argv, prefix);
@@ -732,23 +747,34 @@ static void execv_dashed_external(const char **argv)
 	cmd.clean_on_exit = 1;
 	cmd.wait_after_clean = 1;
 	cmd.silent_exec_failure = 1;
+	cmd.trace2_child_class = "dashed";
 
 	if (run_pre_command_hook(cmd.args.argv))
 		die("pre-command hook aborted command");
 
 	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.
+	 *
+	 * 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);
-	if (status >= 0)
+	trace2_exec_result(status);
+	if (status >= 0) {
+		trace2_cmd_verb("_run_dashed_");
 		exit(status);
-	else if (errno != ENOENT)
+	}
+	else if (errno != ENOENT) {
+		trace2_cmd_verb("_run_dashed_");
 		exit(128);
+	}
 
 	run_post_command_hook();
 }
@@ -773,6 +799,15 @@ static int run_argv(int *argcp, const char ***argv)
 			struct argv_array args = ARGV_ARRAY_INIT;
 			int i;
 
+			/*
+			 * The current process is committed to launching a
+			 * child process to run the command named in (**argv)
+			 * and exiting.  Log a generic string as the trace2
+			 * command verb to indicate this.  Note that the child
+			 * process will log the actual verb when it runs.
+			 */
+			trace2_cmd_verb("_run_git_alias_");
+
 			if (get_super_prefix())
 				die("%s doesn't support --super-prefix", **argv);
 
@@ -788,8 +823,8 @@ static int run_argv(int *argcp, const char ***argv)
 			 * if we fail because the command is not found, it is
 			 * OK to return. Otherwise, we just pass along the status code.
 			 */
-			i = run_command_v_opt(args.argv, RUN_SILENT_EXEC_FAILURE |
-					      RUN_CLEAN_ON_EXIT);
+			i = run_command_v_opt_tr2(args.argv, RUN_SILENT_EXEC_FAILURE |
+						  RUN_CLEAN_ON_EXIT, "git_alias");
 			if (i >= 0 || errno != ENOENT)
 				exit(i);
 			die("could not execute builtin %s", **argv);
@@ -900,5 +935,5 @@ int cmd_main(int argc, const char **argv)
 	fprintf(stderr, _("failed to run command '%s': %s\n"),
 		cmd, strerror(errno));
 
-	return 1;
+	return trace2_cmd_exit(1);
 }

pager.c

@@ -103,6 +103,7 @@ void prepare_pager_args(struct child_process *pager_process, const char *pager)
 	argv_array_push(&pager_process->args, pager);
 	pager_process->use_shell = 1;
 	setup_pager_env(&pager_process->env_array);
+	pager_process->trace2_child_class = "pager";
 }
 
 void setup_pager(void)