patcht: avoid sed-based chain-linting in some expensive cases

Commit 878f988350 (t/test-lib: teach --chain-lint to detect broken &&-chains in subshells, 2018-07-11) introduced additional chain-lint tests which add an extra "sed" pipeline to each test we run. This has a measurable impact on runtime. Here are timings with and without a new environment variable (added by this patch) that lets you disable just the additional sed-based chain-lint tests:

  Benchmark #1: GIT_TEST_CHAIN_LINT_HARDER=1 make test
    Time (mean ± σ):     64.202 s ±  1.030 s    [User: 622.469 s, System: 301.402 s]
    Range (min … max):   61.571 s … 65.662 s    10 runs

  Benchmark #2: GIT_TEST_CHAIN_LINT_HARDER=0 make test
    Time (mean ± σ):     57.591 s ±  0.333 s    [User: 529.368 s, System: 270.618 s]
    Range (min … max):   57.143 s … 58.309 s    10 runs

  Summary
    'GIT_TEST_CHAIN_LINT_HARDER=0 make test' ran
      1.11 ± 0.02 times faster than 'GIT_TEST_CHAIN_LINT_HARDER=1 make test'

Of course those extra lint checks are doing something useful, so paying a few extra seconds (at least on Linux) isn't so bad (though note the CPU time; we're bounded in our parallel run here by the slowest test, so it really is ~120s of CPU improvement).

But we can observe that there are some test scripts where they produce a much stronger effect, and provide less value. In t0027 and t3070 we run a very large number of small tests, all driven by a series of functions/loops which are filling in the test bodies. There we get much less bang for our buck in terms of bug-finding versus CPU cost.

This patch introduces a mechanism for controlling when those extra lint checks are run, at two levels:

  - a user can ask to disable or to force-enable the checks by setting
    GIT_TEST_CHAIN_LINT_HARDER

  - if the user hasn't specified a preference, individual scripts can
    disable the checks by setting GIT_TEST_CHAIN_LINT_HARDER_DEFAULT;
    scripts which don't set that get the current behavior of enabling
    them.

In addition, this patch flips the default for t0027 and t3070's mass-generated sections to disable the extra checks. Here are the timing results for t0027:

  Benchmark #1: GIT_TEST_CHAIN_LINT_HARDER=1 ./t0027-auto-crlf.sh
    Time (mean ± σ):     17.078 s ±  0.848 s    [User: 14.878 s, System: 7.075 s]
    Range (min … max):   15.952 s … 18.421 s    10 runs

  Benchmark #2: GIT_TEST_CHAIN_LINT_HARDER=0 ./t0027-auto-crlf.sh
    Time (mean ± σ):      9.063 s ±  0.759 s    [User: 7.890 s, System: 3.362 s]
    Range (min … max):    7.747 s … 10.619 s    10 runs

  Benchmark #3: ./t0027-auto-crlf.sh
    Time (mean ± σ):      9.186 s ±  0.881 s    [User: 7.957 s, System: 3.427 s]
    Range (min … max):    7.796 s … 10.498 s    10 runs

  Summary
    'GIT_TEST_CHAIN_LINT_HARDER=0 ./t0027-auto-crlf.sh' ran
      1.01 ± 0.13 times faster than './t0027-auto-crlf.sh'
      1.88 ± 0.18 times faster than 'GIT_TEST_CHAIN_LINT_HARDER=1 ./t0027-auto-crlf.sh'

We can see that disabling the checks for the whole script buys us an almost 2x speedup. But the new default behavior, disabling them only for the mass-generated part, gets us most of that speedup (but still leaves the checks on for further manual tests people might write).

  As a side note, I'd caution about comparing runtimes and CPU seconds
  between this timing and the earlier "make test" one. In "make test",
  we're running a lot of scripts in parallel, so the CPU is throttling
  down (and thus a CPU second saved here would count for more during a
  parallel run; the same work takes more CPU seconds there).

We get similar results for t3070:

  Benchmark #1: GIT_TEST_CHAIN_LINT_HARDER=1 ./t3070-wildmatch.sh
    Time (mean ± σ):     20.054 s ±  3.967 s    [User: 16.003 s, System: 8.286 s]
    Range (min … max):   11.891 s … 23.671 s    10 runs

  Benchmark #2: GIT_TEST_CHAIN_LINT_HARDER=0 ./t3070-wildmatch.sh
    Time (mean ± σ):     12.399 s ±  2.256 s    [User: 7.542 s, System: 5.342 s]
    Range (min … max):    9.606 s … 15.727 s    10 runs

  Benchmark #3: ./t3070-wildmatch.sh
    Time (mean ± σ):     10.726 s ±  3.476 s    [User: 6.790 s, System: 4.365 s]
    Range (min … max):    5.444 s … 15.376 s    10 runs

  Summary
    './t3070-wildmatch.sh' ran
      1.16 ± 0.43 times faster than 'GIT_TEST_CHAIN_LINT_HARDER=0 ./t3070-wildmatch.sh'
      1.87 ± 0.71 times faster than 'GIT_TEST_CHAIN_LINT_HARDER=1 ./t3070-wildmatch.sh'

Again, we get almost a 2x speedup disabling these. In this case, there are no tests not covered by the script's "default to disable" behavior, so the second two benchmarks should be the same (and while they do differ, you can see the variance is quite high but they're within one standard deviation).

