Troubleshoot clone issue to NFS.

In setting up some new git servers I was trying to test the performance of some NFS mounted volumes and when compared to local disk (although this is a vitualized server so not truly local) cloning to NFS was taking a long time.

Here are some timings:

~ $ time bin/git clone https://github.com/git/git test
Cloning into 'test'...
remote: Counting objects: 185964, done.
remote: Compressing objects: 100% (276/276), done.
remote: Total 185964 (delta 203), reused 32 (delta 32), pack-reused 185656 Receiving objects: 100% (185964/185964), 61.42 MiB | 26.16 MiB/s, done. Resolving deltas: 100% (135454/135454), done.
Checking connectivity... done.

real    0m8.156s
user    0m10.569s
sys     0m3.857s

~ $ time bin/git clone https://github.com/git/git /sami/test Cloning into '/sami/test'...
remote: Counting objects: 185964, done.
remote: Compressing objects: 100% (276/276), done.
remote: Total 185964 (delta 203), reused 32 (delta 32), pack-reused 185656 Receiving objects: 100% (185964/185964), 61.42 MiB | 10.15 MiB/s, done. Resolving deltas: 100% (135454/135454), done.
Checking connectivity... done.
Checking out files: 100% (2795/2795), done.

real    0m58.685s
user    0m12.153s
sys     0m7.619s

So cloning to NFS is 50 seconds slower on average (I've run this a lot over the last few days and it does appear to be consistent and not a network / github connectivity issue). Tests creating files on the NFS with dd didn't show that much difference to the local disk (and were sometimes quicker).

Volume mount differences are:

/dev/mapper/rootvg-homelv on /home type ext4 (rw,nodev)
nfsserver:/vol/sami/repos on /sami type nfs (rw,bg,nfsvers=3,tcp,hard,nointr,timeo=600,rsize=32768,wsize=32768,addr=10.1.1.1)

And there doesn't appear to be any issue with NFS retransmissions:

/sami $ nfsstat
Client rpc stats:

calls      retrans    authrefrsh
11719847   0          11720190

This morning I did some more digging as when I tried this on a newly build server the NFS times were slower than local disk, but only buy around 6-10 seconds. The new server had git 1.7.1 installed on it compared to 2.4.0 on the machine I've been testing on. So I build a number of versions of git to test each one to try and find the point where it changed:

v1.8.0          11.363 s
v1.8.3          13.597 s
v1.8.4          13.958 s
v1.8.4.1                14.563 s
v1.8.4.2                1m 0s
v1.8.4.3                1m 9s
v1.8.4.5                1m 1s

v1.8.5 1m 0s
v1.8.5.6 1m 0s
v1.9.0 1m 38

v2.4.0 58s
v2.4.1 58s

So there appears to be a change in 1.8.4.2 that made this issue appear for me. Looking at the release notes the only thing that I can see that might be related could be:

* When an object is not found after checking the packfiles and then loose object directory, read_sha1_file() re-checks the packfiles to prevent racing with a concurrent repacker; teach the same logic to has_sha1_file().

So the questions are:

1) Should I expect a clone to NFS to be that much slower?
2) Is there anything I could do to speed it up (I've tried --bare as that is what the repositories will be when stored on NFS and there wasn't really a difference).
3) What else can I use in git to compare the performance on local to NFS to see if it is just clones that are affected?
4) I assume I could bisect between 1.8.4.1 and 1.8.4.2 to find exactly where things get worse for me?

Thanks for any help,

Steve

________________________________

This e-mail is for the sole use of the intended recipient and contains information that may be privileged and/or confidential. If you are not an intended recipient, please notify the sender by return e-mail and delete this e-mail and any attachments. Certain required legal entity disclosures can be accessed on our website.<http://thomsonreuters.com/prof_disclosures/>

That would be commit 45e8a74 (has_sha1_file: re-check pack directory before giving up - 2013-08-30). Maybe you can try the version without that commit to confirm. In case an object is not found pack directory is re-read again, which might cause some increased load on nfs. has_sha1_file() not finding the object should not happen often.. Maybe you could do an strace (following forks) on the "git clone" process to see if readdir() is really called a lot?

Duy

That last statement is probably very wrong, but I have no time to test this now. In index-pack, there is a has_sha1_file() for file collision test. That call on a fresh clone would fail for _every_ object in the (new) pack and the cost of reprepare pack files could be sky high...

Duy

On Thu, May 21, 2015a at 9:31 PM, Duy Nguyen [mailto:[email protected]], did scribble:

Confirmed with bisect that it is that commit:

~/git $ git bisect bad 45e8a7487339c0f0ea28244ef06851308d07387c is the first bad commit commit 45e8a7487339c0f0ea28244ef06851308d07387c

Author: Jeff King <[email protected]>
Date:   Fri Aug 30 15:14:13 2013 -0400

I have an strace for that build but it is 153 megabytes so I probably shouldn't attach, but the call summary is below:

% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
93.71 39.670084 103 386835 2171 futex

  3.16    1.338572           7    190550       181 open
  1.56    0.658786          18     37450         3 read
  0.62    0.262740           2    141390           pread
  0.41    0.171526           5     37313         9 write
  0.18    0.076166           0    188859    188835 access
  0.11    0.047941           0    374712           getdents
  0.11    0.045174          11      4067      3910 lstat
  0.06    0.023630           0    190425           close
  0.04    0.017995           6      2975         1 fstat
  0.02    0.007668        1917         4           wait4
  0.01    0.004150           1      5065           madvise
  0.01    0.003548           0     16090         8 recvfrom
  0.00    0.001872           0      8048           select
  0.00    0.001870          11       173         1 mkdir
  0.00    0.000872           0      8055           poll
  0.00    0.000262          22        12        12 readlink
  0.00    0.000185           0      1217      1146 stat
  0.00    0.000158           0       457           mprotect
  0.00    0.000074           0       298           mmap
  0.00    0.000069           1       109         8 rt_sigreturn
  0.00    0.000047           0       159           brk
  0.00    0.000021           1        17           getcwd
  0.00    0.000000           0        42         3 lseek
  0.00    0.000000           0        92           munmap
  0.00    0.000000           0        35           rt_sigaction
  0.00    0.000000           0         9           rt_sigprocmask
  0.00    0.000000           0         8         3 ioctl
  0.00    0.000000           0        11           pipe
  0.00    0.000000           0         3           dup
  0.00    0.000000           0         8           dup2
  0.00    0.000000           0         6           setitimer
  0.00    0.000000           0        11         1 socket
  0.00    0.000000           0         8         7 connect
  0.00    0.000000           0         8           sendto
  0.00    0.000000           0         2           recvmsg
  0.00    0.000000           0         1           bind
  0.00    0.000000           0         1           getsockname
  0.00    0.000000           0         3         1 getpeername
  0.00    0.000000           0         2           setsockopt
  0.00    0.000000           0         2           getsockopt
  0.00    0.000000           0         8           clone
  0.00    0.000000           0         5           execve
  0.00    0.000000           0         3           uname
  0.00    0.000000           0       100           fcntl
  0.00    0.000000           0         2           fsync
  0.00    0.000000           0        13           chdir
  0.00    0.000000           0        14           rename
  0.00    0.000000           0         2           link
  0.00    0.000000           0         5           unlink
  0.00    0.000000           0         2           symlink
  0.00    0.000000           0         9           chmod
  0.00    0.000000           0         6           getrlimit
  0.00    0.000000           0         2           sysinfo
  0.00    0.000000           0         8           getuid
  0.00    0.000000           0         1           statfs
  0.00    0.000000           0         5           arch_prctl
  0.00    0.000000           0         1           gettid
  0.00    0.000000           0         5           set_tid_address
  0.00    0.000000           0        13           set_robust_list

------ ----------- ----------- --------- --------- ----------------
100.00 42.333410 1594736 196300 total

Is there anything else I can provide or test?

Thanks for the help,

Steve

In builtin/index-pack.c, replace the line "collision_test_needed = has_sha1_file(sha1);" with "collision_test_needed = 0;". Security is compromised but for this test it should be ok. Then clone again. I hope the new number gets down close to v1.8.4.1.

Duy

Yeah, I think that is a good starting point. I timed a local clone before and after 45e8a74; there is a small difference on my system (about 5%), but it goes away with your suggestion.

The problem with has_sha1_file() prior to v1.8.4.2 is that it is racy with respect to simultaneous operations; we might claim we do not have an object, when in fact we do. As you noted, usually has_sha1_file() returns true (i.e., we look up objects that we expect to have), and the performance impact is minimal.

But for code paths where _not_ having the object is normal, the impact is much greater. So I think there are two possibilities for improving this:

1. Find places where we expect the object will not exist (like the collision_test check you pointed out) and use a "has_sha1_file_fast" that accepts that it may very occasionally erroneously return false. In this case it would mean potentially skipping a collision check, but I think that is OK. That could have security implications, but only if an attacker:

a. has broken sha1 to generate a colliding object

b. can manipulate the victim into repacking in a loop

c. can manipulate the victim into fetching (or receiving a push)
simultaneously with (b)

at which point they can try to race the repack procedure to add their colliding object to the repository. It seems rather unlikely (especially part a).

2. Make reprepare_packed_git() cheaper in the common case that nothing has changed. It would probably be enough to stat("objects/pack"). We know that packfiles themselves do not change; we may only add or delete them. And since the hierarchy of objects/pack is flat, we know that the mtime on that directory will change if any packs are added or removed.

Of course, we are still doing an extra stat() for each has_sha1_file call. Whether that helps for the NFS case depends on whether stat() is significantly cheaper than opendir/readdir/closedir. On my local disk, the hacky patch below did seem to give me back the 5% lost by 45e8a74 (I did it directly on master, since that old commit does not have the stat_validity infrastructure).

---

index c97d807..17c840c 100644
@@ -1661,6 +1661,7 @@ int sane_execvp(const char *file, char *const argv[]);
  */
 struct stat_validity {
 	struct stat_data *sd;
+	unsigned mode;
 };
 
 void stat_validity_clear(struct stat_validity *sv);

index 36ff89f..1d8702f 100644
@@ -2281,6 +2281,7 @@ void stat_validity_clear(struct stat_validity *sv)
 {
 	free(sv->sd);
 	sv->sd = NULL;
+	sv->mode = 0;
 }
 
 int stat_validity_check(struct stat_validity *sv, const char *path)

@@ -2291,18 +2292,19 @@ int stat_validity_check(struct stat_validity *sv, const char *path)
 		return sv->sd == NULL;
 	if (!sv->sd)
 		return 0;
-	return S_ISREG(st.st_mode) && !match_stat_data(sv->sd, &st);
+	return sv->mode == st.st_mode && !match_stat_data(sv->sd, &st);
 }
 
 void stat_validity_update(struct stat_validity *sv, int fd)
 {
 	struct stat st;
 
-	if (fstat(fd, &st) < 0 || !S_ISREG(st.st_mode))
+	if (fstat(fd, &st) < 0)
 		stat_validity_clear(sv);
 	else {
 		if (!sv->sd)
 			sv->sd = xcalloc(1, sizeof(struct stat_data));
+		sv->mode = st.st_mode;
 		fill_stat_data(sv->sd, &st);
 	}
 }

index ccc6dac..abe1be9 100644
@@ -1225,7 +1225,8 @@ static void report_pack_garbage(struct string_list *list)
 	report_helper(list, seen_bits, first, list->nr);
 }
 
