{"thread":{"id":"40564","subject":"[BUG] t7063-status-untracked-cache flaky?","startedAt":"2015-10-15T07:52:18Z","lastAt":"2015-10-16T21:25:40Z","messageCount":6,"participants":["Lars Schneider","David Turner","Torsten Bögershausen","Junio C Hamano"],"isPatch":false,"patchVersion":null,"patchTotal":null},"messages":[{"id":"271714","messageId":"326E1A8B-3612-4771-80B8-77346C0D762D@gmail.com","threadId":"40564","inReplyTo":null,"subject":"[BUG] t7063-status-untracked-cache flaky?","fromName":"Lars Schneider","fromEmail":"larsxschneider@gmail.com","sentAt":"2015-10-15T07:52:18Z","receivedAt":"2015-10-15T07:52:18Z","isPatch":false,"sender":{"key":"larsxschneider@gmail.com","avatar":"https://avatars.githubusercontent.com/u/477434?v=4"},"body":"Hi,\n\nI noticed that \"t7063-status-untracked-cache.sh\" occasionally fails with \"not ok 24 - test sparse status with untracked cache\".\n\nE.g. on OS X compiled with gcc:\nhttps://travis-ci.org/larsxschneider/git/jobs/85432514\n\nE.g. on Linux compiled with gcc:\nhttps://travis-ci.org/larsxschneider/git/jobs/84986975\n\nThe 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?\n\nThanks,\nLars"},{"id":"271746","messageId":"1444938244.20887.6.camel@twopensource.com","threadId":"40564","inReplyTo":"326E1A8B-3612-4771-80B8-77346C0D762D@gmail.com","subject":"Re: [BUG] t7063-status-untracked-cache flaky?","fromName":"David Turner","fromEmail":"dturner@twopensource.com","sentAt":"2015-10-15T19:44:04Z","receivedAt":"2015-10-15T19:44:04Z","isPatch":false,"sender":{"key":"novalis@novalis.org","avatar":"https://avatars.githubusercontent.com/u/77003?v=4"},"body":"On Thu, 2015-10-15 at 09:52 +0200, Lars Schneider wrote:\n> Hi,\n> \n> I noticed that \"t7063-status-untracked-cache.sh\" occasionally fails with \"not ok 24 - test sparse status with untracked cache\".\n> \n> E.g. on OS X compiled with gcc:\n> https://travis-ci.org/larsxschneider/git/jobs/85432514\n> \n> E.g. on Linux compiled with gcc:\n> https://travis-ci.org/larsxschneider/git/jobs/84986975\n> \n> 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?\n\nI've never seen this test be flaky before your report.  I just tested\nit, locally, though, and I can reproduce.  After 53 successes, it\nfailed.  Will investigate further.\n"},{"id":"271814","messageId":"56211619.3090907@web.de","threadId":"40564","inReplyTo":"326E1A8B-3612-4771-80B8-77346C0D762D@gmail.com","subject":"Re: [BUG] t7063-status-untracked-cache flaky?","fromName":"Torsten Bögershausen","fromEmail":"tboegi@web.de","sentAt":"2015-10-16T15:22:01Z","receivedAt":"2015-10-16T15:22:01Z","isPatch":false,"sender":{"key":"tboegi@web.de","avatar":"https://avatars.githubusercontent.com/u/7138363?v=4"},"body":"I can't reproduce it here.\nDo you want to give us some info about your setup ?\nOS ?\nHarddisk, SSD, Fusion ?\nDoes \"debug=t verbose=t ./t7063-status-untracked-cache.sh >xx.txt 2>&1\" \ngive any more information ?\n\n\nOn 15.10.15 09:52, Lars Schneider wrote:\n> Hi,\n> \n> I noticed that \"t7063-status-untracked-cache.sh\" occasionally fails with \"not ok 24 - test sparse status with untracked cache\".\n"},{"id":"271831","messageId":"1445026298.20887.28.camel@twopensource.com","threadId":"40564","inReplyTo":"56211619.3090907@web.de","subject":"Re: [BUG] t7063-status-untracked-cache flaky?","fromName":"David Turner","fromEmail":"dturner@twopensource.com","sentAt":"2015-10-16T20:11:38Z","receivedAt":"2015-10-16T20:11:38Z","isPatch":false,"sender":{"key":"novalis@novalis.org","avatar":"https://avatars.githubusercontent.com/u/77003?v=4"},"body":"On Fri, 2015-10-16 at 17:22 +0200, Torsten Bögershausen wrote:\n> On 15.10.15 09:52, Lars Schneider wrote:\n> > Hi,\n> > \n> > I noticed that \"t7063-status-untracked-cache.sh\" occasionally fails with \"not ok 24 - test sparse status with untracked cache\".\n>\n> I can't reproduce it here.\n> Do you want to give us some info about your setup ?\n> OS ?\n> Harddisk, SSD, Fusion ?\n> Does \"debug=t verbose=t ./t7063-status-untracked-cache.sh >xx.txt\n2>&1\" \n> give any more information ?\n\n(rearranged to bottom-post)\n\nThe problem is:\n\ntrash directory.t7063-status-untracked-cache$ diff trace trace.expect \n3,4c3,4\n< directory invalidation: 1\n< opendir: 1\n---\n> directory invalidation: 2\n> opendir: 2\n\n\nI can repro on a SSD.\n\nI had to try many times to reproduce (I think even more the second\ntime). I just ran the test in a while loop until it failed.\n\nI suspect that the kernel might be a bit slow to update the mtime on the\ndirectory, but I have not yet been able to repro, and I don't understand\nwhy it only happens in this one test, since sparseness should be\ncompletely unrelated.\n"},{"id":"271832","messageId":"xmqqfv1aeena.fsf@gitster.mtv.corp.google.com","threadId":"40564","inReplyTo":"1445026298.20887.28.camel@twopensource.com","subject":"Re: [BUG] t7063-status-untracked-cache flaky?","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2015-10-16T20:34:33Z","receivedAt":"2015-10-16T20:34:33Z","isPatch":false,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"David Turner <dturner@twopensource.com> writes:\n\n> The problem is:\n>\n> trash directory.t7063-status-untracked-cache$ diff trace trace.expect \n> 3,4c3,4\n> < directory invalidation: 1\n> < opendir: 1\n> ---\n>> directory invalidation: 2\n>> opendir: 2\n>\n>\n> I can repro on a SSD.\n>\n> I had to try many times to reproduce (I think even more the second\n> time). I just ran the test in a while loop until it failed.\n>\n> I suspect that the kernel might be a bit slow to update the mtime on the\n> directory, but I have not yet been able to repro, and I don't understand\n> why it only happens in this one test, since sparseness should be\n> completely unrelated.\n\nIf you are invalidating your cache based on mtime of the directory,\nan operation within mtime granularity can cause you to miss it,\nunless you try to be conservative and do the \"assume invalid if\nracy\".  And if you do \"assume invalid if racy\", the result will\nbecome timing dependent.  You may end up invalidating more than\nabsolutely necessary, i.e. the test writer may have known that at\nleast 1 must be definitely stale at that point in the test, but\nif another directory was iffy and the code played safe, you would\nsee one more invalidation than expected (which would lead to\nscanning the directory, hence one more opendir).\n\nIs that what is going on here?\n"},{"id":"271839","messageId":"1445030740.20887.33.camel@twopensource.com","threadId":"40564","inReplyTo":"xmqqfv1aeena.fsf@gitster.mtv.corp.google.com","subject":"Re: [BUG] t7063-status-untracked-cache flaky?","fromName":"David Turner","fromEmail":"dturner@twopensource.com","sentAt":"2015-10-16T21:25:40Z","receivedAt":"2015-10-16T21:25:40Z","isPatch":false,"sender":{"key":"novalis@novalis.org","avatar":"https://avatars.githubusercontent.com/u/77003?v=4"},"body":"On Fri, 2015-10-16 at 13:34 -0700, Junio C Hamano wrote:\n> David Turner <dturner@twopensource.com> writes:\n> \n> > The problem is:\n> >\n> > trash directory.t7063-status-untracked-cache$ diff trace trace.expect \n> > 3,4c3,4\n> > < directory invalidation: 1\n> > < opendir: 1\n> > ---\n> >> directory invalidation: 2\n> >> opendir: 2\n> >\n> >\n> > I can repro on a SSD.\n> >\n> > I had to try many times to reproduce (I think even more the second\n> > time). I just ran the test in a while loop until it failed.\n> >\n> > I suspect that the kernel might be a bit slow to update the mtime on the\n> > directory, but I have not yet been able to repro, and I don't understand\n> > why it only happens in this one test, since sparseness should be\n> > completely unrelated.\n> \n> If you are invalidating your cache based on mtime of the directory,\n> an operation within mtime granularity can cause you to miss it,\n> unless you try to be conservative and do the \"assume invalid if\n> racy\".  And if you do \"assume invalid if racy\", the result will\n> become timing dependent.  You may end up invalidating more than\n> absolutely necessary, i.e. the test writer may have known that at\n> least 1 must be definitely stale at that point in the test, but\n> if another directory was iffy and the code played safe, you would\n> see one more invalidation than expected (which would lead to\n> scanning the directory, hence one more opendir).\n> \n> Is that what is going on here?\n\nThe test has a sleep to avoid this.  Looking at it, I think it just\nneeds one more sleep.  Testing now; if correct, I'll send a patch.\n"}]}