How we spent two weeks hunting an NFS bug in the Linux kernel

UPDATE 2019-08-06: This bug has now been resolved in the following distributions:

• Red Hat Enterprise Linux 7
• Ubuntu
• Linux mainline: Backported to 4.14-stable and 4.19-stable

On Sep. 14, the GitLab support team escalated a critical problem encountered by one of our customers: GitLab would run fine for a while, but after some time users encountered errors. When attempting to clone certain repositories via Git, users would see an opaque Stale file error message. The error message persisted for a long time, blocking employees from being able to work, unless a system administrator intervened manually by running ls in the directory itself.

Thus launched an investigation into the inner workings of Git and the Network File System (NFS). The investigation uncovered a bug with the Linux v4.0 NFS client and culiminated with a kernel patch that was written by Trond Myklebust and merged in the latest mainline Linux kernel on Oct. 26.

This post describes the journey of investigating the issue and details the thought process and tools by which we tracked down the bug. It was inspired by the fine detective work in How I spent two weeks hunting a memory leak in Ruby by Oleg Dashevskii.

More importantly, this experience exemplifies how open source software debugging has become a team sport that involves expertise across multiple people, companies, and locations. The GitLab motto "everyone can contribute" applies not only to GitLab itself, but also to other open source projects, such as the Linux kernel.

Reproducing the bug

While we have run NFS on GitLab.com for many years, we have stopped using it to access repository data across our application machines. Instead, we have abstracted all Git calls to Gitaly. Still, NFS remains a supported configuration for our customers who manage their own installation of GitLab, but we had never seen the exact problem described by the customer before.

Our customer gave us a few important clues:

1. The full error message read, fatal: Couldn't read ./packed-refs: Stale file handle.
2. The error seemed to start when they started a manual Git garbage collection run via git gc.
3. The error would go away if a system administrator ran ls in the directory.
4. The error also would go away after git gc process ended.

The first two items seemed obviously related. When you push to a branch in Git, Git creates a loose reference, a fancy name for a file that points your branch name to the commit. For example, a push to master will create a file called refs/heads/master in the repository:

$ cat refs/heads/master
2e33a554576d06d9e71bfd6814ee9ba3a7838963

git gc has several jobs, but one of them is to collect these loose references (refs) and bundle them up into a single file called packed-refs. This makes things a bit faster by eliminating the need to read lots of little files in favor of reading one large one. For example, after running git gc, an example packed-refs might look like:

# pack-refs with: peeled fully-peeled sorted
564c3424d6f9175cf5f2d522e10d20d781511bf1 refs/heads/10-8-stable
edb037cbc85225261e8ede5455be4aad771ba3bb refs/heads/11-0-stable
94b9323033693af247128c8648023fe5b53e80f9 refs/heads/11-1-stable
2e33a554576d06d9e71bfd6814ee9ba3a7838963 refs/heads/master

How exactly is this packed-refs file created? To answer that, we ran strace git gc with a loose ref present. Here are the pertinent lines from that:

28705 open("/tmp/libgit2/.git/packed-refs.lock", O_RDWR|O_CREAT|O_EXCL|O_CLOEXEC, 0666) = 3
28705 open(".git/packed-refs", O_RDONLY) = 3
28705 open("/tmp/libgit2/.git/packed-refs.new", O_RDWR|O_CREAT|O_EXCL|O_CLOEXEC, 0666) = 4
28705 rename("/tmp/libgit2/.git/packed-refs.new", "/tmp/libgit2/.git/packed-refs") = 0
28705 unlink("/tmp/libgit2/.git/packed-refs.lock") = 0

The system calls showed that git gc did the following:

1. Open packed-refs.lock. This tells other processes that packed-refs is locked and cannot be changed.
2. Open packed-refs.new.
3. Write loose refs to packed-refs.new.
4. Rename packed-refs.new to packed-refs.
5. Remove packed-refs.lock.
6. Remove loose refs.

The fourth step is the key here: the rename where Git puts packed-refs into action. In addition to collecting loose refs, git gc also performs a more expensive task of scanning for unused objects and removing them. This task can take over an hour for large repositories.

That made us wonder: for a large repository, does git gc keep the file open while it's running this sweep? Looking at the strace logs and probing the process with lsof, we found that it did the following:

Notice that packed-refs is closed only at the end, after the potentially long Garbage collect objects step takes place.

That made us wonder: how does NFS behave when one node has packed-refs open while another renames over that file?

To experiment, we asked the customer to run the following experiment on two different machines (Alice and Bob):

1. On the shared NFS volume, create two files: test1.txt and test2.txt with different contents to make it easy to distinguish them:

   alice $ echo "1 - Old file" > /path/to/nfs/test1.txt
   alice $ echo "2 - New file" > /path/to/nfs/test2.txt
   

2. On machine Alice, keep a file open to test1.txt:

    alice $ irb
    irb(main):001:0> File.open('/path/to/nfs/test1.txt')
   

3. On machine Alice, show the contents of test1.txt continuously:

   alice $ while true; do cat test1.txt; done
   

4. Then on machine Bob, run:

   bob $ mv -f test2.txt test1.txt
   

This last step emulates what git gc does with packed-refs by overwriting the existing file.

On the customer's machine, the result looked something like:

1 - Old file
1 - Old file
1 - Old file
cat: test1.txt: Stale file handle

Bingo! We seemed to reproduce the problem in a controlled way. However, the same experiment using a Linux NFS server did not have this problem. The result was what you would expect: the new contents were picked up after the rename:

1 - Old file
1 - Old file
1 - Old file
2 - New file  <