Re: [PATCH 2/3] t: teach 'test_must_fail' to save the command's stderr to a file

On Fri, Feb 9, 2018 at 3:21 PM, Jeff King <peff@peff.net> wrote:

Well, now I'm not just slightly negative, see the patch series I will send out in a minute :)

Yeah, they do, but most of the time they shouldn't.

I've looked at uses of 'test_must_fail cmd... 2>&1', and also uses of other test helper functions with stderr duplicated from stdout (and a couple of cases of "plain" 'git cmd ... 2>&1' as well; that's where the t6300-for-each-ref fix came from some days ago).

I think all but one of those cases would benefit from handling stdout and stderr separately, and that one exception shouldn't use 'test_must_fail' for a platform command in the first place[1].

  - Many of these tests check error messages after they mingled stderr
    and stdout like this:

      test_must_fail git cmd >out 2>&1 &&
      (test_i18n)grep "relevant part of the error msg" out

    In these cases there is no need for 2>&1 as they don't care about
    stdout at all.  They could just grep the failed command's stderr,
    with the added benefit that they would ensure that the error message
    indeed goes to stderr.

  - A couple of these tests check the output more strictly:

      test_must_fail git cmd >actual 2>&1 &&
      echo "error message" >expect &&
      test_(i18n)cmp expect actual

    which also checks that nothing was printed on stdout, but does so
    implicitly.  Considering all the sloppy uses of 2>&1, it's hard to
    tell whether it was deliberate to check the empty stdout, or
    accidental, because the writer of the test used 'test_cmp' instead
    of 'grep' for its verbosity on failure, or simply mixed up the two.
    Therefore, I think it's better when it's written more explicitly:

      test_must_fail git cmd >out 2>err &&
      echo "exact error message" >expect &&
      test_cmp expect err &&
      test_must_be_empty out

    ... both when reading such a test and when looking at it's output on
    failure.

  - Then there are some cases that, for some reason, completely silence
    a git command with:

      test_must_fail git cmd >/dev/null 2>&1

    The output of a command could turn out to be useful when debugging a
    failing tests, so tests shouldn't do this, unless there is a very
    good reason (e.g. the command produces a lot of output).

  - Finally, a few tests check that something is surely missing from a
    git command's output, both from stdout and stderr:

      test_must_fail git cmd >out 2>&1 &&
      ! grep "should not be there" out

    Or that a command is completely silent:

      test_must_fail git cmd --quiet >out 2>&1 &&
      test_must_be_empty out

    Checking the emptiness of stdout and stderr separately would give
    more info on failure, as it would tell us right away where the
    unexpected output is coming from (though arguably the presence of
    words like "error" or "fatal" in the output of 'test_must_be_empty'
    would be a dead giveaway).
    BTW, we already have a couple of careful tests that do:

      git cmd >out 2>err &&
      test_must_be_empty out &&
      test_must_be_empty err

    (Which makes me think that extending 'test_must_be_empty' to check
    the emptiness of multiple files at once would be worth it: fewer
    lines, fewer characters to type, and it could report all non-empty
    files, not just the first.)

Relying on the combination of the unbuffered stderr and the block-buffered stdout could be fragile to begin with, though in general it doesn't really cause troubles if the data on stdout is less than the buffer size or if there's no output on stderr after the stdout buffer is flushed. The stdout buffer size is pagesize on Linux (I don't know offhand about others), which is large enough compared to the typical amount of output git commands produce in our test scripts, so we could get away with it.

Sure. I tried to address 'test_must_fail' first, because, with about 90% of the cases, it is by far the worst offender among all test helper functions with redirected stderr. 'test_expect_code' comes in second far behind, and there are a mere handful of the combination of 'test_terminal' and 'perl'.

The 'test_expect_code 129 ... 2>&1' in t0012-help.sh's row of '$builtin can handle -h' tests is particularly interesting, because it hides the inconsistency that 76 commands send their help/usage text to stdout, while 45 to stderr.

Well, not that bad a workaround, but in my opinion the real solution is to make '-x' tracing work reliably with /bin/sh.

Since we strive for POSIX shell compatibility in our test scripts, I dutifully run the test suite with /bin/sh. Switching shells for '-x' to get more info about what went wrong (and then switching back) is a hassle even when it happens to work, and rather annoying when it doesn't. I've lost count of the various ways of running tests with '-x' and Bash that I naively thought would Just Work, but didn't because of the subtleties of GIT-BUILD-OPTIONS and/or re-exec in case of '--verbose-log'. I find I still reached for various ad-hoc debugging/tracing or 'test_pause' first, and kept '-x' only as last resort.

If we start running tests with '-x' and Bash on Travis CI, then it won't be able to (semi-)automatically catch non-POSIX constructs entering the test scripts. And I do want to run all tests with '-x', to get the most information about rarely occurring transient errors.

[1] - 't/lib-git-p4.sh' contains the following command:

        test_must_fail kill $pid >/dev/null 2>&1