[PATCH v4 3/3] run-command: show prepared command

From: Ian Wienand <iwienand@redhat.com>
Date: May 24, 2024, 07:32 UTC
Message-ID: <20240524073411.1355958-3-iwienand@redhat.com>
In-Reply-To: <20240524073411.1355958-1-iwienand@redhat.com>

This adds a trace point in prepare_cmd (for windows, prepare_shell_cmd), so we can see the actual command being run without having to resort to strace/code inspection.

e.g. "test = !echo" when run under GIT_TRACE will show:

 $ GIT_TRACE=1 git test hello
 10:58:56.877234 git.c:755               trace: exec: git-test hello
 10:58:56.877382 run-command.c:657       trace: run_command: git-test hello
 10:58:56.878655 run-command.c:657       trace: run_command: echo hello
 10:58:56.878747 run-command.c:437       trace: prepare_cmd: /usr/bin/echo hello
 hello

A "split" alias, e.g. test = "!echo $*" will show the shell wrapping and appending of "$@".

 $ GIT_TRACE=1 git test hello
 11:00:45.959420 git.c:755               trace: exec: git-test hello
 11:00:45.959737 run-command.c:657       trace: run_command: git-test hello
 11:00:45.961424 run-command.c:657       trace: run_command: 'echo $*' hello
 11:00:45.961528 run-command.c:437       trace: prepare_cmd: /bin/sh -c 'echo $* "$@"' 'echo $*' hello
 hello hello

Prior changes have made the documentation around the internals of the alias command execution clearer, but I have still found this detailed view of the aliased command being run helpful for debugging purposes.

A test case is added. This simply looks for the trace point output; the details change depending on platform -- the important thing is that we have a verbose log point, not so much the details of what happens on each platform.

Signed-off-by: Ian Wienand <iwienand@redhat.com>
---
 run-command.c    | 2 ++
 t/t0014-alias.sh | 6 ++++++
 2 files changed, 8 insertions(+)

diff --git a/run-command.c b/run-command.c
index 1b821042b4..13e35fb76e 100644
--- a/run-command.c
+++ b/run-command.c
@@ -296,6 +296,7 @@ static const char **prepare_shell_cmd(struct strvec *out, const char **argv)
 	}
 
 	strvec_pushv(out, argv);
+	trace_argv_printf(&out->v[1], "trace: prepare_cmd:");
 	return out->v;
 }
 
@@ -435,6 +436,7 @@ static int prepare_cmd(struct strvec *out, const struct child_process *cmd)
 		}
 	}
 
+	trace_argv_printf(&out->v[1], "trace: prepare_cmd:");
 	return 0;
 }
 
diff --git a/t/t0014-alias.sh b/t/t0014-alias.sh
index 95568342be..b7affbe93a 100755
--- a/t/t0014-alias.sh
+++ b/t/t0014-alias.sh
@@ -44,4 +44,10 @@ test_expect_success 'run-command formats empty args properly' '
     test_cmp expect actual
 '
 
+test_expect_success 'tracing a shell alias with arguments shows trace of prepared command' '
+	git config alias.echo "!echo \$*" &&
+	env GIT_TRACE=1 git echo argument 2>output &&
+	test_grep "^trace: prepare_cmd:.*" output
+'
+
 test_done

-- 
2.45.1