git@vger.kernel.org list mirror (unofficial, one of many)
 help / color / mirror / code / Atom feed
* fsmonitor: t7527 racy on OSX?
@ 2022-11-21 13:07 Ævar Arnfjörð Bjarmason
  2022-11-21 13:38 ` Đoàn Trần Công Danh
  0 siblings, 1 reply; 5+ messages in thread
From: Ævar Arnfjörð Bjarmason @ 2022-11-21 13:07 UTC (permalink / raw)
  To: Git ML; +Cc: Eric DeCosta, Jeff Hostetler

I have access to a Mac OS X M1 box (gcc104 at [1]) where t7527 reliably
fails due to what seems to be a race us doing something, and assuming
that fsmonitor picked up on it.

This makes the tests pass:
	
	diff --git a/t/t7527-builtin-fsmonitor.sh b/t/t7527-builtin-fsmonitor.sh
	index 56c0dfffea..ce2555d558 100755
	--- a/t/t7527-builtin-fsmonitor.sh
	+++ b/t/t7527-builtin-fsmonitor.sh
	@@ -428,6 +428,7 @@ test_expect_success 'edit some files' '
	 	start_daemon --tf "$PWD/.git/trace" &&
	 
	 	edit_files &&
	+	sleep 1 &&
	 
	 	test-tool fsmonitor-client query --token 0 &&
	 
	@@ -443,6 +444,7 @@ test_expect_success 'create some files' '
	 	start_daemon --tf "$PWD/.git/trace" &&
	 
	 	create_files &&
	+	sleep 1 &&
	 
	 	test-tool fsmonitor-client query --token 0 &&
	 
	@@ -471,6 +473,7 @@ test_expect_success 'rename some files' '
	 	start_daemon --tf "$PWD/.git/trace" &&
	 
	 	rename_files &&
	+	sleep 1 &&
	 
	 	test-tool fsmonitor-client query --token 0 &&
	 
	@@ -978,6 +981,7 @@ test_expect_success !UNICODE_COMPOSITION_SENSITIVE 'Unicode nfc/nfd' '
	 	mkdir test_unicode/nfd/d_${utf8_nfd} &&
	 
	 	git -C test_unicode fsmonitor--daemon stop &&
	+	sleep 1 &&
	 
	 	if test_have_prereq UNICODE_NFC_PRESERVED
	 	then

The failure is when we grep out the events we expect, which aren't
there, but if you manually inspect them they're there. I.e. they're just
not "in" yet.

I thought this might be a lack of flushing or syncing in our own trace
code, but adding an fsync() to trace_write() didn't do the trick.

1. https://cfarm.tetaneutral.net/news/41#

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: fsmonitor: t7527 racy on OSX?
  2022-11-21 13:07 fsmonitor: t7527 racy on OSX? Ævar Arnfjörð Bjarmason
@ 2022-11-21 13:38 ` Đoàn Trần Công Danh
  2022-11-22 17:04   ` Eric DeCosta
  0 siblings, 1 reply; 5+ messages in thread
From: Đoàn Trần Công Danh @ 2022-11-21 13:38 UTC (permalink / raw)
  To: Ævar Arnfjörð Bjarmason
  Cc: Git ML, Eric DeCosta, Jeff Hostetler

On 2022-11-21 14:07:13+0100, Ævar Arnfjörð Bjarmason <avarab@gmail.com> wrote:
> I have access to a Mac OS X M1 box (gcc104 at [1]) where t7527 reliably
> fails due to what seems to be a race us doing something, and assuming
> that fsmonitor picked up on it.

See also https://lore.kernel.org/git/YvZbGAf+82WtNXcJ@danh.dev/

I raised 3 months ago and it seems like Jeff Hostetler is too busy.

> 
> This makes the tests pass:
> 	
> 	diff --git a/t/t7527-builtin-fsmonitor.sh b/t/t7527-builtin-fsmonitor.sh
> 	index 56c0dfffea..ce2555d558 100755
> 	--- a/t/t7527-builtin-fsmonitor.sh
> 	+++ b/t/t7527-builtin-fsmonitor.sh
> 	@@ -428,6 +428,7 @@ test_expect_success 'edit some files' '
> 	 	start_daemon --tf "$PWD/.git/trace" &&
> 	 
> 	 	edit_files &&
> 	+	sleep 1 &&
> 	 
> 	 	test-tool fsmonitor-client query --token 0 &&
> 	 
> 	@@ -443,6 +444,7 @@ test_expect_success 'create some files' '
> 	 	start_daemon --tf "$PWD/.git/trace" &&
> 	 
> 	 	create_files &&
> 	+	sleep 1 &&
> 	 
> 	 	test-tool fsmonitor-client query --token 0 &&
> 	 
> 	@@ -471,6 +473,7 @@ test_expect_success 'rename some files' '
> 	 	start_daemon --tf "$PWD/.git/trace" &&
> 	 
> 	 	rename_files &&
> 	+	sleep 1 &&
> 	 
> 	 	test-tool fsmonitor-client query --token 0 &&
> 	 
> 	@@ -978,6 +981,7 @@ test_expect_success !UNICODE_COMPOSITION_SENSITIVE 'Unicode nfc/nfd' '
> 	 	mkdir test_unicode/nfd/d_${utf8_nfd} &&
> 	 
> 	 	git -C test_unicode fsmonitor--daemon stop &&
> 	+	sleep 1 &&
> 	 
> 	 	if test_have_prereq UNICODE_NFC_PRESERVED
> 	 	then
> 
> The failure is when we grep out the events we expect, which aren't
> there, but if you manually inspect them they're there. I.e. they're just
> not "in" yet.
> 
> I thought this might be a lack of flushing or syncing in our own trace
> code, but adding an fsync() to trace_write() didn't do the trick.
> 
> 1. https://cfarm.tetaneutral.net/news/41#

-- 
Danh

^ permalink raw reply	[flat|nested] 5+ messages in thread

* RE: fsmonitor: t7527 racy on OSX?
  2022-11-21 13:38 ` Đoàn Trần Công Danh
