threads / bug / 40564

[BUG] t7063-status-untracked-cache flaky?

Subject: [BUG] t7063-status-untracked-cache flaky?

## tl;dr

6 messages between Oct 15, 2015 and Oct 16, 2015.

replies: 5people: 4as markdown or json

Lars Schneider· Oct 15, 2015, 07:52 UTC · lore
Hi,
I noticed that "t7063-status-untracked-cache.sh" occasionally fails with "not ok 24 - test sparse status with untracked cache".

E.g. on OS X compiled with gcc: https://travis-ci.org/larsxschneider/git/jobs/85432514

E.g. on Linux compiled with gcc: https://travis-ci.org/larsxschneider/git/jobs/84986975

The test was added with commit 7687252. I have not really investigated the problem yet but the "avoid_racy" method caught my attention. Is this test known to be flaky? Would an increased sleep time in "avoid_racy" help?

Thanks, Lars

David Turner· Oct 15, 2015, 19:44 UTC · re: Lars Schneider · lore

Re: [BUG] t7063-status-untracked-cache flaky?

On Thu, 2015-10-15 at 09:52 +0200, Lars Schneider wrote:
Show 11 quoted lines
> Hi,
> 
> I noticed that "t7063-status-untracked-cache.sh" occasionally fails with "not ok 24 - test sparse status with untracked cache".
> 
> E.g. on OS X compiled with gcc:
> https://travis-ci.org/larsxschneider/git/jobs/85432514
> 
> E.g. on Linux compiled with gcc:
> https://travis-ci.org/larsxschneider/git/jobs/84986975
> 
> The test was added with commit 7687252. I have not really investigated the problem yet but the "avoid_racy" method caught my attention. Is this test known to be flaky? Would an increased sleep time in "avoid_racy" help?

I've never seen this test be flaky before your report. I just tested it, locally, though, and I can reproduce. After 53 successes, it failed. Will investigate further.

Torsten Bögershausen· Oct 16, 2015, 15:22 UTC · re: Lars Schneider · lore

Re: [BUG] t7063-status-untracked-cache flaky?

I can't reproduce it here. Do you want to give us some info about your setup ? OS ? Harddisk, SSD, Fusion ? Does "debug=t verbose=t ./t7063-status-untracked-cache.sh >xx.txt 2>&1" give any more information ?

On 15.10.15 09:52, Lars Schneider wrote:
> Hi,
> 
> I noticed that "t7063-status-untracked-cache.sh" occasionally fails with "not ok 24 - test sparse status with untracked cache".
David Turner· Oct 16, 2015, 20:11 UTC · re: Torsten Bögershausen · lore

Re: [BUG] t7063-status-untracked-cache flaky?

On Fri, 2015-10-16 at 17:22 +0200, Torsten Bögershausen wrote:
Show 10 quoted lines
> On 15.10.15 09:52, Lars Schneider wrote:
> > Hi,
> > 
> > I noticed that "t7063-status-untracked-cache.sh" occasionally fails with "not ok 24 - test sparse status with untracked cache".
>
> I can't reproduce it here.
> Do you want to give us some info about your setup ?
> OS ?
> Harddisk, SSD, Fusion ?
> Does "debug=t verbose=t ./t7063-status-untracked-cache.sh >xx.txt
2>&1" 
> give any more information ?
(rearranged to bottom-post)
The problem is:

trash directory.t7063-status-untracked-cache$ diff trace trace.expect 3,4c3,4 < directory invalidation: 1 < opendir: 1 ---

> directory invalidation: 2
> opendir: 2
I can repro on a SSD.

I had to try many times to reproduce (I think even more the second time). I just ran the test in a while loop until it failed.

I suspect that the kernel might be a bit slow to update the mtime on the directory, but I have not yet been able to repro, and I don't understand why it only happens in this one test, since sparseness should be completely unrelated.

Junio C Hamano· Oct 16, 2015, 20:34 UTC · re: David Turner · lore

Re: [BUG] t7063-status-untracked-cache flaky?

David Turner <dturner@twopensource.com> writes:
Show 20 quoted lines
> The problem is:
>
> trash directory.t7063-status-untracked-cache$ diff trace trace.expect 
> 3,4c3,4
> < directory invalidation: 1
> < opendir: 1
> ---
>> directory invalidation: 2
>> opendir: 2
>
>
> I can repro on a SSD.
>
> I had to try many times to reproduce (I think even more the second
> time). I just ran the test in a while loop until it failed.
>
> I suspect that the kernel might be a bit slow to update the mtime on the
> directory, but I have not yet been able to repro, and I don't understand
> why it only happens in this one test, since sparseness should be
> completely unrelated.

If you are invalidating your cache based on mtime of the directory, an operation within mtime granularity can cause you to miss it, unless you try to be conservative and do the "assume invalid if racy". And if you do "assume invalid if racy", the result will become timing dependent. You may end up invalidating more than absolutely necessary, i.e. the test writer may have known that at least 1 must be definitely stale at that point in the test, but if another directory was iffy and the code played safe, you would see one more invalidation than expected (which would lead to scanning the directory, hence one more opendir).

Is that what is going on here?
David Turner· Oct 16, 2015, 21:25 UTC · re: Junio C Hamano · lore

Re: [BUG] t7063-status-untracked-cache flaky?

On Fri, 2015-10-16 at 13:34 -0700, Junio C Hamano wrote:
Show 35 quoted lines
> David Turner <dturner@twopensource.com> writes:
> 
> > The problem is:
> >
> > trash directory.t7063-status-untracked-cache$ diff trace trace.expect 
> > 3,4c3,4
> > < directory invalidation: 1
> > < opendir: 1
> > ---
> >> directory invalidation: 2
> >> opendir: 2
> >
> >
> > I can repro on a SSD.
> >
> > I had to try many times to reproduce (I think even more the second
> > time). I just ran the test in a while loop until it failed.
> >
> > I suspect that the kernel might be a bit slow to update the mtime on the
> > directory, but I have not yet been able to repro, and I don't understand
> > why it only happens in this one test, since sparseness should be
> > completely unrelated.
> 
> If you are invalidating your cache based on mtime of the directory,
> an operation within mtime granularity can cause you to miss it,
> unless you try to be conservative and do the "assume invalid if
> racy".  And if you do "assume invalid if racy", the result will
> become timing dependent.  You may end up invalidating more than
> absolutely necessary, i.e. the test writer may have known that at
> least 1 must be definitely stale at that point in the test, but
> if another directory was iffy and the code played safe, you would
> see one more invalidation than expected (which would lead to
> scanning the directory, hence one more opendir).
> 
> Is that what is going on here?

The test has a sleep to avoid this. Looking at it, I think it just needs one more sleep. Testing now; if correct, I'll send a patch.

← back to recent threads