So it seems like for these two scripts, at least, disabling the extra checks is a reasonable tradeoff. Sadly, the overall runtime of "make test" on my system doesn't get much faster. But that's because we're mostly limited by the cost of the single biggest test. Here are the top-5 tests by wall-clock time from a parallel run, before my patch:

  57.9192368984222 t9001-send-email.sh
  45.6329638957977 t0027-auto-crlf.sh
  32.5278220176697 t3070-wildmatch.sh
  22.2701289653778 t7610-mergetool.sh
  20.8635759353638 t1701-racy-split-index.sh

And after:

  57.1476998329163 t9001-send-email.sh
  33.776211977005 t0027-auto-crlf.sh
  21.3116669654846 t7610-mergetool.sh
  20.7748689651489 t1701-racy-split-index.sh
  19.6957249641418 t7112-reset-submodule.sh

We dropped 12s from t0027, and t3070 dropped off our list entirely at around 16s. In both cases we're bound by t9001, but its slowness is due to the actual tests, so we'll have to deal with it in a different way. But this reduces overall CPU, and means that dealing with t9001 (by improving the speed of send-email or splitting it apart) will let us reduce our overall runtime even on multi-core machines.

Signed-off-by: Jeff King <peff@peff.net>
---
This is one of the speedups I mentioned earlier in:

  https://lore.kernel.org/git/YJxmHbHAn4x93xsr@coredump.intra.peff.net/

but it's really independent of Ævar's your work on send-email (of course once he makes t9001 faster, then these two scripts become the most expensive :) ).

I suspect t3070 could be made faster still by consolidating some of its 1890 test cases (e.g., testing multiple related variants in a single invocation of git, reducing the number of processes needed). But it looks non-trivial, and I think this extra chain-lint knob is a good tool to have in our belt anyway.

 t/README             | 5 +++++
 t/t0027-auto-crlf.sh | 7 ++++++-
 t/t3070-wildmatch.sh | 5 +++++
 t/test-lib.sh        | 7 +++++--
 4 files changed, 21 insertions(+), 3 deletions(-)

Jeff King <peff@peff.net> writes:

Nice.

We have been doing the more expensive one first, but we now optionally skip it while retaining the one that uses the shell. OK.

Nicely done.

On Thu, May 13, 2021 at 03:49:52PM +0900, Junio C Hamano wrote:

Oh yeah, I meant to call that out. I flipped them mostly because it made the conditional easier to read (though as you can see, it's already quite a mouthful).

In practice the short-circuit doesn't help us much, though. Unless a test is buggy, we end up having to run both tests either way, no matter the order.

-Peff

On Thu, 13 May 2021 at 08:29, Jeff King <peff@peff.net> wrote:

Devil's advocate: Who do we expect to turn GIT_TEST_CHAIN_LINT_HARDER on, and when? If no one ever does it then we might as well drop the "default" thing and just go "we won't bother linting these particular tests, ever". But as long as "someone" does it "sometimes", it's not like it's a very complex mechanism to carry around.

I seem to have 140 tests that haven't changed on disk since I did this particular clone in 2017. 235 haven't changed this calendar year. Maybe we could skip linting those tests that haven't been modified for several weeks on the basis that they can't reasonably have newly-introduced syntax mistakes. I guess it gets tricky where the t????-*.sh file doesn't change in a long time, but it sources tests from other places, such as a lib-foo.sh helper. We'd have to be a bit more clever there. That's all just thinking out loud, and definitely not something that should hold up your patch.

Martin

On Thu, May 13, 2021 at 01:05:28PM +0200, Martin Ågren wrote:

The answer is probably: people who suspect something is broken. We could perhaps also turn it on for CI to be more complete there (and where 30 seconds of CPU time is relatively much smaller). It was also handy to have while timing the impact, of course.

I'm not opposed to having it be less flexible, and in fact I wrote it that way originally. But it doesn't actually make the code much simpler. The assignments to _DEFAULT in the scripts become GIT_TEST_CHAIN_LINT_HARDER and the read side has one less level of defaulting:

-test "${GIT_TEST_CHAIN_LINT_HARDER:-${GIT_TEST_CHAIN_LINT_HARDER_DEFAULT:-1}}" != 0 && +test "${GIT_TEST_CHAIN_LINT_HARDER:-1}" != 0 &&

I guess it's conceptually a little simpler, though. I dunno. I sort of assumed it would just work and nobody would need to ever look at or configure it either way. :)

Yeah, I suspect that would work in general. But it seems like even more complexity (now you have a cache of "I linted this script at time X and it was good" that has to be written). It does increase the possible savings though (up to perhaps 100 or so seconds of parallel CPU in my case).

I think a bigger and better version of that is to actually see which code paths are run by which scripts, and not even bother running scripts that don't touch code which has changed. But that's a _lot_ more complicated, and writing such a tool is probably at least worth a thesis project. ;)

-Peff

On Fri, 14 May 2021 at 07:48, Jeff King <peff@peff.net> wrote:

And to be clear, I'm not opposed to having it more flexible. :)

:)

Yeah, I thought about the cache. I guess it would be a list of known-good test script hashes / blob IDs. But what I actually meant was to check whether the mtime was way back in the past. It's not fool-proof though. You could have a network-mounted disk where the date is way off, or you could hack up the test script, wait for several weeks and *then* run it. ;)

Ah yes, it should be safe to punt on that for now.

Martin

On Fri, May 14, 2021 at 10:52:35AM +0200, Martin Ågren wrote:

Ah, I see. You'd set some date for "this is so old you've probably run the linting on it by now". Yeah, that is less complex to implement. It does feel awfully magical, though.

-Peff