@ 2022-11-22 17:04   ` Eric DeCosta
  2022-11-22 20:50     ` Eric DeCosta
  2022-11-22 22:12     ` Ævar Arnfjörð Bjarmason
  0 siblings, 2 replies; 5+ messages in thread
From: Eric DeCosta @ 2022-11-22 17:04 UTC (permalink / raw)
  To: Đoàn Trần Công Danh,
	Ævar Arnfjörð Bjarmason
  Cc: Git ML, Jeff Hostetler



> -----Original Message-----
> From: Đoàn Trần Công Danh <congdanhqx@gmail.com>
> Sent: Monday, November 21, 2022 8:39 AM
> To: Ævar Arnfjörð Bjarmason <avarab@gmail.com>
> Cc: Git ML <git@vger.kernel.org>; Eric DeCosta
> <edecosta@mathworks.com>; Jeff Hostetler <jeffhost@microsoft.com>
> Subject: Re: fsmonitor: t7527 racy on OSX?
> 
> On 2022-11-21 14:07:13+0100, Ævar Arnfjörð Bjarmason
> <avarab@gmail.com> wrote:
> > I have access to a Mac OS X M1 box (gcc104 at [1]) where t7527
> > reliably fails due to what seems to be a race us doing something, and
> > assuming that fsmonitor picked up on it.
> 
> See also https://lore.kernel.org/git/YvZbGAf+82WtNXcJ@danh.dev/
> <https://protect-
> us.mimecast.com/s/580RCpYn6ETDOBoycYVkUq?domain=lore.kernel.org>
> 
> I raised 3 months ago and it seems like Jeff Hostetler is too busy.
> 
> >
> > This makes the tests pass:
> >
> > diff --git a/t/t7527-builtin-fsmonitor.sh
> > b/t/t7527-builtin-fsmonitor.sh index 56c0dfffea..ce2555d558 100755
> > --- a/t/t7527-builtin-fsmonitor.sh
> > +++ b/t/t7527-builtin-fsmonitor.sh
> > @@ -428,6 +428,7 @@ test_expect_success 'edit some files' '
> > start_daemon --tf "$PWD/.git/trace" &&
> >
> > edit_files &&
> > + sleep 1 &&
> >
> > test-tool fsmonitor-client query --token 0 &&
> >
> > @@ -443,6 +444,7 @@ test_expect_success 'create some files' '
> > start_daemon --tf "$PWD/.git/trace" &&
> >
> > create_files &&
> > + sleep 1 &&
> >
> > test-tool fsmonitor-client query --token 0 &&
> >
> > @@ -471,6 +473,7 @@ test_expect_success 'rename some files' '
> > start_daemon --tf "$PWD/.git/trace" &&
> >
> > rename_files &&
> > + sleep 1 &&
> >
> > test-tool fsmonitor-client query --token 0 &&
> >
> > @@ -978,6 +981,7 @@ test_expect_success
> !UNICODE_COMPOSITION_SENSITIVE 'Unicode nfc/nfd' '
> > mkdir test_unicode/nfd/d_${utf8_nfd} &&
> >
> > git -C test_unicode fsmonitor--daemon stop &&
> > + sleep 1 &&
> >
> > if test_have_prereq UNICODE_NFC_PRESERVED then
> >
> > The failure is when we grep out the events we expect, which aren't
> > there, but if you manually inspect them they're there. I.e. they're
> > just not "in" yet.
> >
> > I thought this might be a lack of flushing or syncing in our own trace
> > code, but adding an fsync() to trace_write() didn't do the trick.
> >
> > 1. https://cfarm.tetaneutral.net/news/41#
> > <https://protect-
> us.mimecast.com/s/S6YNCqxoXGIWkoNRHEfMzu?domain=cfarm
> > .tetaneutral.net>
> 
> --
> Danh

Honestly, I'm not surprised. Stopping the daemon and grepping for expected results immediately there after is just asking for these sorts of races. Sleeping is a bit ugly, but without an explicit means of synchronization is probably the best that can be done. I can take a look at it some more as I have access to M1 Macs.

-Eric

^ permalink raw reply	[flat|nested] 5+ messages in thread

* RE: fsmonitor: t7527 racy on OSX?
  2022-11-22 17:04   ` Eric DeCosta
