Re: [PATCHv2.1] t6500: wait for detached auto gc at the end of the test script

2017-04-13 Thread Jeff King
On Thu, Apr 13, 2017 at 08:08:12PM +0200, SZEDER Gábor wrote:

> On Thu, Apr 13, 2017 at 6:44 PM, Jeff King  wrote:
> > On Thu, Apr 13, 2017 at 12:31:38PM +0200, SZEDER Gábor wrote:
> 
> > I did wonder what will happen if Windows learns to daemonize() the
> > auto-gc. I don't think we'll get an immediate test failure, but this
> > test will become racy again. But this time we'll actually notice the
> > racy failure, because the "ls" will report extra packs if it runs before
> > the background gc does. At which point we can revisit this.
> 
> Dscho said that it would take significant effort to make daemonize()
> work on Windows, so I guess it will take a while before we'll have to
> revisit this.

Yeah, that's what I figured. I mostly just didn't want to leave a
time-bomb for future developers.

> > I guess we could probably grep for the "in the background" message from
> > the parent gc. OTOH, maybe it is not even worth it.
> 
> That wouldn't work at the moment, because auto gc says that it will go
> to the background even on Windows.

Ah, OK. Let's not worry about it, then. I think the way your test is
constructed we should get a racy failure not long after the change, and
your comments would lead people to realize what is going on.

-Peff


Re: [PATCHv2.1] t6500: wait for detached auto gc at the end of the test script

2017-04-13 Thread SZEDER Gábor
On Thu, Apr 13, 2017 at 6:44 PM, Jeff King  wrote:
> On Thu, Apr 13, 2017 at 12:31:38PM +0200, SZEDER Gábor wrote:

> I did wonder what will happen if Windows learns to daemonize() the
> auto-gc. I don't think we'll get an immediate test failure, but this
> test will become racy again. But this time we'll actually notice the
> racy failure, because the "ls" will report extra packs if it runs before
> the background gc does. At which point we can revisit this.

Dscho said that it would take significant effort to make daemonize()
work on Windows, so I guess it will take a while before we'll have to
revisit this.

> It would be nice if there were a non-racy way to detect whether we
> daemonized or not, and complain on Windows when we do. Then we'll be
> notified immediately when daemonize() changes by the test failure,
> rather than waiting for a racy failure.
>
> I guess we could probably grep for the "in the background" message from
> the parent gc. OTOH, maybe it is not even worth it.

That wouldn't work at the moment, because auto gc says that it will go
to the background even on Windows.

As it is, auto gc first prints the "Auto packing the repo..." message,
and calls daemonize() after that.  Which message it prints, i.e. "in
background" or not, depends solely on the value of the 'gc.autoDetach'
config variable, which is true by default.  The only platform-specific
thing about all this is the #ifdef in daemonize(), but then it's
already too late, the misleading message has already been printed.

