[BUG] commit fails with 'bus error' when working directory is on an NFS share

> I've recently upgraded my (Linux Mint) distribution version, which
> came with git v2.43.0 and I noticed that I can no longer `commit` on
> any working directory which resides on an NFS share mount.
> 
> Git reports "Bus error (core dumped)" and dmesg shows multiple "NFS:
> server error: fileid changed. fsid 0:68: expected fileid
> 0xf8e3d8e80230ddb5, got 0xeeb48230d99ed0d4" messages.
> 
> This does not happen if I move the working directory off the NFS share.

>
> On Fri, Nov 29, 2024 at 09:58:51PM -0700, Dmitriy Panteleyev wrote:
>
> > I've recently upgraded my (Linux Mint) distribution version, which
> > came with git v2.43.0 and I noticed that I can no longer `commit` on
> > any working directory which resides on an NFS share mount.
> >
> > Git reports "Bus error (core dumped)" and dmesg shows multiple "NFS:
> > server error: fileid changed. fsid 0:68: expected fileid
> > 0xf8e3d8e80230ddb5, got 0xeeb48230d99ed0d4" messages.
> >
> > This does not happen if I move the working directory off the NFS share.
>
> I can't reproduce any problems here on a test NFS mount. But since the
> old version works here:
>
> > I attempted to upgrade git to v2.47.1, with the same result.
> >
> > I then downgraded git to v2.34.1 (the version for the previous
> > distribution release) and the error has resolved.
>
> Can you try bisecting between v2.34.1 and v2.43.0 to see which commit
> introduces the problem for you?
>
> -Peff

> > > I attempted to upgrade git to v2.47.1, with the same result.
> > >
> > > I then downgraded git to v2.34.1 (the version for the previous
> > > distribution release) and the error has resolved.
> >
> > Can you try bisecting between v2.34.1 and v2.43.0 to see which commit
> > introduces the problem for you?
> >
> > -Peff
> 
> Bisecting: 0 revisions left to test after this (roughly 0 steps)
> [04fb96219abc0cbe46ba084997dc9066de3ac889] parse_object(): drop extra
> "has" check before checking object type

>
> On Sun, Dec 01, 2024 at 10:17:44AM -0700, Dmitriy Panteleyev wrote:
>
> > > > I attempted to upgrade git to v2.47.1, with the same result.
> > > >
> > > > I then downgraded git to v2.34.1 (the version for the previous
> > > > distribution release) and the error has resolved.
> > >
> > > Can you try bisecting between v2.34.1 and v2.43.0 to see which commit
> > > introduces the problem for you?
> > >
> > > -Peff
> >
> > Bisecting: 0 revisions left to test after this (roughly 0 steps)
> > [04fb96219abc0cbe46ba084997dc9066de3ac889] parse_object(): drop extra
> > "has" check before checking object type
>
> That seems like an unlikely commit to introduce the problem you're
> seeing. And how did we end up with 0 revisions left to check, but no
> final outcome? Did you need to do one more test and "git bisect
> good/bad" on this commit?
>

> Or alternatively, can you share what you're doing to test the bisection?
> That might help us reproduce. I kind of wonder if the results might not
> be deterministic, to end up at an apparently unrelated commit like that.
>
> -Peff

> 04fb96219abc0cbe46ba084997dc9066de3ac889 is the first bad commit
> commit 04fb96219abc0cbe46ba084997dc9066de3ac889
> Author: Jeff King <peff@peff.net>
> Date:   Thu Nov 17 17:37:58 2022 -0500
> 
>     parse_object(): drop extra "has" check before checking object type
> 
>     When parsing an object of unknown type, we check to see if it's a blob,
>     so we can use our streaming code path. This uses oid_object_info() to
>     check the type, but before doing so we call repo_has_object_file(). This
>     latter is pointless, as oid_object_info() will already fail if the
>     object is missing. Checking it ahead of time just complicates the code
>     and is a waste of resources (albeit small).
> 
>     Let's drop the redundant check.

