git@vger.kernel.org mailing list mirror (one of many)
 help / color / mirror / code / Atom feed
From: Elijah Newren <newren@gmail.com>
To: "SZEDER Gábor" <szeder.dev@gmail.com>
Cc: Junio C Hamano <gitster@pobox.com>,
	Eric Rannaud <e@nanocritical.com>,
	Git Mailing List <git@vger.kernel.org>
Subject: Re: [PATCH] t9300: wait for background fast-import process to die after killing it
Date: Fri, 20 Jul 2018 12:03:44 -0700	[thread overview]
Message-ID: <CABPp-BGko5_N7uX=AgTqjTyF2rSusR81FnSQpSNhXxi64uvY3A@mail.gmail.com> (raw)
In-Reply-To: <20180719222641.12152-1-szeder.dev@gmail.com>

On Thu, Jul 19, 2018 at 3:26 PM, SZEDER Gábor <szeder.dev@gmail.com> wrote:
> The five new tests added to 't9300-fast-import.sh' in 30e215a65c
> (fast-import: checkpoint: dump branches/tags/marks even if
> object_count==0, 2017-09-28), all with the prefix "V:" in their test
> description, run 'git fast-import' in the background and then 'kill'
> it as part of a 'test_when_finished' cleanup command.  When this test
> script is executed with Bash, some or even all of these tests tend to
> pollute the test script's stderr, and messages about terminated
> processes end up on the terminal:
>
>   $ bash ./t9300-fast-import.sh
>   <... snip ...>
>   ok 179 - V: checkpoint helper does not get stuck with extra output
>   /<...>/test-lib-functions.sh: line 388: 28383 Terminated              git fast-import $options 0<&8 1>&9
>   ok 180 - V: checkpoint updates refs after reset
>   ./t9300-fast-import.sh: line 3210: 28401 Terminated              git fast-import $options 0<&8 1>&9
>   ok 181 - V: checkpoint updates refs and marks after commit
>   ok 182 - V: checkpoint updates refs and marks after commit (no new objects)
>   ./test-lib.sh: line 634: line 3250: 28485 Terminated              git fast-import $options 0<&8 1>&9
>   ok 183 - V: checkpoint updates tags after tag
>   ./t9300-fast-import.sh: line 3264: 28510 Terminated              git fast-import $options 0<&8 1>&9
>
> After a background child process terminates, its parent Bash process
> always outputs a message like those above to stderr, even when in
> non-interactive mode.
>
> But how do some of these messages end up on the test script's stderr,
> why don't we get them from all five tests, and why do they come from
> different file/line locations?  Well, after sending the TERM signal to
> the background child process, it takes a little while until that
> process receives the signal and terminates, and then it takes another
> while until the parent process notices it.  During this time the
> parent Bash process is continuing execution, and by the time it
> notices that its child terminated it might have already left
> 'test_eval_inner_' and its stderr is not redirected to /dev/null
> anymore.  That's why such a message can appear on the test script's
> stderr, while other times, when the child terminates fast and/or the
> parent shell is slow enough, the message ends up in /dev/null, just
> like any other output of the test does.  Bash always adds the file
> name and line number of the code location it was about to execute when
> it notices the termination of its child process as a prefix to that
> message, hence the varying and sometimes totally unrelated location
> prefixes in those messages (e.g. line 388 in 'test-lib-functions.sh'
> is 'test_verify_prereq', and I saw such a message pointing to
> 'say_color' as well).
>
> Prevent these messages from appearing on the test script's stderr by
> 'wait'-ing on the pid of the background 'git fast-import' process
> after sending it the TERM signal.  This ensures that the executing
> shell's stderr is still redirected when the shell notices the
> termination of its child process in the background, and that these
> messages get a consistent file/line location prefix.
>
> Note that this is not an issue when the test script is run with Bash
> and '-v', because then these messages are supposed to go to the test
> script's stderr anyway, and indeed all of them do; though the
> sometimes seemingly random file/line prefixes could be confusing
> still.  Similarly, it's not an issue with Bash and '--verbose-log'
> either, because then all messages go to the log file as they should.
> Finally, it's not an issue with some other shells (I tried dash, ksh,
> ksh93 and mksh) even without any of the verbose options, because they
> don't print messages like these in non-interactive mode in the first
> place.
>
> Signed-off-by: SZEDER Gábor <szeder.dev@gmail.com>
> ---
>  t/t9300-fast-import.sh | 5 ++++-
>  1 file changed, 4 insertions(+), 1 deletion(-)
>
> diff --git a/t/t9300-fast-import.sh b/t/t9300-fast-import.sh
> index 9e7f96223d..fac33e524c 100755
> --- a/t/t9300-fast-import.sh
> +++ b/t/t9300-fast-import.sh
> @@ -3147,7 +3147,10 @@ background_import_then_checkpoint () {
>         echo $! >V.pid
>         # We don't mind if fast-import has already died by the time the test
>         # ends.
> -       test_when_finished "exec 8>&-; exec 9>&-; kill $(cat V.pid) || true"
> +       test_when_finished "
> +               exec 8>&-; exec 9>&-;
> +               kill $(cat V.pid) && wait $(cat V.pid)
> +               true"
>
>         # Start in the background to ensure we adhere strictly to (blocking)
>         # pipes writing sequence. We want to assume that the write below could
> --
> 2.18.0.408.g42635c01bc

Sweet, thanks for fixing this.  I got these messages nearly 100% of
the time on a certain machine when running prove with a high enough
parallel flag.  I was getting a little annoyed by them, but hadn't dug
in yet.  Your patch squelches them up in my testing.

      parent reply	other threads:[~2018-07-20 19:03 UTC|newest]

Thread overview: 3+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2018-07-19 22:26 [PATCH] t9300: wait for background fast-import process to die after killing it SZEDER Gábor
2018-07-20  5:20 ` Eric Rannaud
2018-07-20 19:03 ` Elijah Newren [this message]

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

  List information: http://vger.kernel.org/majordomo-info.html

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to='CABPp-BGko5_N7uX=AgTqjTyF2rSusR81FnSQpSNhXxi64uvY3A@mail.gmail.com' \
    --to=newren@gmail.com \
    --cc=e@nanocritical.com \
    --cc=git@vger.kernel.org \
    --cc=gitster@pobox.com \
    --cc=szeder.dev@gmail.com \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
Code repositories for project(s) associated with this public inbox

	https://80x24.org/mirrors/git.git

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).