@ 2022-11-22 20:50     ` Eric DeCosta
  2022-11-22 22:12     ` Ævar Arnfjörð Bjarmason
  1 sibling, 0 replies; 5+ messages in thread
From: Eric DeCosta @ 2022-11-22 20:50 UTC (permalink / raw)
  To: Đoàn Trần Công Danh,
	Ævar Arnfjörð Bjarmason
  Cc: Git ML, Jeff Hostetler



> -----Original Message-----
> From: Eric DeCosta
> Sent: Tuesday, November 22, 2022 12:05 PM
> To: Đoàn Trần Công Danh <congdanhqx@gmail.com>; Ævar Arnfjörð
> Bjarmason <avarab@gmail.com>
> Cc: Git ML <git@vger.kernel.org>; Jeff Hostetler <jeffhost@microsoft.com>
> Subject: RE: fsmonitor: t7527 racy on OSX?
> 
> 
> 
> > -----Original Message-----
> > From: Đoàn Trần Công Danh <congdanhqx@gmail.com>
> > Sent: Monday, November 21, 2022 8:39 AM
> > To: Ævar Arnfjörð Bjarmason <avarab@gmail.com>
> > Cc: Git ML <git@vger.kernel.org>; Eric DeCosta
> > <edecosta@mathworks.com>; Jeff Hostetler <jeffhost@microsoft.com>
> > Subject: Re: fsmonitor: t7527 racy on OSX?
> >
> > On 2022-11-21 14:07:13+0100, Ævar Arnfjörð Bjarmason
> > <avarab@gmail.com> wrote:
> > > I have access to a Mac OS X M1 box (gcc104 at [1]) where t7527
> > > reliably fails due to what seems to be a race us doing something,
> > > and assuming that fsmonitor picked up on it.
> >
> > See also https://lore.kernel.org/git/YvZbGAf+82WtNXcJ@danh.dev/
> > <https://protect-
> > us.mimecast.com/s/580RCpYn6ETDOBoycYVkUq?domain=lore.kernel.org>
> >
> > I raised 3 months ago and it seems like Jeff Hostetler is too busy.
> >
> > >
> > > This makes the tests pass:
> > >
> > > diff --git a/t/t7527-builtin-fsmonitor.sh
> > > b/t/t7527-builtin-fsmonitor.sh index 56c0dfffea..ce2555d558 100755
> > > --- a/t/t7527-builtin-fsmonitor.sh
> > > +++ b/t/t7527-builtin-fsmonitor.sh
> > > @@ -428,6 +428,7 @@ test_expect_success 'edit some files' '
> > > start_daemon --tf "$PWD/.git/trace" &&
> > >
> > > edit_files &&
> > > + sleep 1 &&
> > >
> > > test-tool fsmonitor-client query --token 0 &&
> > >
> > > @@ -443,6 +444,7 @@ test_expect_success 'create some files' '
> > > start_daemon --tf "$PWD/.git/trace" &&
> > >
> > > create_files &&
> > > + sleep 1 &&
> > >
> > > test-tool fsmonitor-client query --token 0 &&
> > >
> > > @@ -471,6 +473,7 @@ test_expect_success 'rename some files' '
> > > start_daemon --tf "$PWD/.git/trace" &&
> > >
> > > rename_files &&
> > > + sleep 1 &&
> > >
> > > test-tool fsmonitor-client query --token 0 &&
> > >
> > > @@ -978,6 +981,7 @@ test_expect_success
> > !UNICODE_COMPOSITION_SENSITIVE 'Unicode nfc/nfd' '
> > > mkdir test_unicode/nfd/d_${utf8_nfd} &&
> > >
> > > git -C test_unicode fsmonitor--daemon stop &&
> > > + sleep 1 &&
> > >
> > > if test_have_prereq UNICODE_NFC_PRESERVED then
> > >
> > > The failure is when we grep out the events we expect, which aren't
> > > there, but if you manually inspect them they're there. I.e. they're
> > > just not "in" yet.
> > >
> > > I thought this might be a lack of flushing or syncing in our own
> > > trace code, but adding an fsync() to trace_write() didn't do the trick.
> > >
> > > 1. https://cfarm.tetaneutral.net/news/41#
> > > <https://protect-
> > us.mimecast.com/s/S6YNCqxoXGIWkoNRHEfMzu?domain=cfarm
> > > .tetaneutral.net>
> >
> > --
> > Danh
> 
> Honestly, I'm not surprised. Stopping the daemon and grepping for expected
> results immediately there after is just asking for these sorts of races.
> Sleeping is a bit ugly, but without an explicit means of synchronization is
> probably the best that can be done. I can take a look at it some more as I
> have access to M1 Macs.
> 
> -Eric