>
> On Sun, Dec 01, 2024 at 03:24:35PM -0700, Dmitriy Panteleyev wrote:
>
> > You are right, Jeff, I needed to run one more bisect. But it does point to
> > the commit I linked above. The bisect result is:
>
> Thanks for checking. I'm still puzzled how this commit:
>
> > 04fb96219abc0cbe46ba084997dc9066de3ac889 is the first bad commit
> > commit 04fb96219abc0cbe46ba084997dc9066de3ac889
> > Author: Jeff King <peff@peff.net>
> > Date:   Thu Nov 17 17:37:58 2022 -0500
> >
> >     parse_object(): drop extra "has" check before checking object type
> >
> >     When parsing an object of unknown type, we check to see if it's a blob,
> >     so we can use our streaming code path. This uses oid_object_info() to
> >     check the type, but before doing so we call repo_has_object_file(). This
> >     latter is pointless, as oid_object_info() will already fail if the
> >     object is missing. Checking it ahead of time just complicates the code
> >     and is a waste of resources (albeit small).
> >
> >     Let's drop the redundant check.
>
> could be the culprit, though. The diff is just
>
> diff --git a/object.c b/object.c
> index 8a74eb85e9..16eb944e98 100644
> --- a/object.c
> +++ b/object.c
> @@ -287,8 +287,7 @@ struct object *parse_object_with_flags(struct repository *r,
>         }
>
>         if ((obj && obj->type == OBJ_BLOB && repo_has_object_file(r, oid)) ||
> -           (!obj && repo_has_object_file(r, oid) &&
> -            oid_object_info(r, oid, NULL) == OBJ_BLOB)) {
> +           (!obj && oid_object_info(r, oid, NULL) == OBJ_BLOB)) {
>                 if (!skip_hash && stream_object_signature(r, repl) < 0) {
>                         error(_("hash mismatch %s"), oid_to_hex(oid));
>                         return NULL;
>
> So it is actually doing _less_, though what it is removing is going to
> just be a pack .idx lookup (or maybe a stat() call if the object is
> loose).
>
> > I am not at all familiar with the standard process for this, but the way I ran
> > the test is:
> >
> > (0. cloned test project into /nfs/proj/ and made a change)
> > 1. cloned git repo (from github) into /tmp/git/
> > 2. ran bisect in /tmp/git/, starting with v2.34.1 (good) and v2.43.1 (bad)
> > 3. ran `make all` in /tmp/git/
> > 4. in /nfs/proj/ ran `/tmp/git/bin-wrappers/git commit -m 'test'`
> > 5. repeated 2-4
>
> That sounds reasonable. I'm still not sure what's going on. It's always
> possible that commit introduced a problem, but I just don't see it. So I
> still have a suspicion (especially given that your symptom is a bus
> error) that the problem might not be deterministic.
>
> I wonder if building git with:
>
>   make SANITIZE=address,undefined
>
> and running the same test might yield anything useful.
>
> -Peff

> > I wonder if building git with:
> >
> >   make SANITIZE=address,undefined
> >
> > and running the same test might yield anything useful.
> 
> Not sure if this is useful, but this is what I got:

> AddressSanitizer:DEADLYSIGNAL
> =================================================================
> ==155141==ERROR: AddressSanitizer: BUS on unknown address (pc
> 0x78811e863aed bp 0x7ffe9d5ac800 sp 0x7ffe9d5ac770 T0)
> ==155141==The signal is caused by a READ memory access.
> ==155141==Hint: this fault was caused by a dereference of a high value
> address (see register values below).  Disassemble the provided pc to
> learn which register was used.
>     #0 0x78811e863aed in inflate
> (/lib/x86_64-linux-gnu/libz.so.1+0xfaed) (BuildId:
> bbefe2bbdc367b0c3cfbfcf80c579930496fb963)
>     #1 0x563e32ec7e5f in git_inflate /tmp/git_tests/git/zlib.c:118
>     #2 0x563e32bde431 in unpack_loose_header
> /tmp/git_tests/git/object-file.c:1271
>     #3 0x563e32be429c in loose_object_info /tmp/git_tests/git/object-file.c:1474

>     #4 0x563e32be5348 in do_oid_object_info_extended
> /tmp/git_tests/git/object-file.c:1582
>     #5 0x563e32be5dac in oid_object_info_extended
> /tmp/git_tests/git/object-file.c:1640
>     #6 0x563e32be5dac in oid_object_info /tmp/git_tests/git/object-file.c:1656
>     #7 0x563e32bf8b57 in parse_object_with_flags /tmp/git_tests/git/object.c:290

>
> On Mon, Dec 02, 2024 at 07:48:05PM -0700, Dmitriy Panteleyev wrote:
>
> > > I wonder if building git with:
> > >
> > >   make SANITIZE=address,undefined
> > >
> > > and running the same test might yield anything useful.
> >
> > Not sure if this is useful, but this is what I got:
>
> Thanks. If you bisect with that command, does it end up on the same
> commit?

>
> > AddressSanitizer:DEADLYSIGNAL
> > =================================================================
> > ==155141==ERROR: AddressSanitizer: BUS on unknown address (pc
> > 0x78811e863aed bp 0x7ffe9d5ac800 sp 0x7ffe9d5ac770 T0)
> > ==155141==The signal is caused by a READ memory access.
> > ==155141==Hint: this fault was caused by a dereference of a high value
> > address (see register values below).  Disassemble the provided pc to
> > learn which register was used.
> >     #0 0x78811e863aed in inflate
> > (/lib/x86_64-linux-gnu/libz.so.1+0xfaed) (BuildId:
> > bbefe2bbdc367b0c3cfbfcf80c579930496fb963)
> >     #1 0x563e32ec7e5f in git_inflate /tmp/git_tests/git/zlib.c:118
> >     #2 0x563e32bde431 in unpack_loose_header
> > /tmp/git_tests/git/object-file.c:1271
> >     #3 0x563e32be429c in loose_object_info /tmp/git_tests/git/object-file.c:1474
>
> Hmm. So we are inflating a loose object. It's mmap()-ed, so presumably
> that is why you get the bus error (the underlying nfs system for
> whatever reason is not able to provide the bytes).
>
> I'm still super puzzled about why this would start happening, or how it
> could be related to that commit. The rest of the stack here:
>
> >     #4 0x563e32be5348 in do_oid_object_info_extended
> > /tmp/git_tests/git/object-file.c:1582
> >     #5 0x563e32be5dac in oid_object_info_extended
> > /tmp/git_tests/git/object-file.c:1640
> >     #6 0x563e32be5dac in oid_object_info /tmp/git_tests/git/object-file.c:1656
> >     #7 0x563e32bf8b57 in parse_object_with_flags /tmp/git_tests/git/object.c:290
>
> shows that we are coming from parse_object_with_flags(). Is it possible
> that calling stat() somehow primes the nfs system to be better able to
> serve the mmap'd data? That seems kind of weird.
>
> Maybe one other thing to try. Build with:
>
>   make NO_MMAP=1
>
> (optionally with SANITIZE also). That should replace the mmap calls with
> a compat wrapper that just reads into an internal buffer. I suspect that
> will make your problem go away, though I'm not sure it gets us any
> closer to understanding what's going wrong.
>
> What's the nfs server in your setup? Is it another Linux machine, or is
> it some other implementation? Do you know which nfs version?
>
> -Peff

>
> On Wed, Dec 04, 2024 at 07:21:16PM -0700, Dmitriy Panteleyev wrote:
>
> > After trying NO_MMAP=1 with and without SANITIZE, I get:
> > "fatal: mmap failed: Permission denied"
>
> Hmm, that's odd. If you run it under strace, which syscall fails? That
> message should be reporting errno from mmap(), which in NO_MMAP mode
> should be a pread() call. I'm not sure why that would get EACCES if the
> open() call succeeded, but that might explain why the mmap'd version
> gets SIGBUS (I don't know much about NFS, but I imagine that under the
> hood the client is probably issuing reads for individual pages to
> fault in the map).

>
> This issue sounds similar to yours:
>
>   https://unix.stackexchange.com/questions/633389/man-cannot-read-manpage-from-nfs-although-the-file-is-readable
>
> especially the bit where reading the metadata once makes it magically
> work for a brief period (which is the only thing I'd expect the commit
> you found via bisection to have an effect on).
>
> -Peff

> Strace with NO_MMAP=1, I gives:
> 
> openat(AT_FDCWD,
> ".git/objects/34/5819b235838e219d66420b536a54ce4cf0624c",
> O_RDONLY|O_CLOEXEC) = 4
> fstat(4, {st_mode=S_IFREG|0444, st_size=154, ...}) = 0
> pread64(4, 0x61a0292e15d0, 154, 0)      = -1 ESTALE (Stale file handle)
> write(2, "fatal: mmap failed: Permission d"..., 38) = 38
> 
> Weirdly, it's throwing ESTALE not EACCESS...

> Hrm. I just spun up a couple of different VMs on my server with old
> and new NFS versions, and git works fine from those shares.
> 
> I think we should put a pin in it, since I can't reproduce the problem
> outside of my specific server instance.