-static void prepare_packed_git_one(char *objdir, int local)
+static void prepare_packed_git_one(char *objdir, int local,
+				   struct stat_validity *validity)
 {
 	struct strbuf path = STRBUF_INIT;
 	size_t dirnamelen;

@@ -1235,6 +1236,12 @@ static void prepare_packed_git_one(char *objdir, int local)
 
 	strbuf_addstr(&path, objdir);
 	strbuf_addstr(&path, "/pack");
+
+	if (stat_validity_check(validity, path.buf)) {
+		strbuf_release(&path);
+		return;
+	}
+
 	dir = opendir(path.buf);
 	if (!dir) {
 		if (errno != ENOENT)

@@ -1243,6 +1250,10 @@ static void prepare_packed_git_one(char *objdir, int local)
 		strbuf_release(&path);
 		return;
 	}
+
+	/* XXX dirfd is a BSD-ism that only made it into POSIX.1-2008 */
+	stat_validity_update(validity, dirfd(dir));
+
 	strbuf_addch(&path, '/');
 	dirnamelen = path.len;
 	while ((de = readdir(dir)) != NULL) {

@@ -1348,15 +1359,17 @@ static void rearrange_packed_git(void)
 static int prepare_packed_git_run_once = 0;
 void prepare_packed_git(void)
 {
+	static struct stat_validity validity;
 	struct alternate_object_database *alt;
 
 	if (prepare_packed_git_run_once)
 		return;
-	prepare_packed_git_one(get_object_directory(), 1);
+	prepare_packed_git_one(get_object_directory(), 1, &validity);
 	prepare_alt_odb();
 	for (alt = alt_odb_list; alt; alt = alt->next) {
 		alt->name[-1] = 0;
-		prepare_packed_git_one(alt->base, 0);
+		/* XXX should carry pack validity struct for each alternate */
+		prepare_packed_git_one(alt->base, 0, NULL);
 		alt->name[-1] = '/';
 	}
 	rearrange_packed_git();

On Friday, May 22, 2015 @ 8:12 AM Jeff King did scribble:

Tested this change on a couple of versions, first of all on the revision where things go wrong for me:

~ $ bin/git --version
git version 1.8.4.1.g45e8a74.dirty

~ $ time bin/git clone https://github.com/git/git test <snip>

real    0m7.105s
user    0m9.566s
sys     0m0.989s

~ $ time bin/git clone https://github.com/git/git /sami/test <snip>

real    0m14.411s
user    0m9.703s
sys     0m1.374s

This is more in line with what I see normally. Also tested on master:

~ $ bin/git --version
git version 2.4.1.217.g6c1249c.dirty

~ $ time bin/git clone https://github.com/git/git test <snip>

real    0m5.946s
user    0m9.111s
sys     0m1.332s

~ $ time bin/git clone https://github.com/git/git /sami/test <snip>

real    0m12.344s
user    0m9.187s
sys     0m1.579s

So similar on the latest as well.

Also tested master with the patch provided:

~ $ bin/git --version
git version 2.4.1.217.g6c1249c.dirty

~ $ time git clone https://github.com/git/git test

real    0m8.263s
user    0m10.550s
sys     0m3.763s

~ $ time git clone https://github.com/git/git /sami/test

real    1m3.286s
user    0m12.149s
sys     0m9.192s

So the patch isn't reducing the time taken when cloning to NAS.

Here are the top calls from strace

% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
90.68 19.946171 46 437398 45436 futex

  4.63    1.017637          22     46141         5 read
  2.37    0.521161           4    141429           pread
  0.73    0.161442           3     47130         9 write
  0.42    0.093146           0    188645    188621 access
  0.38    0.083033          26      3209       181 open
  0.32    0.069587           0    188613      1146 stat
  0.23    0.050855          12      4082      3925 lstat
  0.11    0.023317           8      2979         1 fstat
  0.04    0.009134           0     35696         3 recvfrom
  0.03    0.007666        1917         4           wait4
  0.02    0.004478           1      3923           madvise
  0.01    0.002291           0     17858           poll
  0.01    0.002155           0     17851           select

Thanks for looking into this.

Steve

Strange. Maybe there is something else... Anyway some numbers from me. This is nfs3 hosted by Raspberry Pi, accessed over wireless. I just run index-pack on git.git pack instead of full clone.

- v1.8.4.1 34s
- v1.8.4.2 519s (oh.. wireless..)
- v1.8.4.2 without has_sha1_file() in index-pack.c 33s
- v1.8.4.2 + Jeff's mtime patch 36s

Duy

On Friday, May 22, 2015 @ 11:06 AM Duy Nguyen did write:

Just ran the test again and it was 12 seconds. Too many versions of git available on the
machine and I think I might have run the wrong one:

~ $ time bin/git clone https://github.com/git/git test Cloning into 'test'...
remote: Counting objects: 186015, done.
remote: Compressing objects: 100% (8/8), done.
remote: Total 186015 (delta 8), reused 7 (delta 7), pack-reused 186000 Receiving objects: 100% (186015/186015), 61.33 MiB | 30.35 MiB/s, done. Resolving deltas: 100% (135512/135512), done.
Checking connectivity... done.

real    0m6.931s
user    0m10.011s
sys     0m2.685s

~ $ time bin/git clone https://github.com/git/git /sami/test Cloning into '/sami/test'...
remote: Counting objects: 186015, done.
remote: Compressing objects: 100% (8/8), done.
remote: Total 186015 (delta 8), reused 7 (delta 7), pack-reused 186000 Receiving objects: 100% (186015/186015), 61.33 MiB | 29.91 MiB/s, done. Resolving deltas: 100% (135512/135512), done.
Checking connectivity... done.
Checking out files: 100% (2795/2795), done.

real    0m13.169s
user    0m9.961s
sys     0m3.480s

So I would say that was in line with the timings for the other versions I have tested.

And looking back at the email from the morning I did run the wrong bin/git. Sorry, totally my fault on that.

If I can test anything else then let me know.

Thanks,

Steve
--

Thanks for re-checking. Here's a series that fixes the rough edges of the patch I sent earlier. I'd appreciate it if you can re-confirm that it improves things for you.

[1/3]: stat_validity: handle non-regular files
[2/3]: cache.h: move stat_validity definition up
[3/3]: prepare_packed_git: use stat_validity to avoid re-reading packs

I'm adding Michael to the cc, as I'm abusing the stat_validity code which we worked on in 2013.

My big concern here is that using stat_validity with a directory is racy. It works for a regular file like packed-refs because that file is replaced atomically. We fill the validity using fstat() on the same descriptor we read the data from, and nobody modifies an already-written file. So we know it matches what we read.

For a directory, I don't think that atomicity guarantee is there. Somebody can modify the direct while we're reading. For the most part, I think that is OK. We fstat() before reading any entries, so our fstat data will then become out of date, and we'll re-read next time. It would be a problem if opendir() looked at the entries at all (e.g., if it called getdents() under Linux before our first readdir() call, then our fstat is happening after the first read, and wouldn't match what we read). I don't have any reason to believe that any libc does that, but it is making an assumption about how opendir() is implemented.

The other problem is that I'm not sure stat data is enough to notice when a directory changes. Certainly the mtime should change, but if you have only one-second resolution on your mtimes, we can be fooled. For a regular file that is replaced atomically, the inode will change (and probably the size, too). But I don't know if that is the case for a directory. Can writing an entry go undetected between two stat() calls (or something even more pathological, like deleting one entry and writing another one)?

-Peff

The stat_validity code was originally written to avoid re-reading the packed-refs file when it has not changed. It makes sure that the file continues to match S_ISREG() when we check it.

However, we can use the same concept on a directory to see whether it has been modified. Even though we still have to touch the filesystem to do the stat, this can provide a speedup even over opendir/readdir/closedir, especially on high-latency filesystems like NFS.

This patch adds a "mode" field to stat_validity, which lets us check that the mode has stayed the same (rather than explicitly checking that it is a regular file).

As a bonus cleanup, we can stop allocating the embedded "stat_data" on the heap. Prior to this patch, we needed to represent the case where the file did not exist, and we used "sv->sd == NULL" for that. Now we can simply check that "sv->mode" is 0.

---
 cache.h      |  3 ++-
 read-cache.c | 16 ++++++----------
 2 files changed, 8 insertions(+), 11 deletions(-)

index c97d807..2941e7e 100644
@@ -1660,7 +1660,8 @@ int sane_execvp(const char *file, char *const argv[]);
  * for the index.
  */
 struct stat_validity {
-	struct stat_data *sd;
+	struct stat_data sd;
+	unsigned mode;
 };
 
 void stat_validity_clear(struct stat_validity *sv);

index 36ff89f..115b000 100644
@@ -2279,8 +2279,7 @@ void *read_blob_data_from_index(struct index_state *istate, const char *path, un
 
 void stat_validity_clear(struct stat_validity *sv)
 {
-	free(sv->sd);
-	sv->sd = NULL;
+	memset(sv, 0, sizeof(*sv));
 }
 
 int stat_validity_check(struct stat_validity *sv, const char *path)

@@ -2288,21 +2287,18 @@ int stat_validity_check(struct stat_validity *sv, const char *path)
 	struct stat st;
 
 	if (stat(path, &st) < 0)
-		return sv->sd == NULL;
-	if (!sv->sd)
-		return 0;
-	return S_ISREG(st.st_mode) && !match_stat_data(sv->sd, &st);
+		return sv->mode == 0;
+	return sv->mode == st.st_mode && !match_stat_data(&sv->sd, &st);
 }
 
 void stat_validity_update(struct stat_validity *sv, int fd)
 {
 	struct stat st;
 
-	if (fstat(fd, &st) < 0 || !S_ISREG(st.st_mode))
+	if (fstat(fd, &st) < 0)
 		stat_validity_clear(sv);
 	else {
-		if (!sv->sd)
-			sv->sd = xcalloc(1, sizeof(struct stat_data));
-		fill_stat_data(sv->sd, &st);
+		sv->mode = st.st_mode;
+		fill_stat_data(&sv->sd, &st);
 	}
 }

2.4.1.538.g69ac333

I don't have any insight about whether mtimes are reliable change indicators for directories.

But if you make this change, you are changing the contract of the stat_validity functions:

* Have you verified that no callers rely on the old stat_validity's check that the file is a regular file?

* The docstrings in cache.h need to be updated.

Otherwise, looks OK.

Michael

Michael Haggerty
[email protected]

I think they are OK if a directory appears (they notice the error in reading and call stat_validity_clear to throw away the result). But it would be a problem, I suppose, if you put a FIFO or something into $GIT_DIR/packed-refs. OTOH, that would suffer from the stat data changing constantly, so we would fall back to safe behavior.

I don't know how careful we want to be. I guess the conservative choice would be to barf if it's not a file or directory, both of which can be handled pretty sanely.

Thanks, will fix if I re-roll (I'm still not convinced this is a robust thing to be doing overall).

I'd rather not. stat_data is shared with the cache_entry code, which holds the mode separately. I'd like to avoid impacting the index code at all.

Yeah, I considered that. My feeling is that testing _more_ information is probably OK. Even if there is extra data there, it presumably doesn't change from call to call of stat() unless the directory changes. And if we are wrong, we fail safely (e.g., if the permissions change we don't technically need to re-read the pack directory, but it is OK to do so).

-Peff

It would be nice to embed stat_validity structs inside other structs defined in cache.h. We cannot get away with a forward declaration, because using it in a struct definition means the compiler needs the real size.

---
 cache.h | 56 ++++++++++++++++++++++++++++----------------------------
 1 file changed, 28 insertions(+), 28 deletions(-)

index 2941e7e..cdd279a 100644
@@ -1185,6 +1185,34 @@ extern int has_dirs_only_path(const char *name, int len, int prefix_len);
 extern void schedule_dir_for_removal(const char *name, int len);
 extern void remove_scheduled_dirs(void);
 
+/*
+ * A struct to encapsulate the concept of whether a file has changed
+ * since we last checked it. This uses criteria similar to those used
+ * for the index.
+ */
+struct stat_validity {
+	struct stat_data sd;
+	unsigned mode;
+};
+
+void stat_validity_clear(struct stat_validity *sv);
+
+/*
+ * Returns 1 if the path is a regular file (or a symlink to a regular
+ * file) and matches the saved stat_validity, 0 otherwise.  A missing
+ * or inaccessible file is considered a match if the struct was just
+ * initialized, or if the previous update found an inaccessible file.
+ */
+int stat_validity_check(struct stat_validity *sv, const char *path);
+
+/*
+ * Update the stat_validity from a file opened at descriptor fd. If
+ * the file is missing, inaccessible, or not a regular file, then
+ * future calls to stat_validity_check will match iff one of those
+ * conditions continues to be true.
+ */
+void stat_validity_update(struct stat_validity *sv, int fd);
+
 extern struct alternate_object_database {
 	struct alternate_object_database *next;
 	char *name;

@@ -1654,34 +1682,6 @@ int checkout_fast_forward(const unsigned char *from,
 
 int sane_execvp(const char *file, char *const argv[]);
 
-/*
- * A struct to encapsulate the concept of whether a file has changed
- * since we last checked it. This uses criteria similar to those used
- * for the index.
- */
-struct stat_validity {
-	struct stat_data sd;
-	unsigned mode;
-};
-
-void stat_validity_clear(struct stat_validity *sv);
-
-/*
- * Returns 1 if the path is a regular file (or a symlink to a regular
- * file) and matches the saved stat_validity, 0 otherwise.  A missing
- * or inaccessible file is considered a match if the struct was just
- * initialized, or if the previous update found an inaccessible file.
- */
-int stat_validity_check(struct stat_validity *sv, const char *path);
-
-/*
- * Update the stat_validity from a file opened at descriptor fd. If
- * the file is missing, inaccessible, or not a regular file, then
- * future calls to stat_validity_check will match iff one of those
- * conditions continues to be true.
- */
-void stat_validity_update(struct stat_validity *sv, int fd);
-
 int versioncmp(const char *s1, const char *s2);
 
 #endif /* CACHE_H */

2.4.1.538.g69ac333

When we try to read an object and fail, we call reprepare_packed_git() to re-scan the list of packfiles. This catches any "racy" cases in which somebody is repacking or making new objects. The performance implications of re-scanning the pack directory are not usually a big deal, because failing to find an object is the unlikely case; we typically die if the re-scan does not help.

Since 45e8a74 (has_sha1_file: re-check pack directory before giving up, 2013-08-30), we do the same thing for has_sha1_file. Some calls to has_sha1_file are in the same
boat: they expect most calls to return true. But some sites, such as the collision test in index-pack.c, may make a large number of calls, most of which they expect to be false. On a local system, this can cause a performance slowdown of around 5%. But on a system with high-latency system calls (like NFS), it can be much worse.

Since the common case is that the pack directory has _not_ changed, we can improve the performance by using stat() before doing the opendir()/readdir()/closedir() to re-scan the directory. It's valid to check stat() for just the single "objects/pack" directory because:

1. We know that packfiles themselves are not changed in place; only new files are written, which would update the mtime of the directory.

2. There are no subdirectories inside the pack directory. Checking the single top-level directory can tell us whether anything changed.

---
I'm not sure what we want to do for the case where we don't have DIRFD. We have to separately open the directory, but I'm not sure if regular open() is even valid on a regular directory on all systems. We could just skip the stat_validity entirely in that case.

 cache.h           |  1 +
 git-compat-util.h |  4 ++++
 sha1_file.c       | 27 ++++++++++++++++++++++++---
 3 files changed, 29 insertions(+), 3 deletions(-)

index cdd279a..9c34a17 100644
@@ -1216,6 +1216,7 @@ void stat_validity_update(struct stat_validity *sv, int fd);
 extern struct alternate_object_database {
 	struct alternate_object_database *next;
 	char *name;
+	struct stat_validity pack_validity;
 	char base[FLEX_ARRAY]; /* more */
 } *alt_odb_list;
 extern void prepare_alt_odb(void);

index b7a97fb..8631e75 100644
@@ -941,4 +941,8 @@ struct tm *git_gmtime_r(const time_t *, struct tm *);
 #define getc_unlocked(fh) getc(fh)
 #endif
 
+#if _POSIX_VERSION >= 200809L
+#define HAVE_DIRFD
+#endif
+
 #endif

index ccc6dac..0e77838 100644
@@ -1225,7 +1225,8 @@ static void report_pack_garbage(struct string_list *list)
 	report_helper(list, seen_bits, first, list->nr);
 }
 
-static void prepare_packed_git_one(char *objdir, int local)
+static void prepare_packed_git_one(char *objdir, int local,
+				   struct stat_validity *validity)
 {
 	struct strbuf path = STRBUF_INIT;
 	size_t dirnamelen;

@@ -1235,6 +1236,12 @@ static void prepare_packed_git_one(char *objdir, int local)
 
 	strbuf_addstr(&path, objdir);
 	strbuf_addstr(&path, "/pack");
+
+	if (stat_validity_check(validity, path.buf)) {
+		strbuf_release(&path);
+		return;
+	}
+
 	dir = opendir(path.buf);
 	if (!dir) {
 		if (errno != ENOENT)

@@ -1243,6 +1250,19 @@ static void prepare_packed_git_one(char *objdir, int local)
 		strbuf_release(&path);
 		return;
 	}
+
+#ifdef HAVE_DIRFD
+	stat_validity_update(validity, dirfd(dir));
+#else
+	{
+		int fd = open(path.buf, O_RDONLY);
+		if (fd >= 0) {
+			stat_validity_update(validity, fd);
+			close(fd);
+		}
+	}
+#endif
+
 	strbuf_addch(&path, '/');
 	dirnamelen = path.len;
 	while ((de = readdir(dir)) != NULL) {

@@ -1348,15 +1368,16 @@ static void rearrange_packed_git(void)
 static int prepare_packed_git_run_once = 0;
 void prepare_packed_git(void)
 {
+	static struct stat_validity validity;
 	struct alternate_object_database *alt;
 
 	if (prepare_packed_git_run_once)
 		return;
-	prepare_packed_git_one(get_object_directory(), 1);
+	prepare_packed_git_one(get_object_directory(), 1, &validity);
 	prepare_alt_odb();
 	for (alt = alt_odb_list; alt; alt = alt->next) {
 		alt->name[-1] = 0;
-		prepare_packed_git_one(alt->base, 0);
+		prepare_packed_git_one(alt->base, 0, &alt->pack_validity);
 		alt->name[-1] = '/';
 	}
 	rearrange_packed_git();

2.4.1.538.g69ac333

mtime may or may not change. I based my untracked-cache series entirely on this directory mtime and did some research about it. For UNIXy filesystems on UNIXy OSes, mtime should work as you expect. FAT on Windows does not (but FAT on Linux does..). NTFS works fine according to some MS document. No idea about CIFS. But people often just do open operation of a time and this racy is not an issue. It is only an issue on the busy server side, and you can make sure you run on the right fs+OS.

Duy

Very bad proof reading. This should read "But people often do one operation at a time.."

Duy

Even on Linux+ext4, I think there is some raciness.

For instance, the program at the end of this mail will loop forever, running "stat" on an open directory fd, then enumerating the entries in the directory. If we ever get the same stat data as the last iteration but different contents, then it complains. If you run it alongside something simple, like touching 10,000 files in the directory, it fails pretty quickly.

This is because we have no atomicity guarantees with directories. We can stat() them, and then while we are reading them, somebody else can be changing the entries. Whether we see the "before" or "after" state depends on the timing.

I'm not 100% sure this translates into real-world problems for packfiles. If you notice that an object is missing and re-scan the pack directory (stat-ing it during the re-scan), then the change that made the object go missing must have happened _before_ the stat, and would presumably be reflected in it (modulo mtime resolution issues). But I haven't thought that hard about it yet, and I have a nagging feeling that there will be problem cases.

It might be that you could get an "atomic" read of the directory by doing a stat before and after and making sure they're the same (and if not, repeating the readdir() calls). But I think that suffers from the same mtime-resolution problems.

Linux+ext4 _does_ have nanosecond mtimes, which perhaps is enough to assume that any change will be reflected.

I dunno. I guess the most interesting test would be something closer to the real world: one process repeatedly making sure the object pointed to by "master" exists, and another one constantly rewriting "master" and then repacking the object.

-- >8 --
#include "cache.h"
#include "string-list.h"

static void get_data(const char *path, struct string_list *entries,
struct stat_validity *validity)

{
	DIR *dir = opendir(path);
	struct dirent *de;

	stat_validity_update(validity, dirfd(dir));
	while ((de = readdir(dir)))
		string_list_insert(entries, de->d_name);
	closedir(dir);
}

static int list_eq(const struct string_list *a,
const struct string_list *b)

{
	int i;

	if (a->nr != b->nr)
		return 0;
	for (i = 0; i < a->nr; i++)
		if (strcmp(a->items[i].string, b->items[i].string))
			return 0;
	return 1;
}

static void monitor(const char *path)

{
	struct string_list last_entries = STRING_LIST_INIT_DUP;
	struct stat_validity last_validity;

	get_data(path, &last_entries, &last_validity);
	while (1) {
		struct string_list cur_entries = STRING_LIST_INIT_DUP;
		struct stat_validity cur_validity;

		get_data(path, &cur_entries, &cur_validity);
		if (!memcmp(&last_validity, &cur_validity, sizeof(last_validity)) &&
		    !list_eq(&cur_entries, &last_entries))
			die("mismatch");

		string_list_clear(&last_entries, 0);
		memcpy(&last_entries, &cur_entries, sizeof(last_entries));
		stat_validity_clear(&last_validity);
		memcpy(&last_validity, &cur_validity, sizeof(last_validity));
	}
}

int main(int argc, const char **argv)

{
	monitor(*++argv);
	return 0;
}

So the checkout codepath to touch working tree is one difference? Are there other differences?

In case you want to back away from option 2 because it starts to leak raciness, which your old commit tried to fix in the first place. I think the only other place that tests for lots of non-existent loose objects is write_sha1_file (e.g. "tar -xf bigtarball.tar.gz; cd bigtarball; git init; git add ."). But the number of calls should be much smaller compared to index-pack and it does not use has_sha1_file, it uses check_and_freshen_file() instead.

There are other places where has_sha1_file() may return 0, but I think the number of calls is even smaller to bother (shallow.c, fetch-pack.c, apply.c, buik-checkin.c)

Duy

On Sunday, May 24, 2015 @ 10:01 AM Duy Nguyen [mailto:[email protected]] did scribble:

Any updates / further thoughts on this?

Thanks,

Steve

Sorry, I haven't had a chance to look at it further. It still on my todo list. My plan is:

1. Devise some torture to tests to see whether my patch series is in fact racy on Linux.

2. Assuming it is, scrap it and make a has_sha1_file_quick() which might sometimes return a false negative (if somebody else is repacking). Use that in index-pack (and possibly other places, but we can start with index-pack).

If we skip step 1 out of pessimism (which I think is a reasonable thing to do), then step 2 should not be all that much work. I'm going to be offline for a few days, though, so I won't get to it until next week at the earliest. If you (or someone else) wants to take a stab at it, please feel free.

-Peff

Actually, it really is a tiny bit of work. I knocked this out in less than 10 minutes. It passes the test suite, but it's entirely possible that I did something boneheaded that does not fix your problem. ;)

Please test and confirm that it makes things better on your system.

-- >8 --
Subject: [PATCH] index-pack: avoid excessive re-reading of pack directory

Since 45e8a74 (has_sha1_file: re-check pack directory before giving up, 2013-08-30), we spend extra effort for has_sha1_file to give the right answer when somebody else is repacking. Usually this effort does not matter, because after finding that the object does not exist, the next step is usually to die().

However, some code paths make a large number of has_sha1_file checks which are _not_ expected to return 1. The collision test in index-pack.c is such a case. On a local system, this can cause a performance slowdown of around 5%. But on a system with high-latency system calls (like NFS), it can be much worse.

This patch introduces a "quick" flag to has_sha1_file which callers can use when they would prefer high performance at the cost of false negatives during repacks. There may be other code paths that can use this, but the index-pack one is the most obviously critical, so we'll start with switching that one.

---
 builtin/index-pack.c |  2 +-
 cache.h              | 11 ++++++++++-
 sha1_file.c          |  4 +++-
 3 files changed, 14 insertions(+), 3 deletions(-)

index 7ea2020..0761dfd 100644
@@ -784,7 +784,7 @@ static void sha1_object(const void *data, struct object_entry *obj_entry,
 	assert(data || obj_entry);
 
 	read_lock();
-	collision_test_needed = has_sha1_file(sha1);
+	collision_test_needed = has_sha1_file_with_flags(sha1, HAS_SHA1_QUICK);
 	read_unlock();
 
 	if (collision_test_needed && !data) {

index 571c98f..98edc2c 100644
@@ -943,8 +943,17 @@ extern int has_sha1_pack(const unsigned char *sha1);
  * Return true iff we have an object named sha1, whether local or in
  * an alternate object database, and whether packed or loose.  This
  * function does not respect replace references.
+ *
+ * If the QUICK flag is set, do not re-check the pack directory
+ * when we cannot find the object (this means we may give a false
+ * negative answer if another process is simultaneously repacking).
  */
-extern int has_sha1_file(const unsigned char *sha1);
+#define HAS_SHA1_QUICK 0x1
+extern int has_sha1_file_with_flags(const unsigned char *sha1, int flags);
+static inline int has_sha1_file(const unsigned char *sha1)
+{
+	return has_sha1_file_with_flags(sha1, 0);
+}
 
 /*
  * Return true iff an alternate object database has a loose object

index 7e38148..dc8746b 100644
@@ -3161,7 +3161,7 @@ int has_sha1_pack(const unsigned char *sha1)
 	return find_pack_entry(sha1, &e);
 }
 
-int has_sha1_file(const unsigned char *sha1)
+int has_sha1_file_with_flags(const unsigned char *sha1, int flags)
 {
 	struct pack_entry e;
 

@@ -3169,6 +3169,8 @@ int has_sha1_file(const unsigned char *sha1)
 		return 1;
 	if (has_loose_object(sha1))
 		return 1;
+	if (flags & HAS_SHA1_QUICK)
+		return 0;
 	reprepare_packed_git();
 	return find_pack_entry(sha1, &e);
 }

2.4.2.752.geeb594a

I tested this on my system, and confirmed that for a "git clone --no-local --bare git.git":

1. It cuts the number of openat/getdents/close syscalls by several orders of magnitude.

2. The overall time drops from ~11.4s to ~10.5s. I suppose if I timed only the index-pack process, it would be even higher (as a percentage improvement).

So I expect it should fix the problem on your NFS system.

Here's the patch again. Same as before, but I'm cc-ing Junio, as I think it is good to apply.

-- >8 --
Subject: index-pack: avoid excessive re-reading of pack directory

Since 45e8a74 (has_sha1_file: re-check pack directory before giving up, 2013-08-30), we spend extra effort for has_sha1_file to give the right answer when somebody else is repacking. Usually this effort does not matter, because after finding that the object does not exist, the next step is usually to die().

However, some code paths make a large number of has_sha1_file checks which are _not_ expected to return 1. The collision test in index-pack.c is such a case. On a local system, this can cause a performance slowdown of around 5%. But on a system with high-latency system calls (like NFS), it can be much worse.

This patch introduces a "quick" flag to has_sha1_file which callers can use when they would prefer high performance at the cost of false negatives during repacks. There may be other code paths that can use this, but the index-pack one is the most obviously critical, so we'll start with switching that one.

---
 builtin/index-pack.c |  2 +-
 cache.h              | 11 ++++++++++-
 sha1_file.c          |  4 +++-
 3 files changed, 14 insertions(+), 3 deletions(-)

index 7ea2020..0761dfd 100644
@@ -784,7 +784,7 @@ static void sha1_object(const void *data, struct object_entry *obj_entry,
 	assert(data || obj_entry);
 
 	read_lock();
-	collision_test_needed = has_sha1_file(sha1);
+	collision_test_needed = has_sha1_file_with_flags(sha1, HAS_SHA1_QUICK);
 	read_unlock();
 
 	if (collision_test_needed && !data) {

index 571c98f..98edc2c 100644
@@ -943,8 +943,17 @@ extern int has_sha1_pack(const unsigned char *sha1);
  * Return true iff we have an object named sha1, whether local or in
  * an alternate object database, and whether packed or loose.  This
  * function does not respect replace references.
+ *
+ * If the QUICK flag is set, do not re-check the pack directory
+ * when we cannot find the object (this means we may give a false
+ * negative answer if another process is simultaneously repacking).
  */
-extern int has_sha1_file(const unsigned char *sha1);
+#define HAS_SHA1_QUICK 0x1
+extern int has_sha1_file_with_flags(const unsigned char *sha1, int flags);
+static inline int has_sha1_file(const unsigned char *sha1)
+{
+	return has_sha1_file_with_flags(sha1, 0);
+}
 
 /*
  * Return true iff an alternate object database has a loose object

index 7e38148..dc8746b 100644
@@ -3161,7 +3161,7 @@ int has_sha1_pack(const unsigned char *sha1)
 	return find_pack_entry(sha1, &e);
 }
 
-int has_sha1_file(const unsigned char *sha1)
+int has_sha1_file_with_flags(const unsigned char *sha1, int flags)
 {
 	struct pack_entry e;
 

@@ -3169,6 +3169,8 @@ int has_sha1_file(const unsigned char *sha1)
 		return 1;
 	if (has_loose_object(sha1))
 		return 1;
+	if (flags & HAS_SHA1_QUICK)
+		return 0;
 	reprepare_packed_git();
 	return find_pack_entry(sha1, &e);
 }

2.4.2.752.geeb594a

Just for fun, I did a "git pack-objects --all --stdout" from linux.git, and then timed "git index-pack --stdin" on it in an empty repo. With a configured alternate pointing to another empty repo, just to make it more unfair. And then I stored it all on a ramdisk to emphasize the cost of the syscalls versus hitting the disk. The numbers I got were:

[before]

  real    2m13.093s
  user    3m31.884s
  sys     0m55.208s

[after]

  real    1m40.389s
  user    3m10.776s
  sys     0m26.012s

That's sort of a ridiculous test, but it does show that this was having some impact even on "normal" systems without insane syscall latencies.

-Peff

Hilarious. We did this in JGit back in ... uhm before 2009. :)

But its Java. So of course we had to do optimizations.

This is actually how Git did it up until v1.8.4.2, in 2013. I changed it then because the old way was racy (and git could flakily report refs as broken and skip them during repacks!).

If you are doing it the "quick" way everywhere in JGit, you may want to reexamine the possibility for races. :)

Yeah, I thought about that while writing this. It would be a win as long as you have a small number of loose objects and were going to make a large number of requests (otherwise you are traversing even though nobody is going to look it up). According to perf, though, loose object lookups are not a large expenditure[1].

I'm also hesitant to go that route because it's basically caching, which introduces new opportunities for race conditions when the cache is stale (we do the same thing with loose refs, and we have indeed run into races there).

-Peff

[1] As measured mostly by __d_lookup_rcu calls. Of course, my patch gives a 5% improvement over the original, and we were not spending 5% of the time there originally. I suspect part of the problem is that we do the lookup under a lock, so the longer we spend there, the more contention we have between threads, and the less parallelism. Indeed, I just did a quick repeat of my tests with pack.threads=1, and the size of the improvement shrinks.

I was expecting this :D

Watchman may help avoid races _with_ caching. But we need to support both ways in that case, falling back to normal file poking when watchman gives up, or when we're on Windows. Extra work needs big enough performance gain to justify. I haven't seen that gain yet.

Duy

Correct, fortunately we are not this naive.

JGit always does the reprepare_packed_git() + retry search on a miss.

But we have a code path to bypass that inside critical loops like our equivalent of index-pack pulling off the wire. We snapshot the object tree at the start of the operation before we read in the pack header, and then require that the incoming pack be completed with that snapshot. Since the snapshot was taking after ref negotiation/advertisement, we should be at least as current as the refs that were exchanged on the wire.

Interesting. We were getting hurt by this in JGit. For most repositories it was cheaper to issue 256 readdir() and build a set of SHA-1s we found. I think we even just hit every directory 00..ff, we don't even bother with a readdir() on the $GIT_DIR/objects itself.

Yes. But see above, we do this only after we snapshot the packs, and only after the ref negotiation, and only for the duration of parsing the pack off the wire. So we should never have a data race.

Since JGit is multi-threaded, this cache is also effectively a thread-local. Its never shared across threads.

Interesting. Yea, fine-grained locking can hurt parallel execution... :(

On Friday, June 05, 2015 @ 1:18 PM Jeff King [mailto:[email protected]] did scribble:

I've been off myself and wanted to make sure I hadn't missed anything in the email threads while I was away as there we rather a lot of them.

Not feeling confident enough to make the changes myself at the moment. I think what you are saying is that has_sha1_file_quick() would be the version from before your change in 45e8a74. And then use that, but I could be barking up the wrong tree completely.

Thanks,

Steve

I do not know that we needed further convincing that the patch series to stat() the objects/pack directory was flaky, but just as an extra data point in case somebody tries this approach later: it is indeed flaky.

I've been running with it for a week or so, and I noticed that a simple clone of a small repository fails racily:

  $ git clone --bare --no-local . foo.git
  Cloning into bare repository 'child.git'...
  remote: Counting objects: 210, done.
  remote: Compressing objects: 100% (98/98), done.
  remote: Total 210 (delta 99), reused 210 (delta 99)
  Receiving objects: 100% (210/210), 68.00 KiB | 0 bytes/s, done.
  Resolving deltas: 100% (99/99), done.
  Checking connectivity... done.
  error: internal error: refs/heads/master is not a valid packed reference!

Sometimes it works, and sometimes not. It looks like we're failing to re-scan the pack directory when we should (presumably because the open() and readdir() operations are not atomic).

-Peff

On Thu, May 21, 2015 at 3:13 PM, <[email protected]> wrote:

[...]

Yeah, it would be very nice if you could bisect further. You can probably do it automatically using a script such as the one Junio used in this email:

http://thread.gmane.org/gmane.comp.version-control.git/45195/

Thanks,
Christian.