https://github.com/gitgitgadget/git/commit/63db616d0ec644cee9f81529ed093beee0a01f65

After applying those pending test changes that I have been developing for fsmonitor for Linux, I have been unable to reproduce the problem on Mac OS.

-Eric

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: fsmonitor: t7527 racy on OSX?
  2022-11-22 17:04   ` Eric DeCosta
  2022-11-22 20:50     ` Eric DeCosta
@ 2022-11-22 22:12     ` Ævar Arnfjörð Bjarmason
  1 sibling, 0 replies; 5+ messages in thread
From: Ævar Arnfjörð Bjarmason @ 2022-11-22 22:12 UTC (permalink / raw)
  To: Eric DeCosta
  Cc: Đoàn Trần Công Danh, Git ML, Jeff Hostetler


On Tue, Nov 22 2022, Eric DeCosta wrote:

>> -----Original Message-----
>> From: Đoàn Trần Công Danh <congdanhqx@gmail.com>
>> Sent: Monday, November 21, 2022 8:39 AM
>> To: Ævar Arnfjörð Bjarmason <avarab@gmail.com>
>> Cc: Git ML <git@vger.kernel.org>; Eric DeCosta
>> <edecosta@mathworks.com>; Jeff Hostetler <jeffhost@microsoft.com>
>> Subject: Re: fsmonitor: t7527 racy on OSX?
>> 
>> On 2022-11-21 14:07:13+0100, Ævar Arnfjörð Bjarmason
>> <avarab@gmail.com> wrote:
>> > I have access to a Mac OS X M1 box (gcc104 at [1]) where t7527
>> > reliably fails due to what seems to be a race us doing something, and
>> > assuming that fsmonitor picked up on it.
>> 
>> See also https://lore.kernel.org/git/YvZbGAf+82WtNXcJ@danh.dev/
>> <https://protect-
>> us.mimecast.com/s/580RCpYn6ETDOBoycYVkUq?domain=lore.kernel.org>
>> 
>> I raised 3 months ago and it seems like Jeff Hostetler is too busy.
>> 
>> >
>> > This makes the tests pass:
>> >
>> > diff --git a/t/t7527-builtin-fsmonitor.sh
>> > b/t/t7527-builtin-fsmonitor.sh index 56c0dfffea..ce2555d558 100755
>> > --- a/t/t7527-builtin-fsmonitor.sh
>> > +++ b/t/t7527-builtin-fsmonitor.sh
>> > @@ -428,6 +428,7 @@ test_expect_success 'edit some files' '
>> > start_daemon --tf "$PWD/.git/trace" &&
>> >
>> > edit_files &&
>> > + sleep 1 &&
>> >
>> > test-tool fsmonitor-client query --token 0 &&
>> >
>> > @@ -443,6 +444,7 @@ test_expect_success 'create some files' '
>> > start_daemon --tf "$PWD/.git/trace" &&
>> >
>> > create_files &&
>> > + sleep 1 &&
>> >
>> > test-tool fsmonitor-client query --token 0 &&
>> >
>> > @@ -471,6 +473,7 @@ test_expect_success 'rename some files' '
>> > start_daemon --tf "$PWD/.git/trace" &&
>> >
>> > rename_files &&
>> > + sleep 1 &&
>> >
>> > test-tool fsmonitor-client query --token 0 &&
>> >
>> > @@ -978,6 +981,7 @@ test_expect_success
>> !UNICODE_COMPOSITION_SENSITIVE 'Unicode nfc/nfd' '
>> > mkdir test_unicode/nfd/d_${utf8_nfd} &&
>> >
>> > git -C test_unicode fsmonitor--daemon stop &&
>> > + sleep 1 &&
>> >
>> > if test_have_prereq UNICODE_NFC_PRESERVED then
>> >
>> > The failure is when we grep out the events we expect, which aren't
>> > there, but if you manually inspect them they're there. I.e. they're
>> > just not "in" yet.
>> >
>> > I thought this might be a lack of flushing or syncing in our own trace
>> > code, but adding an fsync() to trace_write() didn't do the trick.
>> >
>> > 1. https://cfarm.tetaneutral.net/news/41#
>> > <https://protect-
>> us.mimecast.com/s/S6YNCqxoXGIWkoNRHEfMzu?domain=cfarm
>> > .tetaneutral.net>
>> 
>> --
>> Danh
>
> Honestly, I'm not surprised. Stopping the daemon and grepping for
> expected results immediately there after is just asking for these
> sorts of races. Sleeping is a bit ugly, but without an explicit means
> of synchronization is probably the best that can be done. I can take a
> look at it some more as I have access to M1 Macs.

I don't see why it would have to do with stopping the daemon. If
anything that should reduce the odds that you're running into a
race. I.e. on OSX in general this will work:

	echo foo >f &&
	grep foo f

Or, the equivalent with an "echo" that's not a shell built-in. I.e. we
had a process start, print to a file, and then we grep data out of it
agin.

The reason I'm saying it should reduce them is if the "echo" were some
long-running daemon process that was still running the "grep" might fail
because the "foo" was still in some buffer and hadn't been written or
fsync'd to disk.

Anyway, all of that seems inapplicable to these failures, as we're not
stopping the daemon yet by the time we run into the synchronization
problem. We just *started* it, then renamed some files, but when we ask
for those events we don't get them back.

Maybe there's some innocuous reason for that, but I have the sinking
feeling that it might be some race between creating the files, the
kernel getting those events, acting on them, but not having sent notice
of those events to the daemon that's listening.

*That* would be much scarier, and would mean that this fsmonitor
implementation would be racy outside of our tests, wouldn't it?

^ permalink raw reply	[flat|nested] 5+ messages in thread

end of thread, other threads:[~2022-11-22 22:20 UTC | newest]

Thread overview: 5+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2022-11-21 13:07 fsmonitor: t7527 racy on OSX? Ævar Arnfjörð Bjarmason
2022-11-21 13:38 ` Đoàn Trần Công Danh
2022-11-22 17:04   ` Eric DeCosta
2022-11-22 20:50     ` Eric DeCosta
2022-11-22 22:12     ` Ævar Arnfjörð Bjarmason

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).