Message ID | 0767c8b77c820cfc03bbc617da4dc9f20ba4a46a.1585114881.git.gitgitgadget@gmail.com (mailing list archive) |
---|---|
State | New, archived |
Headers | show |
Series | Enable GPG in the Windows part of the CI/PR builds | expand |
"Johannes Schindelin via GitGitGadget" <gitgitgadget@gmail.com> writes: > The `test_expect_*` functions use `test_eval_` and so does > `test_run_lazy_prereq_`. If tracing is enabled via the `-x` option, > `test_eval_` turns on tracing while evaluating the code block, and turns > it off directly after it. > > This is unwanted for nested invocations. Nice finding. > As we will introduce just such a scenario with the GPG, GPGSM and > RFC1991 prereqs, let's fix that by introducing a variable that keeps > track of the current trace level: nested `test_eval_` calls will > increment and then decrement the level, and only when it reaches 0, the > tracing will _actually_ be turned off. Doesn't this explanation urge us to reorder these patches? It sounds to me that it argues to have this step before 3/5. Other than that, both the explanation and the code look correctly done. It looks to me that the surrounding code favors trailing "_" instead of leading one for private names, so we might want to rename the variable to $trace_level_ but that is minor. Thanks. > Signed-off-by: Johannes Schindelin <johannes.schindelin@gmx.de> > --- > t/t0000-basic.sh | 13 +++++++++++++ > t/test-lib.sh | 6 ++++-- > 2 files changed, 17 insertions(+), 2 deletions(-) > > diff --git a/t/t0000-basic.sh b/t/t0000-basic.sh > index 3e440c078d5..b8597216200 100755 > --- a/t/t0000-basic.sh > +++ b/t/t0000-basic.sh > @@ -833,6 +833,19 @@ then > exit 1 > fi > > +test_expect_success 'lazy prereqs do not turn off tracing' " > + run_sub_test_lib_test lazy-prereq-and-tracing \ > + 'lazy prereqs and -x' -v -x <<-\\EOF && > + test_lazy_prereq LAZY true > + > + test_expect_success lazy 'test_have_prereq LAZY && echo trace' > + > + test_done > + EOF > + > + grep 'echo trace' lazy-prereq-and-tracing/err > +" > + > test_expect_success 'tests clean up even on failures' " > run_sub_test_lib_test_err \ > failing-cleanup 'Failing tests with cleanup commands' <<-\\EOF && > diff --git a/t/test-lib.sh b/t/test-lib.sh > index 0ea1e5a05ed..dbf25348106 100644 > --- a/t/test-lib.sh > +++ b/t/test-lib.sh > @@ -882,6 +882,7 @@ maybe_setup_valgrind () { > fi > } > > +_trace_level=0 > want_trace () { > test "$trace" = t && { > test "$verbose" = t || test "$verbose_log" = t > @@ -895,7 +896,7 @@ want_trace () { > test_eval_inner_ () { > # Do not add anything extra (including LF) after '$*' > eval " > - want_trace && set -x > + want_trace && _trace_level=$(($_trace_level+1)) && set -x > $*" > } > > @@ -926,7 +927,8 @@ test_eval_ () { > test_eval_ret_=$? > if want_trace > then > - set +x > + test 1 = $_trace_level && set +x > + _trace_level=$(($_trace_level-1)) > fi > } 2>/dev/null 4>&2
On Wed, Mar 25, 2020 at 05:41:20AM +0000, Johannes Schindelin via GitGitGadget wrote: > From: Johannes Schindelin <johannes.schindelin@gmx.de> > > The `test_expect_*` functions use `test_eval_` and so does > `test_run_lazy_prereq_`. If tracing is enabled via the `-x` option, > `test_eval_` turns on tracing while evaluating the code block, and turns > it off directly after it. > > This is unwanted for nested invocations. > > One somewhat surprising example of this is when running a test that > calls `test_i18ngrep`: that function requires the `C_LOCALE_OUTPUT` > prereq, and that prereq is a lazy one, so it is evaluated via > `test_eval_`, the command tracing is turned off, and the test case > continues to run _without tracing the commands_. Good catch. I didn't see this when looking at the GPG stuff earlier because I didn't nest the lazy prereqs. But it is worth fixing regardless, because as you note it comes up in other places. > @@ -926,7 +927,8 @@ test_eval_ () { > test_eval_ret_=$? > if want_trace > then > - set +x > + test 1 = $_trace_level && set +x > + _trace_level=$(($_trace_level-1)) > fi > } 2>/dev/null 4>&2 I briefly wondered if adding more logic here might upset our delicate balance of avoiding writing cruft to the "-x" output. But the answer is "no", due to the descriptor hackery at the end of that {} block. Of course, any test evaluating a lazy prereq already gets tons of cruft anyway, because the outer level of tracing sees all of our internal function calls checking the prereq and setting up the inner level of tracing. But there's not much we can do about that. -Peff
Hi Junio, On Wed, 25 Mar 2020, Junio C Hamano wrote: > "Johannes Schindelin via GitGitGadget" <gitgitgadget@gmail.com> > writes: > > > The `test_expect_*` functions use `test_eval_` and so does > > `test_run_lazy_prereq_`. If tracing is enabled via the `-x` option, > > `test_eval_` turns on tracing while evaluating the code block, and turns > > it off directly after it. > > > > This is unwanted for nested invocations. > > Nice finding. Heh. I found this ages ago, and mistook it for "all prereqs turn off tracing" when I reported it, but Gábor pointed out that that is incorrect. That was a long time ago, maybe even a year, and I finally used this patch series as an excuse to finally dig deep on this. > > As we will introduce just such a scenario with the GPG, GPGSM and > > RFC1991 prereqs, let's fix that by introducing a variable that keeps > > track of the current trace level: nested `test_eval_` calls will > > increment and then decrement the level, and only when it reaches 0, the > > tracing will _actually_ be turned off. > > Doesn't this explanation urge us to reorder these patches? It > sounds to me that it argues to have this step before 3/5. Yes, that's where I had meant to put this patch. Sorry for the confusion. > Other than that, both the explanation and the code look correctly > done. It looks to me that the surrounding code favors trailing "_" > instead of leading one for private names, so we might want to rename > the variable to $trace_level_ but that is minor. Good point, I had missed that. Will be fixed in the next iteration. Ciao, Dscho > > Thanks. > > > Signed-off-by: Johannes Schindelin <johannes.schindelin@gmx.de> > > --- > > t/t0000-basic.sh | 13 +++++++++++++ > > t/test-lib.sh | 6 ++++-- > > 2 files changed, 17 insertions(+), 2 deletions(-) > > > > diff --git a/t/t0000-basic.sh b/t/t0000-basic.sh > > index 3e440c078d5..b8597216200 100755 > > --- a/t/t0000-basic.sh > > +++ b/t/t0000-basic.sh > > @@ -833,6 +833,19 @@ then > > exit 1 > > fi > > > > +test_expect_success 'lazy prereqs do not turn off tracing' " > > + run_sub_test_lib_test lazy-prereq-and-tracing \ > > + 'lazy prereqs and -x' -v -x <<-\\EOF && > > + test_lazy_prereq LAZY true > > + > > + test_expect_success lazy 'test_have_prereq LAZY && echo trace' > > + > > + test_done > > + EOF > > + > > + grep 'echo trace' lazy-prereq-and-tracing/err > > +" > > + > > test_expect_success 'tests clean up even on failures' " > > run_sub_test_lib_test_err \ > > failing-cleanup 'Failing tests with cleanup commands' <<-\\EOF && > > diff --git a/t/test-lib.sh b/t/test-lib.sh > > index 0ea1e5a05ed..dbf25348106 100644 > > --- a/t/test-lib.sh > > +++ b/t/test-lib.sh > > @@ -882,6 +882,7 @@ maybe_setup_valgrind () { > > fi > > } > > > > +_trace_level=0 > > want_trace () { > > test "$trace" = t && { > > test "$verbose" = t || test "$verbose_log" = t > > @@ -895,7 +896,7 @@ want_trace () { > > test_eval_inner_ () { > > # Do not add anything extra (including LF) after '$*' > > eval " > > - want_trace && set -x > > + want_trace && _trace_level=$(($_trace_level+1)) && set -x > > $*" > > } > > > > @@ -926,7 +927,8 @@ test_eval_ () { > > test_eval_ret_=$? > > if want_trace > > then > > - set +x > > + test 1 = $_trace_level && set +x > > + _trace_level=$(($_trace_level-1)) > > fi > > } 2>/dev/null 4>&2 >
Hi Peff, On Thu, 26 Mar 2020, Jeff King wrote: > On Wed, Mar 25, 2020 at 05:41:20AM +0000, Johannes Schindelin via GitGitGadget wrote: > > > From: Johannes Schindelin <johannes.schindelin@gmx.de> > > > > The `test_expect_*` functions use `test_eval_` and so does > > `test_run_lazy_prereq_`. If tracing is enabled via the `-x` option, > > `test_eval_` turns on tracing while evaluating the code block, and turns > > it off directly after it. > > > > This is unwanted for nested invocations. > > > > One somewhat surprising example of this is when running a test that > > calls `test_i18ngrep`: that function requires the `C_LOCALE_OUTPUT` > > prereq, and that prereq is a lazy one, so it is evaluated via > > `test_eval_`, the command tracing is turned off, and the test case > > continues to run _without tracing the commands_. > > Good catch. I didn't see this when looking at the GPG stuff earlier > because I didn't nest the lazy prereqs. But it is worth fixing > regardless, because as you note it comes up in other places. > > > @@ -926,7 +927,8 @@ test_eval_ () { > > test_eval_ret_=$? > > if want_trace > > then > > - set +x > > + test 1 = $_trace_level && set +x > > + _trace_level=$(($_trace_level-1)) > > fi > > } 2>/dev/null 4>&2 > > I briefly wondered if adding more logic here might upset our delicate > balance of avoiding writing cruft to the "-x" output. But the answer is > "no", due to the descriptor hackery at the end of that {} block. > > Of course, any test evaluating a lazy prereq already gets tons of cruft > anyway, because the outer level of tracing sees all of our internal > function calls checking the prereq and setting up the inner level of > tracing. But there's not much we can do about that. We could turn off the tracing specifically in those cases. At some point, though, it strikes me as rather ridiculous through how many hoops we jump just because our test suite framework is implemented in portable Unix shell script, as opposed to a more powerful language such as, say, C. For example, we could prevent the `test_eval_ret_=$?` line from being traced by default, simply by redirecting fd `4` to `/dev/null`. At that stage, we would of course have to open yet another fd to support the use case where the `-x` is passed to `sh` itself (`sh -x t0000-*.sh -i -v`). In the context of this here patch series, which really is about enabling the GPG-related tests on Windows, I will refrain from going down that particular rabbit hole. My ego might get stuck. Ciao, Dscho
diff --git a/t/t0000-basic.sh b/t/t0000-basic.sh index 3e440c078d5..b8597216200 100755 --- a/t/t0000-basic.sh +++ b/t/t0000-basic.sh @@ -833,6 +833,19 @@ then exit 1 fi +test_expect_success 'lazy prereqs do not turn off tracing' " + run_sub_test_lib_test lazy-prereq-and-tracing \ + 'lazy prereqs and -x' -v -x <<-\\EOF && + test_lazy_prereq LAZY true + + test_expect_success lazy 'test_have_prereq LAZY && echo trace' + + test_done + EOF + + grep 'echo trace' lazy-prereq-and-tracing/err +" + test_expect_success 'tests clean up even on failures' " run_sub_test_lib_test_err \ failing-cleanup 'Failing tests with cleanup commands' <<-\\EOF && diff --git a/t/test-lib.sh b/t/test-lib.sh index 0ea1e5a05ed..dbf25348106 100644 --- a/t/test-lib.sh +++ b/t/test-lib.sh @@ -882,6 +882,7 @@ maybe_setup_valgrind () { fi } +_trace_level=0 want_trace () { test "$trace" = t && { test "$verbose" = t || test "$verbose_log" = t @@ -895,7 +896,7 @@ want_trace () { test_eval_inner_ () { # Do not add anything extra (including LF) after '$*' eval " - want_trace && set -x + want_trace && _trace_level=$(($_trace_level+1)) && set -x $*" } @@ -926,7 +927,8 @@ test_eval_ () { test_eval_ret_=$? if want_trace then - set +x + test 1 = $_trace_level && set +x + _trace_level=$(($_trace_level-1)) fi } 2>/dev/null 4>&2