| Message ID | 20240524073411.1355958-3-iwienand@redhat.com (mailing list archive) |
|---|---|
| State | Superseded |
| Headers | show |
| Series | [v4,1/3] Documentation: alias: rework notes into points | expand |
Ian Wienand <iwienand@redhat.com> writes: > +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 > +' If you run $ cd t && sh ./t0014-alias.sh -d && cat trash*.t0014-alias/output you'll see two "prepare_cmd" logged, because you added one to prepare_shell_cmd() and another to prepare_cmd(). If you were tracing something that uses prepare_git_cmd() on Windows, you would not see any trace output, on the other hand, I would suspect (I do not do Windows so this is from code inspection only). Perhaps squashing something like this is sufficient? run-command.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git c/run-command.c w/run-command.c index 13e35fb76e..7eb68a541d 100644 --- c/run-command.c +++ w/run-command.c @@ -296,7 +296,6 @@ 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; } @@ -436,7 +435,6 @@ static int prepare_cmd(struct strvec *out, const struct child_process *cmd) } } - trace_argv_printf(&out->v[1], "trace: prepare_cmd:"); return 0; } @@ -747,6 +745,7 @@ int start_command(struct child_process *cmd) error_errno("cannot run %s", cmd->args.v[0]); goto end_of_spawn; } + trace_argv_printf(&argv.v[1], "trace: prepare_cmd:"); if (pipe(notify_pipe)) notify_pipe[0] = notify_pipe[1] = -1; @@ -914,6 +913,7 @@ int start_command(struct child_process *cmd) cmd->args.v = prepare_git_cmd(&nargv, sargv); else if (cmd->use_shell) cmd->args.v = prepare_shell_cmd(&nargv, sargv); + trace_argv_printf(&cmd->args.v[1], "trace: prepare_cmd:"); cmd->pid = mingw_spawnvpe(cmd->args.v[0], cmd->args.v, (char**) cmd->env.v,
Junio C Hamano <gitster@pobox.com> writes: >> + test_grep "^trace: prepare_cmd:.*" output >> +' > > If you run > > $ cd t && sh ./t0014-alias.sh -d && cat trash*.t0014-alias/output > > you'll see two "prepare_cmd" logged, because you added one to > prepare_shell_cmd() and another to prepare_cmd(). To avoid similar issues, perhaps the test can try to see a bit more into the output? We already know that we cannot expect the output to be identical everywhere, but we can do something along the lines of the attached patch, or is the expected pattern below a bit too specific? t/t0014-alias.sh | 10 +++++++++- 1 file changed, 9 insertions(+), 1 deletion(-) diff --git c/t/t0014-alias.sh w/t/t0014-alias.sh index b7affbe93a..a3c133be96 100755 --- c/t/t0014-alias.sh +++ w/t/t0014-alias.sh @@ -45,9 +45,17 @@ test_expect_success 'run-command formats empty args properly' ' ' test_expect_success 'tracing a shell alias with arguments shows trace of prepared command' ' + cat >expect <<-EOF && + trace: exec: git-echo argument + trace: run_command: git-echo argument + trace: run_command: ${SQ}echo \$*${SQ} argument + trace: prepare_cmd: SHELL -c ${SQ}echo \$* "\$@"${SQ} ${SQ}echo \$*${SQ} argument + EOF git config alias.echo "!echo \$*" && env GIT_TRACE=1 git echo argument 2>output && - test_grep "^trace: prepare_cmd:.*" output + # redact platform differences + sed -e "s/^\(trace: prepare_cmd:\) .* -c /\1 SHELL -c /" output >actual && + test_cmp expect actual ' test_done
On Fri, May 24, 2024 at 12:16:34PM -0700, Junio C Hamano wrote: > Ian Wienand <iwienand@redhat.com> writes: > > > +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 > > +' > > If you run > > $ cd t && sh ./t0014-alias.sh -d && cat trash*.t0014-alias/output > > you'll see two "prepare_cmd" logged, because you added one to > prepare_shell_cmd() and another to prepare_cmd(). Sorry that's a bit embarrasing that I missed that. Reading this more carefully, I agree that the points you've identified in start_command are probably the best place. I've updated to this. -i
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
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(+)