{"thread":{"id":"61098","subject":"t0032 fails on NFS mounts","startedAt":"2024-03-12T15:10:37Z","lastAt":"2024-03-22T15:15:29Z","messageCount":10,"participants":["Chuck Lever","rsbecker@nexbridge.com","Jeff King","Patrick Steinhardt","Junio C Hamano","Toon Claes"],"isPatch":false,"patchVersion":null,"patchTotal":null},"messages":[{"id":"490487","messageId":"ZfBwZTL9zqDsac5m@manet.1015granger.net","threadId":"61098","inReplyTo":null,"subject":"t0032 fails on NFS mounts","fromName":"Chuck Lever","fromEmail":"chuck.lever@oracle.com","sentAt":"2024-03-12T15:10:29Z","receivedAt":"2024-03-12T15:10:37Z","isPatch":false,"sender":{"key":"chuck.lever@oracle.com","avatar":null},"body":"Hi-\n\nI've checked out \"maint\".\n\nUnit test t0032 fails when run on an NFS mount:\n\n[vagrant@cel t]$ ./t0032-reftable-unittest.sh \nnot ok 1 - unittests\n#\t\n#\t\tTMPDIR=$(pwd) && export TMPDIR &&\n#\t\ttest-tool reftable\n#\t\n# failed 1 among 1 test(s)\n1..1\n[vagrant@cel t]$\n\nBut not on XFS:\n\n[vagrant@cel t]$ ./t0032-reftable-unittest.sh \nok 1 - unittests\n# passed all 1 test(s)\n1..1\n[vagrant@cel t]$ cd ..\n[vagrant@cel git]$ ./git --version\ngit version 2.44.0\n[vagrant@cel git]$\n\nv2.43.2 seems to work OK.\n\n-- \nChuck Lever\n"},{"id":"490494","messageId":"0cb701da74a0$4e39ef60$eaadce20$@nexbridge.com","threadId":"61098","inReplyTo":"ZfBwZTL9zqDsac5m@manet.1015granger.net","subject":"RE: t0032 fails on NFS mounts","fromName":"","fromEmail":"rsbecker@nexbridge.com","sentAt":"2024-03-12T17:11:15Z","receivedAt":"2024-03-12T17:11:38Z","isPatch":false,"sender":{"key":"randall.becker@nexbridge.ca","avatar":"https://avatars.githubusercontent.com/u/28956764?v=4"},"body":"On Tuesday, March 12, 2024 11:10 AM, Chuck Lever wrote:\n>I've checked out \"maint\".\n>\n>Unit test t0032 fails when run on an NFS mount:\n>\n>[vagrant@cel t]$ ./t0032-reftable-unittest.sh not ok 1 - unittests\n>#\n>#\t\tTMPDIR=$(pwd) && export TMPDIR &&\n>#\t\ttest-tool reftable\n>#\n># failed 1 among 1 test(s)\n>1..1\n>[vagrant@cel t]$\n>\n>But not on XFS:\n>\n>[vagrant@cel t]$ ./t0032-reftable-unittest.sh ok 1 - unittests # passed all\n1 test(s)\n>1..1\n>[vagrant@cel t]$ cd ..\n>[vagrant@cel git]$ ./git --version\n>git version 2.44.0\n>[vagrant@cel git]$\n>\n>v2.43.2 seems to work OK.\n\nI have seen a similar effect on a standard POSIX file system (NonStop) when\nrun in a special platform container (Pathway). It does not happen for me\nwhen run from bash directly. This may be something other than an NFS effect,\nor unrelated to what I observed. I'll be monitoring this sub-test for\nrepeats.\n--Randall\n\n"},{"id":"490531","messageId":"20240313072052.GC125150@coredump.intra.peff.net","threadId":"61098","inReplyTo":"ZfBwZTL9zqDsac5m@manet.1015granger.net","subject":"Re: t0032 fails on NFS mounts","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2024-03-13T07:20:52Z","receivedAt":"2024-03-13T07:20:53Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"+cc Patrick for reftable\n\nOn Tue, Mar 12, 2024 at 11:10:29AM -0400, Chuck Lever wrote:\n\n> Unit test t0032 fails when run on an NFS mount:\n> \n> [vagrant@cel t]$ ./t0032-reftable-unittest.sh \n> not ok 1 - unittests\n> #\t\n> #\t\tTMPDIR=$(pwd) && export TMPDIR &&\n> #\t\ttest-tool reftable\n> #\t\n> # failed 1 among 1 test(s)\n> 1..1\n\nThe output for this test script is particularly unhelpful because it's\nnot using our test harness at all, but just running a bunch of internal\ntests using a single program.\n\nRunning with \"-v\" should give more details about what's failing.\n\nI set up a basic loopback server like:\n\n  mkdir /mnt/{server,client}\n  exportfs -o rw,sync 127.0.0.1:/mnt/server\n  mount -t nfs 127.0.0.1:/mnt/server /mnt/client\n\nand then ran:\n\n  ./t0032-reftable-unittest.sh --root=/mnt/client -v\n\nLooks like it fails at:\n\n  running test_reftable_stack_compaction_concurrent_clean\n  reftable/stack_test.c: 1063: failed assertion count_dir_entries(dir) == 2\n  Aborted\n\n> v2.43.2 seems to work OK.\n\nFor me, too. Bisecting shows the problem appearing in 4f36b8597c\n(reftable/stack: fix race in up-to-date check, 2024-01-18).\n\n-Peff\n\nPS That test seems to run ~20x slower on NFS versus directly on ext4.\n   I'd expect a little overhead, but that's quite a bit.\n"},{"id":"490654","messageId":"ZfOXz81cpGZvq6Pq@tanuki","threadId":"61098","inReplyTo":"20240313072052.GC125150@coredump.intra.peff.net","subject":"Re: t0032 fails on NFS mounts","fromName":"Patrick Steinhardt","fromEmail":"ps@pks.im","sentAt":"2024-03-15T00:35:27Z","receivedAt":"2024-03-15T00:35:38Z","isPatch":false,"sender":{"key":"ps@pks.im","avatar":"https://avatars.githubusercontent.com/u/4056630?v=4"},"body":"On Wed, Mar 13, 2024 at 03:20:52AM -0400, Jeff King wrote:\n> +cc Patrick for reftable\n> \n> On Tue, Mar 12, 2024 at 11:10:29AM -0400, Chuck Lever wrote:\n> \n> > Unit test t0032 fails when run on an NFS mount:\n> > \n> > [vagrant@cel t]$ ./t0032-reftable-unittest.sh \n> > not ok 1 - unittests\n> > #\t\n> > #\t\tTMPDIR=$(pwd) && export TMPDIR &&\n> > #\t\ttest-tool reftable\n> > #\t\n> > # failed 1 among 1 test(s)\n> > 1..1\n> \n> The output for this test script is particularly unhelpful because it's\n> not using our test harness at all, but just running a bunch of internal\n> tests using a single program.\n> \n> Running with \"-v\" should give more details about what's failing.\n> \n> I set up a basic loopback server like:\n> \n>   mkdir /mnt/{server,client}\n>   exportfs -o rw,sync 127.0.0.1:/mnt/server\n>   mount -t nfs 127.0.0.1:/mnt/server /mnt/client\n> \n> and then ran:\n> \n>   ./t0032-reftable-unittest.sh --root=/mnt/client -v\n> \n> Looks like it fails at:\n> \n>   running test_reftable_stack_compaction_concurrent_clean\n>   reftable/stack_test.c: 1063: failed assertion count_dir_entries(dir) == 2\n>   Aborted\n> \n> > v2.43.2 seems to work OK.\n> \n> For me, too. Bisecting shows the problem appearing in 4f36b8597c\n> (reftable/stack: fix race in up-to-date check, 2024-01-18).\n> \n> -Peff\n> \n> PS That test seems to run ~20x slower on NFS versus directly on ext4.\n>    I'd expect a little overhead, but that's quite a bit.\n\nUnless somebody else beats me to it I'll investigate this next week when\nI'm back in the office. Thanks for the report and for digging into this\nissue!\n\nPatrick\n"},{"id":"490693","messageId":"xmqqmsqztsd1.fsf@gitster.g","threadId":"61098","inReplyTo":"ZfOXz81cpGZvq6Pq@tanuki","subject":"Re: t0032 fails on NFS mounts","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2024-03-15T15:41:30Z","receivedAt":"2024-03-15T15:41:35Z","isPatch":false,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Patrick Steinhardt <ps@pks.im> writes:\n\n> Unless somebody else beats me to it I'll investigate this next week when\n> I'm back in the office. Thanks for the report and for digging into this\n> issue!\n\nThanks.\n"},{"id":"491151","messageId":"ZfxO8ApCDUbBHJyc@tanuki","threadId":"61098","inReplyTo":"20240313072052.GC125150@coredump.intra.peff.net","subject":"Re: t0032 fails on NFS mounts","fromName":"Patrick Steinhardt","fromEmail":"ps@pks.im","sentAt":"2024-03-21T15:14:56Z","receivedAt":"2024-03-21T15:15:03Z","isPatch":false,"sender":{"key":"ps@pks.im","avatar":"https://avatars.githubusercontent.com/u/4056630?v=4"},"body":"On Wed, Mar 13, 2024 at 03:20:52AM -0400, Jeff King wrote:\n> +cc Patrick for reftable\n> \n> On Tue, Mar 12, 2024 at 11:10:29AM -0400, Chuck Lever wrote:\n> \n> > Unit test t0032 fails when run on an NFS mount:\n> > \n> > [vagrant@cel t]$ ./t0032-reftable-unittest.sh \n> > not ok 1 - unittests\n> > #\t\n> > #\t\tTMPDIR=$(pwd) && export TMPDIR &&\n> > #\t\ttest-tool reftable\n> > #\t\n> > # failed 1 among 1 test(s)\n> > 1..1\n> \n> The output for this test script is particularly unhelpful because it's\n> not using our test harness at all, but just running a bunch of internal\n> tests using a single program.\n> \n> Running with \"-v\" should give more details about what's failing.\n> \n> I set up a basic loopback server like:\n> \n>   mkdir /mnt/{server,client}\n>   exportfs -o rw,sync 127.0.0.1:/mnt/server\n>   mount -t nfs 127.0.0.1:/mnt/server /mnt/client\n> \n> and then ran:\n> \n>   ./t0032-reftable-unittest.sh --root=/mnt/client -v\n> \n> Looks like it fails at:\n> \n>   running test_reftable_stack_compaction_concurrent_clean\n>   reftable/stack_test.c: 1063: failed assertion count_dir_entries(dir) == 2\n>   Aborted\n> \n> > v2.43.2 seems to work OK.\n> \n> For me, too. Bisecting shows the problem appearing in 4f36b8597c\n> (reftable/stack: fix race in up-to-date check, 2024-01-18).\n\nI think this is actually benign. I set a breakpoint in the respective\ntest right before double-checking our conditions, and curiously I got\nback the following list of files:\n\n    ./stack_test-1027.QJBpnd\n    ./stack_test-1027.QJBpnd/0x000000000001-0x000000000003-dad7ac80.ref\n    ./stack_test-1027.QJBpnd/.nfs000000000001729f00001e11\n    ./stack_test-1027.QJBpnd/tables.list\n\nNotice the \".nfs*\" thing? This is a temporary file managed by the NFS\nclient that maintains delete-on-close behaviour because we have unlinked\nthe file while it was still open [1]. But of course we count that file\nwhen executing `count_dir_entries()`, and thus we arrive at an\nunexpected number of files.\n\nI will send a patch to fix the test.\n\n> PS That test seems to run ~20x slower on NFS versus directly on ext4.\n>    I'd expect a little overhead, but that's quite a bit.\n\nI'm not all that surprised here given that the reftable library is quite\nprone to stat(3P)ing the \"tables.list\" file, and potentially re-reading\nit. I kind of suspect that this is what's going on. An alternative\nexplanation might be that mmap'ing over NFS is really slow.\n\nAnyway, I will have a deeper look at this and see where we spend all the\ntime.\n\nPatrick\n\n[1]: https://nfs.sourceforge.net/#faq_d2\n"},{"id":"491152","messageId":"8ac5e94a3930cdd2aee9ea86acda3155674b635c.1711035529.git.ps@pks.im","threadId":"61098","inReplyTo":"ZfBwZTL9zqDsac5m@manet.1015granger.net","subject":"[PATCH] reftable: fix tests being broken by NFS' delete-after-close semantics","fromName":"Patrick Steinhardt","fromEmail":"ps@pks.im","sentAt":"2024-03-21T15:39:52Z","receivedAt":"2024-03-21T15:39:58Z","isPatch":true,"sender":{"key":"ps@pks.im","avatar":"https://avatars.githubusercontent.com/u/4056630?v=4"},"body":"It was reported that the reftable unit tests in t0032 fail with the\nfollowing assertion when running on top of NFS:\n\n    running test_reftable_stack_compaction_concurrent_clean\n    reftable/stack_test.c: 1063: failed assertion count_dir_entries(dir) == 2\n    Aborted\n\nSetting a breakpoint immediately before the assertion in fact shows the\nfollowing list of files:\n\n    ./stack_test-1027.QJBpnd\n    ./stack_test-1027.QJBpnd/0x000000000001-0x000000000003-dad7ac80.ref\n    ./stack_test-1027.QJBpnd/.nfs000000000001729f00001e11\n    ./stack_test-1027.QJBpnd/tables.list\n\nNote the weird \".nfs*\" file? This file is maintained by NFS clients in\norder to emulate delete-after-last-close semantics that we rely on in\nthe reftable code [1]. Instead of unlinking the file right away and\nkeeping it open in the client, the NFS client will rename it to \".nfs*\"\nand then delete that temporary file when the last reference to it gets\ndropped. Quoting the NFS FAQ:\n\n    > D2. What is a \"silly rename\"? Why do these .nfsXXXXX files keep\n    > showing up?\n    >\n    > A. Unix applications often open a scratch file and then unlink it.\n    > They do this so that the file is not visible in the file system name\n    > space to any other applications, and so that the system will\n    > automatically clean up (delete) the file when the application exits.\n    > This is known as \"delete on last close\", and is a tradition among\n    > Unix applications.\n    >\n    > Because of the design of the NFS protocol, there is no way for a\n    > file to be deleted from the name space but still remain in use by an\n    > application. Thus NFS clients have to emulate this using what\n    > already exists in the protocol. If an open file is unlinked, an NFS\n    > client renames it to a special name that looks like \".nfsXXXXX\".\n    > This \"hides\" the file while it remains in use. This is known as a\n    > \"silly rename.\" Note that NFS servers have nothing to do with this\n    > behavior.\n\nThis of course throws off the assertion that we got exactly two files in\nthat directory.\n\nThe test in question triggers this behaviour by holding two open file\ndescriptors to the \"tables.list\" file. One of the references is because\nwe are about to append to the stack, whereas the other reference is\nbecause we want to compact it. As the compaction has just finished we\nalready rewrote \"tables.list\" to point to the new contents, but the\nother file descriptor pointing to the old version is still open. Thus we\ntrigger the delete-after-last-close emulation.\n\nFurthermore, it was reported that this behaviour only triggers with\n4f36b8597c (reftable/stack: fix race in up-to-date check, 2024-01-18).\nThis is expected as well because it is the first point in time where we\nactually keep the \"tables.list\" file descriptor open for the stat cache.\n\nFix this bug by skipping over any files that start with a leading dot\nwhen counting files. While we could explicitly check for a prefix of\n\".nfs\", other network file systems like SMB for example do the same\ntrickery but with a \".smb\" prefix. In any case though, this loosening of\nthe assertion should be fine given that the reftable library would never\nwrite files with leading dots by itself.\n\n[1]: https://nfs.sourceforge.net/#faq_d2\n\nReported-by: Chuck Lever <chuck.lever@oracle.com>\nSigned-off-by: Patrick Steinhardt <ps@pks.im>\n---\n reftable/stack_test.c | 12 +++++++++++-\n 1 file changed, 11 insertions(+), 1 deletion(-)\n\ndiff --git a/reftable/stack_test.c b/reftable/stack_test.c\nindex 509f486623..621578fda8 100644\n--- a/reftable/stack_test.c\n+++ b/reftable/stack_test.c\n@@ -38,7 +38,17 @@ static int count_dir_entries(const char *dirname)\n \t\treturn 0;\n \n \twhile ((d = readdir(dir))) {\n-\t\tif (!strcmp(d->d_name, \"..\") || !strcmp(d->d_name, \".\"))\n+\t\t/*\n+\t\t * Besides skipping over \".\" and \"..\", we also need to\n+\t\t * skip over other files that have a leading \".\". This\n+\t\t * is due to behaviour of NFS, which will rename files\n+\t\t * to \".nfs*\" to emulate delete-on-last-close.\n+\t\t *\n+\t\t * In any case this should be fine as the reftable\n+\t\t * library will never write files with leading dots\n+\t\t * anyway.\n+\t\t */\n+\t\tif (starts_with(d->d_name, \".\"))\n \t\t\tcontinue;\n \t\tlen++;\n \t}\n-- \n2.44.0\n\n"},{"id":"491153","messageId":"ZfxXOR9e7Mu7T3to@tanuki","threadId":"61098","inReplyTo":"0cb701da74a0$4e39ef60$eaadce20$@nexbridge.com","subject":"Re: t0032 fails on NFS mounts","fromName":"Patrick Steinhardt","fromEmail":"ps@pks.im","sentAt":"2024-03-21T15:50:17Z","receivedAt":"2024-03-21T15:50:23Z","isPatch":false,"sender":{"key":"ps@pks.im","avatar":"https://avatars.githubusercontent.com/u/4056630?v=4"},"body":"On Tue, Mar 12, 2024 at 01:11:15PM -0400, rsbecker@nexbridge.com wrote:\n> On Tuesday, March 12, 2024 11:10 AM, Chuck Lever wrote:\n> >I've checked out \"maint\".\n> >\n> >Unit test t0032 fails when run on an NFS mount:\n> >\n> >[vagrant@cel t]$ ./t0032-reftable-unittest.sh not ok 1 - unittests\n> >#\n> >#\t\tTMPDIR=$(pwd) && export TMPDIR &&\n> >#\t\ttest-tool reftable\n> >#\n> ># failed 1 among 1 test(s)\n> >1..1\n> >[vagrant@cel t]$\n> >\n> >But not on XFS:\n> >\n> >[vagrant@cel t]$ ./t0032-reftable-unittest.sh ok 1 - unittests # passed all\n> 1 test(s)\n> >1..1\n> >[vagrant@cel t]$ cd ..\n> >[vagrant@cel git]$ ./git --version\n> >git version 2.44.0\n> >[vagrant@cel git]$\n> >\n> >v2.43.2 seems to work OK.\n> \n> I have seen a similar effect on a standard POSIX file system (NonStop) when\n> run in a special platform container (Pathway). It does not happen for me\n> when run from bash directly. This may be something other than an NFS effect,\n> or unrelated to what I observed. I'll be monitoring this sub-test for\n> repeats.\n\nInteresting. Do you know at what point in time this happened? Was it for\none of the releases or any of the in-between states? Also, does Pathway\nmess with the stat(3P) info somehow?\n\nPatrick\n"},{"id":"491163","messageId":"xmqqsf0j8p48.fsf@gitster.g","threadId":"61098","inReplyTo":"8ac5e94a3930cdd2aee9ea86acda3155674b635c.1711035529.git.ps@pks.im","subject":"Re: [PATCH] reftable: fix tests being broken by NFS' delete-after-close semantics","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2024-03-21T17:35:19Z","receivedAt":"2024-03-21T17:35:24Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Patrick Steinhardt <ps@pks.im> writes:\n\n>  \twhile ((d = readdir(dir))) {\n> -\t\tif (!strcmp(d->d_name, \"..\") || !strcmp(d->d_name, \".\"))\n> +\t\t/*\n> +\t\t * Besides skipping over \".\" and \"..\", we also need to\n> +\t\t * skip over other files that have a leading \".\". This\n> +\t\t * is due to behaviour of NFS, which will rename files\n> +\t\t * to \".nfs*\" to emulate delete-on-last-close.\n> +\t\t *\n> +\t\t * In any case this should be fine as the reftable\n> +\t\t * library will never write files with leading dots\n> +\t\t * anyway.\n> +\t\t */\n> +\t\tif (starts_with(d->d_name, \".\"))\n>  \t\t\tcontinue;\n\nSounds good.  We should count what we positively consider what we\nwrote, not random cruft somebody else might have dropped in the\ndirectory, and this is a good first thing to do.\n\nWill queue.  Thanks.\n"},{"id":"491248","messageId":"87frwiuwlb.fsf@to1.studio","threadId":"61098","inReplyTo":"8ac5e94a3930cdd2aee9ea86acda3155674b635c.1711035529.git.ps@pks.im","subject":"Re: [PATCH] reftable: fix tests being broken by NFS' delete-after-close semantics","fromName":"Toon Claes","fromEmail":"toon@iotcl.com","sentAt":"2024-03-22T15:15:12Z","receivedAt":"2024-03-22T15:15:29Z","isPatch":true,"sender":{"key":"toon@iotcl.com","avatar":"https://avatars.githubusercontent.com/u/121621?v=4"},"body":"Patrick Steinhardt <ps@pks.im> writes:\n\n> Fix this bug by skipping over any files that start with a leading dot\n> when counting files. While we could explicitly check for a prefix of\n> \".nfs\", other network file systems like SMB for example do the same\n> trickery but with a \".smb\" prefix. In any case though, this loosening of\n> the assertion should be fine given that the reftable library would never\n> write files with leading dots by itself.\n\nI'm fully supportive of this, as this will also fix any issues possibly\ncaused by .DS_Store files created by Finder on macOS, although it's very\nunlikely they will be created in these tests.\n\n--\nToon\n"}]}