See the discussion the patch for the same issue in a different test
script (bb05510e5 (t5510: run auto-gc in the foreground, 2016-05-01)),
including a patch at the end that prevents auto gc on Windows from
lying about going to the background (which I, not being a Windows
user, didn't follow through).

  
http://public-inbox.org/git/20160505171430.horde.-guvdpzbfs8vi1zcfn4b...@webmail.informatik.kit.edu/T/#u

> The racy version
> should fail reasonably promptly, I think, and the comments you've left
> would point any investigator in the right direction.


Re: [PATCHv2.1] t6500: wait for detached auto gc at the end of the test script

2017-04-13 Thread Jeff King
On Thu, Apr 13, 2017 at 12:31:38PM +0200, SZEDER Gábor wrote:

> Note, that this fd trickery doesn't work on Windows, because due to
> MSYS limitations the git process only inherits the standard fds 0, 1
> and 2 from the shell.  Luckily, it doesn't matter in this case,
> because on Windows daemonize() is basically a noop, thus 'git gc
> --auto' always runs in the foreground.
> 
> And since we can now continue the test reliably after the detached gc
> finished, check that there is only a single packfile left at the end,
> i.e. that the detached gc actually did what it was supposed to do.
> Also add a comment at the end of the test script to warn developers of
> future tests about this issue of long running detached gc processes.

The whole thing looks nicely explained, and I'm happy that we're able to
reliably add this extra check at the end of the test.

I did wonder what will happen if Windows learns to daemonize() the
auto-gc. I don't think we'll get an immediate test failure, but this
test will become racy again. But this time we'll actually notice the
racy failure, because the "ls" will report extra packs if it runs before
the background gc does. At which point we can revisit this.

It would be nice if there were a non-racy way to detect whether we
daemonized or not, and complain on Windows when we do. Then we'll be
notified immediately when daemonize() changes by the test failure,
rather than waiting for a racy failure.

I guess we could probably grep for the "in the background" message from
the parent gc. OTOH, maybe it is not even worth it. The racy version
should fail reasonably promptly, I think, and the comments you've left
would point any investigator in the right direction.

-Peff


RE: [PATCHv2.1] t6500: wait for detached auto gc at the end of the test script

2017-04-13 Thread David Turner
Thanks for fixing this!

> -Original Message-
> From: SZEDER Gábor [mailto:szeder@gmail.com]
> Sent: Thursday, April 13, 2017 6:32 AM
> To: Junio C Hamano 
> Cc: Jeff King ; Johannes Sixt ; David Turner
> ; git@vger.kernel.org; SZEDER Gábor
> 
> Subject: [PATCHv2.1] t6500: wait for detached auto gc at the end of the test
> script
> 
> The last test in 't6500-gc', 'background auto gc does not run if gc.log is 
> present
> and recent but does if it is old', added in
> a831c06a2 (gc: ignore old gc.log files, 2017-02-10), may sporadically trigger 
> an
> error message from the test harness:
> 
>   rm: cannot remove 'trash directory.t6500-gc/.git/objects': Directory not 
> empty
> 
> The test in question ends with executing an auto gc in the backround, which
> occasionally takes so long that it's still running when 'test_done' is about 
> to
> remove the trash directory.  This 'rm -rf $trash' in the foreground might race
> with the detached auto gc to create and delete files and directories, and gc
> might (re-)create a path that 'rm' already visited and removed, triggering the
> above error message when 'rm' attempts to remove its parent directory.
> 
> Commit bb05510e5 (t5510: run auto-gc in the foreground, 2016-05-01) fixed the
> same problem in a different test script by simply disallowing background gc.
> Unfortunately, what worked there is not applicable here, because the purpose
> of this test is to check the behavior of a detached auto gc.
> 
> Make sure that the test doesn't continue before the gc is finished in the
> background with a clever bit of shell trickery:
> 
>   - Open fd 9 in the shell, to be inherited by the background gc
> process, because our daemonize() only closes the standard fds 0,
> 1 and 2.
>   - Duplicate this fd 9 to stdout.
>   - Read 'git gc's stdout, and thus fd 9, through a command
> substitution.  We don't actually care about gc's output, but this
> construct has two useful properties:
>   - This read blocks until stdout or fd 9 are open.  While stdout is
> closed after the main gc process creates the background process
> and exits, fd 9 remains open until the backround process exits.
>   - The variable assignment from the command substitution gets its
> exit status from the command executed within the command
> substitution, i.e. a failing main gc process will cause the test
> to fail.
> 
> Note, that this fd trickery doesn't work on Windows, because due to MSYS
> limitations the git process only inherits the standard fds 0, 1 and 2 from 
> the shell.
> Luckily, it doesn't matter in this case, because on Windows daemonize() is
> basically a noop, thus 'git gc --auto' always runs in the foreground.
> 
> And since we can now continue the test reliably after the detached gc 
> finished,
> check that there is only a single packfile left at the end, i.e. that the 
> detached gc
> actually did what it was supposed to do.
> Also add a comment at the end of the test script to warn developers of future
> tests about this issue of long running detached gc processes.
> 
> Helped-by: Jeff King 
> Helped-by: Johannes Sixt 
> Signed-off-by: SZEDER Gábor 
> ---
> 
> Updated subject line, but otherwise the same as v2.
> 
>  t/t6500-gc.sh | 18 +-
>  1 file changed, 17 insertions(+), 1 deletion(-)
> 
> diff --git a/t/t6500-gc.sh b/t/t6500-gc.sh index 08de2e8ab..cc7acd101 100755
> --- a/t/t6500-gc.sh
> +++ b/t/t6500-gc.sh
> @@ -67,6 +67,16 @@ test_expect_success 'auto gc with too many loose
> objects does not attempt to cre
>   test_line_count = 2 new # There is one new pack and its .idx  '
> 
> +run_and_wait_for_auto_gc () {
> + # We read stdout from gc for the side effect of waiting until the
> + # background gc process exits, closing its fd 9.  Furthermore, the
> + # variable assignment from a command substitution preserves the
> + # exit status of the main gc process.
> + # Note: this fd trickery doesn't work on Windows, but there is no
> + # need to, because on Win the auto gc always runs in the foreground.
> + doesnt_matter=$(git gc --auto 9>&1)
> +}
> +
>  test_expect_success 'background auto gc does not run if gc.log is present and
> recent but does if it is old' '
>   test_commit foo &&
>   test_commit bar &&
> @@ -80,7 +90,13 @@ test_expect_success 'background auto gc does not run if
> gc.log is present and re
>   test-chmtime =-345600 .git/gc.log &&
>   test_must_fail git gc --auto &&
>   test_config gc.logexpiry 2.days &&
> - git gc --auto
> + run_and_wait_for_auto_gc &&
> + ls .git/objects/pack/pack-*.pack >packs &&
> + test_line_count = 1 packs
>  '
> 
> +# DO NOT leave a detached auto gc process running near the end of the #
> +test script: it can run long enough in the background to racily #
> +interfere with the cleanup in 'test_done'.
> +
>  test_done
> --
> 2.12.2.613.g9c5b79913