Skip to contentSkip to conversation

FSMonitor Preliminary Commits

PATCH Superseded Jeff Hostetler via GitGitGadget 4 participants 30 messages Feb 1, 2021 – Feb 17, 2021

lore
Share & tools
lore
#0 lore raw

cover FSMonitor Preliminary Commits

This patch series fixes runtime errors in t/perf/p7519 on Windows and MacOS. It adds Trace2 logging to p7519 to make it easier to compare results when Watchman is enabled and disabled. And finally, it adds some Trace2 regions and data events around our usage of Watchman and the existing FSMonitor framework.

This series is independent of the "Simple IPC" series.

A future series to add a builtin FSMonitor daemon will build upon both of these series.

Jeff Hostetler (10):
p7519: use xargs -0 rather than -d in test
p7519: fix watchman watch-list test on Windows
p7519: move watchman cleanup earlier in the test
p7519: add trace logging during perf test
preload-index: log the number of lstat calls to trace2
read-cache: log the number of lstat calls to trace2
read-cache: log the number of scanned files to trace2
fsmonitor: log invocation of FSMonitor hook to trace2
fsmonitor: log FSMN token when reading and writing the index
fsmonitor: refactor initialization of fsmonitor_last_update token

Kevin Willford (1):
fsmonitor: allow all entries for a folder to be invalidated

 fsmonitor.c               | 107 ++++++++++++++++++++++++++++++++++----
 fsmonitor.h               |   5 ++
 preload-index.c           |  10 ++++
 read-cache.c              |  24 +++++++--
 t/perf/.gitignore         |   1 +
 t/perf/Makefile           |   4 +-
 t/perf/p7519-fsmonitor.sh |  61 ++++++++++++++++++----
 7 files changed, 186 insertions(+), 26 deletions(-)

base-commit: 71ca53e8125e36efbda17293c50027d31681a41f
Published-As: https://github.com/gitgitgadget/git/releases/tag/pr-860%2Fjeffhostetler%2Ffsmonitor-prework-v1
Fetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-860/jeffhostetler/fsmonitor-prework-v1
Pull-Request: https://github.com/gitgitgadget/git/pull/860

Signature · 1 line
gitgitgadget
#1 lore raw

PATCH 1/11 p7519: use xargs -0 rather than -d in test

From: Jeff Hostetler <[email protected]>

The Mac version of xargs does not support the "-d" option. Convert the test setup to pipe the data set thru lf_to_nul | xargs -0 instead.

---
 t/perf/p7519-fsmonitor.sh | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)
t/perf/p7519-fsmonitor.sh +1 -1
index 9b43342806b..7bb37e9a6c1 100755
@@ -165,7 +165,7 @@ test_fsmonitor_suite() {
 	'
 
 	test_perf_w_drop_caches "status (dirty) ($DESC)" '
-		git ls-files | head -100000 | xargs -d "\n" touch -h &&
+		git ls-files | head -100000 | lf_to_nul | xargs -0 touch -h &&
 		git status
 	'
 
Signature · 1 line
gitgitgadget
#2 lore raw

Re: [PATCH 01/11] p7519: use xargs -0 rather than -d in test

Quoted 4 lines · Jeff Hostetler via GitGitGadget

From: Jeff Hostetler <[email protected]>

The Mac version of xargs does not support the "-d" option. Convert the test setup to pipe the data set thru lf_to_nul | xargs -0 instead.

"xargs -0" is not all that portable, either, and neither is "touch -h".

But since the t/perf stuff already depends on having GNU toolchain anyway, I can be persuaded to believe that it is OK.

Do we know that this part runs much later than the staged files are last touched, so that these uses of "touch" actually are effective to make the paths stat-dirty? Otherwise, we may be just "touch"ing them with the timestamp they already have after all.

Thanks.

Quoted 17 lines
---
 t/perf/p7519-fsmonitor.sh | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)
t/perf/p7519-fsmonitor.sh +1 -1
index 9b43342806b..7bb37e9a6c1 100755
@@ -165,7 +165,7 @@ test_fsmonitor_suite() {
 	'
 
 	test_perf_w_drop_caches "status (dirty) ($DESC)" '
-		git ls-files | head -100000 | xargs -d "\n" touch -h &&
+		git ls-files | head -100000 | lf_to_nul | xargs -0 touch -h &&
 		git status
 	'
#3 lore raw

Re: [PATCH 01/11] p7519: use xargs -0 rather than -d in test

Quoted 9 lines · Junio C Hamano
Quoted 4 lines · Jeff Hostetler via GitGitGadget

From: Jeff Hostetler <[email protected]>

The Mac version of xargs does not support the "-d" option. Convert the test setup to pipe the data set thru lf_to_nul | xargs -0 instead.

"xargs -0" is not all that portable, either, and neither is "touch -h".

Quoted 7 lines

But since the t/perf stuff already depends on having GNU toolchain anyway, I can be persuaded to believe that it is OK.

Do we know that this part runs much later than the staged files are last touched, so that these uses of "touch" actually are effective to make the paths stat-dirty? Otherwise, we may be just "touch"ing them with the timestamp they already have after all.

I'm not sure now that you mention it. I suppose on modern filesystems that have mtimes with nanosecond fields we could (are) assuming that "touch" is actually doing something. On older filesystems (such as FAT32), you're right it is probably not doing anything at the speed that the test runs.

TBH I'm not sure that the test needs the "-h". Symlinks are not that common and it shouldn't affect the timings that much if there are a few.

I'm not sure what to do about "-0". Not even "--null" is portable.

Let me do a little digging here.

Quoted 20 lines

Thanks.

Quoted 17 lines
---
  t/perf/p7519-fsmonitor.sh | 2 +-
  1 file changed, 1 insertion(+), 1 deletion(-)
t/perf/p7519-fsmonitor.sh +1 -1
index 9b43342806b..7bb37e9a6c1 100755
@@ -165,7 +165,7 @@ test_fsmonitor_suite() {
  	'
 
  	test_perf_w_drop_caches "status (dirty) ($DESC)" '
-		git ls-files | head -100000 | xargs -d "\n" touch -h &&
+		git ls-files | head -100000 | lf_to_nul | xargs -0 touch -h &&
  		git status
  	'
#4 lore raw

Re: [PATCH 01/11] p7519: use xargs -0 rather than -d in test

Quoted 5 lines · Jeff Hostetler

I'm not sure now that you mention it. I suppose on modern filesystems that have mtimes with nanosecond fields we could (are) assuming that "touch" is actually doing something. On older filesystems (such as FAT32), you're right it is probably not doing anything at the speed that the test runs.

That one is probably the most relevant nit among the ones I raised. I do not actually mind if we used test-chmtime to force our own timestamp (e.g. "5 seconds before the filesystem time"), and added the helper the "--stdin" option to read paths to work around the "xargs" issue.

Quoted 2 lines

TBH I'm not sure that the test needs the "-h". Symlinks are not that common and it shouldn't affect the timings that much if there are a few.

I agree.

Quoted 1 line

I'm not sure what to do about "-0". Not even "--null" is portable.

Correct. I do not think it is worth "digging", though. I do not mind "ls-files -z | test-tool chmtime -600 --stdin -z" to lose xargs, but we already depend on GNU time to run t/perf, and it is not too far a stretch to require GNU xargs that knows "-0" or "-d".

Thanks.

#5 lore raw

PATCH 2/11 p7519: fix watchman watch-list test on Windows

In reply to Jeff Hostetler via GitGitGadget

From: Jeff Hostetler <[email protected]>

Only use the final portion of the test trash directory file name when verifying that Watchman was started.

On Windows and under the SDK, $GIT_WORKTREE is a cygwin-style path with forward slashes and a "/c/" drive name. However watchman watch-list reports a proper Windows-style pathname with drive letters and backslashes. This causes the grep to fail. Since we don't really care about the full pathname (and we really don't want to bother with normalizaing them), just see if the test-name portion of the path is found.

---
 t/perf/p7519-fsmonitor.sh | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)
t/perf/p7519-fsmonitor.sh +1 -1
index 7bb37e9a6c1..e5a4b0582fb 100755
@@ -101,7 +101,7 @@ test_expect_success "one time repo setup" '
 	# If Watchman exists, watch the work tree and attempt a query.
 	if test_have_prereq WATCHMAN; then
 		watchman watch "$GIT_WORK_TREE" &&
-		watchman watch-list | grep -q -F "$GIT_WORK_TREE"
+		watchman watch-list | grep -q -F "p7519-fsmonitor"
 	fi
 '
 
Signature · 1 line
gitgitgadget
#6 lore raw

PATCH 3/11 p7519: move watchman cleanup earlier in the test

In reply to Jeff Hostetler via GitGitGadget

From: Jeff Hostetler <[email protected]>

Shutdown Watchman after the Watchman-based tests and before the block of "no fsmonitor" tests.

This helps ensure that Watchman cannot affect the test results for the other.

---
 t/perf/p7519-fsmonitor.sh | 25 +++++++++++++++++--------
 1 file changed, 17 insertions(+), 8 deletions(-)
t/perf/p7519-fsmonitor.sh +17 -8
index e5a4b0582fb..45bbba3c92f 100755
@@ -198,6 +198,11 @@ test_fsmonitor_suite() {
 	'
 }
 
+#
+# Run a full set of perf tests using each Hook-based fsmonitor provider,
+# such as Watchman.
+#
+
 if test -n "$GIT_PERF_7519_FSMONITOR"; then
 	for INTEGRATION_PATH in $GIT_PERF_7519_FSMONITOR; do
 		test_expect_success "setup for fsmonitor $INTEGRATION_PATH" 'setup_for_fsmonitor'
@@ -208,14 +213,6 @@ else
 	test_fsmonitor_suite
 fi
 
-test_expect_success "setup without fsmonitor" '
-	unset INTEGRATION_SCRIPT &&
-	git config --unset core.fsmonitor &&
-	git update-index --no-fsmonitor
-'
-
-test_fsmonitor_suite
-
 if test_have_prereq WATCHMAN
 then
 	watchman watch-del "$GIT_WORK_TREE" >/dev/null 2>&1 &&
@@ -225,4 +222,16 @@ then
 	watchman shutdown-server >/dev/null 2>&1
 fi
 
+#
+# Run a full set of perf tests with the fsmonitor feature disabled.
+#
+
+test_expect_success "setup without fsmonitor" '
+	unset INTEGRATION_SCRIPT &&
+	git config --unset core.fsmonitor &&
+	git update-index --no-fsmonitor
+'
+
+test_fsmonitor_suite
+
 test_done
Signature · 1 line
gitgitgadget
#7 lore raw

PATCH 4/11 p7519: add trace logging during perf test

In reply to Jeff Hostetler via GitGitGadget

From: Jeff Hostetler <[email protected]>

Add optional trace logging to allow us to better compare performance of various fsmonitor providers and compare results with non-fsmonitor runs.

Currently, this includes Trace2 logging, but may be extended to include other trace targets, such as GIT_TRACE_FSMONITOR if desired.

Using this logging helped me explain an odd behavior on MacOS where the kernel was dropping events and causing the hook to Watchman to timeout.

---
 t/perf/.gitignore         |  1 +
 t/perf/Makefile           |  4 ++--
 t/perf/p7519-fsmonitor.sh | 32 ++++++++++++++++++++++++++++++++
 3 files changed, 35 insertions(+), 2 deletions(-)
t/perf/.gitignore +1 -0
index 982eb8e3a94..72f5d0d3148 100644
@@ -1,3 +1,4 @@
 /build/
 /test-results/
+/test-trace/
 /trash directory*/
t/perf/Makefile +2 -2
index fcb0e8865e4..2465770a782 100644
@@ -7,10 +7,10 @@ perf: pre-clean
 	./run
 
 pre-clean:
-	rm -rf test-results
+	rm -rf test-results test-trace
 
 clean:
-	rm -rf build "trash directory".* test-results
+	rm -rf build "trash directory".* test-results test-trace
 
 test-lint:
 	$(MAKE) -C .. test-lint
t/perf/p7519-fsmonitor.sh +32 -0
index 45bbba3c92f..e6724d3604b 100755
@@ -32,6 +32,8 @@ test_description="Test core.fsmonitor"
 #
 # GIT_PERF_7519_DROP_CACHE: if set, the OS caches are dropped between tests
 #
+# GIT_PERF_7519_TRACE: if set, enable trace logging during the test.
+#   Trace logs will be grouped by fsmonitor provider.
 
 test_perf_large_repo
 test_checkout_worktree
@@ -70,6 +72,32 @@ then
 	fi
 fi
 
+trace_start() {
+	if test -n "$GIT_PERF_7519_TRACE"
+	then
+		name="$1"
+		TEST_TRACE_DIR="$TEST_OUTPUT_DIRECTORY/test-trace/p7519/"
+		echo "Writing trace logging to $TEST_TRACE_DIR"
+
+		mkdir -p "$TEST_TRACE_DIR"
+
+		# Start Trace2 logging and any other GIT_TRACE_* logs that you
+		# want for this named test case.
+
+		GIT_TRACE2_PERF="$TEST_TRACE_DIR/$name.trace2perf"
+		export GIT_TRACE2_PERF
+
+		>"$GIT_TRACE2_PERF"
+	fi
+}
+
+trace_stop() {
+	if test -n "$GIT_PERF_7519_TRACE"
+	then
+		unset GIT_TRACE2_PERF
+	fi
+}
+
 test_expect_success "one time repo setup" '
 	# set untrackedCache depending on the environment
 	if test -n "$GIT_PERF_7519_UNTRACKED_CACHE"
@@ -203,6 +231,7 @@ test_fsmonitor_suite() {
 # such as Watchman.
 #
 
+trace_start fsmonitor-watchman
 if test -n "$GIT_PERF_7519_FSMONITOR"; then
 	for INTEGRATION_PATH in $GIT_PERF_7519_FSMONITOR; do
 		test_expect_success "setup for fsmonitor $INTEGRATION_PATH" 'setup_for_fsmonitor'
@@ -221,11 +250,13 @@ then
 	# preventing the removal of the trash directory
 	watchman shutdown-server >/dev/null 2>&1
 fi
+trace_stop
 
 #
 # Run a full set of perf tests with the fsmonitor feature disabled.
 #
 
+trace_start fsmonitor-disabled
 test_expect_success "setup without fsmonitor" '
 	unset INTEGRATION_SCRIPT &&
 	git config --unset core.fsmonitor &&
@@ -233,5 +264,6 @@ test_expect_success "setup without fsmonitor" '
 '
 
 test_fsmonitor_suite
+trace_stop
 
 test_done
Signature · 1 line
gitgitgadget
#8 lore raw

PATCH 5/11 preload-index: log the number of lstat calls to trace2

In reply to Jeff Hostetler via GitGitGadget

From: Jeff Hostetler <[email protected]>

Report the total number of calls made to lstat() inside preload_index().

FSMonitor improves the performance of commands like git status by avoiding scanning the disk for changed files. This can be seen in preload_index(). Let's measure this.

---
 preload-index.c | 10 ++++++++++
 1 file changed, 10 insertions(+)
preload-index.c +10 -0
index ed6eaa47388..e5529a58636 100644
@@ -31,6 +31,7 @@ struct thread_data {
 	struct pathspec pathspec;
 	struct progress_data *progress;
 	int offset, nr;
+	int t2_nr_lstat;
 };
 
 static void *preload_thread(void *_data)
@@ -73,6 +74,7 @@ static void *preload_thread(void *_data)
 			continue;
 		if (threaded_has_symlink_leading_path(&cache, ce->name, ce_namelen(ce)))
 			continue;
+		p->t2_nr_lstat++;
 		if (lstat(ce->name, &st))
 			continue;
 		if (ie_match_stat(index, ce, &st, CE_MATCH_RACY_IS_DIRTY|CE_MATCH_IGNORE_FSMONITOR))
@@ -98,6 +100,7 @@ void preload_index(struct index_state *index,
 	int threads, i, work, offset;
 	struct thread_data data[MAX_PARALLEL];
 	struct progress_data pd;
+	int t2_sum_lstat = 0;
 
 	if (!HAVE_THREADS || !core_preload_index)
 		return;
@@ -107,6 +110,9 @@ void preload_index(struct index_state *index,
 		threads = 2;
 	if (threads < 2)
 		return;
+
+	trace2_region_enter("index", "preload", NULL);
+
 	trace_performance_enter();
 	if (threads > MAX_PARALLEL)
 		threads = MAX_PARALLEL;
@@ -141,10 +147,14 @@ void preload_index(struct index_state *index,
 		struct thread_data *p = data+i;
 		if (pthread_join(p->pthread, NULL))
 			die("unable to join threaded lstat");
+		t2_sum_lstat += p->t2_nr_lstat;
 	}
 	stop_progress(&pd.progress);
 
 	trace_performance_leave("preload index");
+
+	trace2_data_intmax("index", NULL, "preload/sum_lstat", t2_sum_lstat);
+	trace2_region_leave("index", "preload", NULL);
 }
 
 int repo_read_index_preload(struct repository *repo,
Signature · 1 line
gitgitgadget
#9 lore raw

PATCH 6/11 read-cache: log the number of lstat calls to trace2

In reply to Jeff Hostetler via GitGitGadget

From: Jeff Hostetler <[email protected]>

Report the total number of calls made to lstat() inside of refresh_index().

FSMonitor improves the performance of commands like git status by avoiding scanning the disk for changed files. This can be seen in refresh_index(). Let's measure this.

---
 read-cache.c | 17 ++++++++++++++---
 1 file changed, 14 insertions(+), 3 deletions(-)
read-cache.c +14 -3
index ecf6f689940..893cc41e1d9 100644
@@ -1364,7 +1364,8 @@ int add_index_entry(struct index_state *istate, struct cache_entry *ce, int opti
 static struct cache_entry *refresh_cache_ent(struct index_state *istate,
 					     struct cache_entry *ce,
 					     unsigned int options, int *err,
-					     int *changed_ret)
+					     int *changed_ret,
+					     int *t2_did_lstat)
 {
 	struct stat st;
 	struct cache_entry *updated;
@@ -1406,6 +1407,8 @@ static struct cache_entry *refresh_cache_ent(struct index_state *istate,
 		return NULL;
 	}
 
+	if (t2_did_lstat)
+		*t2_did_lstat = 1;
 	if (lstat(ce->name, &st) < 0) {
 		if (ignore_missing && errno == ENOENT)
 			return ce;
@@ -1519,6 +1522,7 @@ int refresh_index(struct index_state *istate, unsigned int flags,
 	const char *added_fmt;
 	const char *unmerged_fmt;
 	struct progress *progress = NULL;
+	int t2_sum_lstat = 0;
 
 	if (flags & REFRESH_PROGRESS && isatty(2))
 		progress = start_delayed_progress(_("Refresh index"),
@@ -1536,11 +1540,13 @@ int refresh_index(struct index_state *istate, unsigned int flags,
 	 * we only have to do the special cases that are left.
 	 */
 	preload_index(istate, pathspec, 0);
+	trace2_region_enter("index", "refresh", NULL);
 	for (i = 0; i < istate->cache_nr; i++) {
 		struct cache_entry *ce, *new_entry;
 		int cache_errno = 0;
 		int changed = 0;
 		int filtered = 0;
+		int t2_did_lstat = 0;
 
 		ce = istate->cache[i];
 		if (ignore_submodules && S_ISGITLINK(ce->ce_mode))
@@ -1566,7 +1572,10 @@ int refresh_index(struct index_state *istate, unsigned int flags,
 		if (filtered)
 			continue;
 
-		new_entry = refresh_cache_ent(istate, ce, options, &cache_errno, &changed);
+		new_entry = refresh_cache_ent(istate, ce, options,
+					      &cache_errno, &changed,
+					      &t2_did_lstat);
+		t2_sum_lstat += t2_did_lstat;
 		if (new_entry == ce)
 			continue;
 		if (progress)
@@ -1602,6 +1611,8 @@ int refresh_index(struct index_state *istate, unsigned int flags,
 
 		replace_index_entry(istate, i, new_entry);
 	}
+	trace2_data_intmax("index", NULL, "refresh/sum_lstat", t2_sum_lstat);
+	trace2_region_leave("index", "refresh", NULL);
 	if (progress) {
 		display_progress(progress, istate->cache_nr);
 		stop_progress(&progress);
@@ -1614,7 +1625,7 @@ struct cache_entry *refresh_cache_entry(struct index_state *istate,
 					struct cache_entry *ce,
 					unsigned int options)
 {
-	return refresh_cache_ent(istate, ce, options, NULL, NULL);
+	return refresh_cache_ent(istate, ce, options, NULL, NULL, NULL);
 }
 
 
Signature · 1 line
gitgitgadget
#10 lore raw

PATCH 7/11 read-cache: log the number of scanned files to trace2

In reply to Jeff Hostetler via GitGitGadget

From: Jeff Hostetler <[email protected]>

Report the number of files in the working directory that were read and their hashes verified in refresh_index().

FSMonitor improves the performance of commands like git status by avoiding scanning the disk for changed files. Let's measure this.

---
 read-cache.c | 13 ++++++++++---
 1 file changed, 10 insertions(+), 3 deletions(-)
read-cache.c +10 -3
index 893cc41e1d9..c9dd7f4015e 100644
@@ -1365,7 +1365,8 @@ static struct cache_entry *refresh_cache_ent(struct index_state *istate,
 					     struct cache_entry *ce,
 					     unsigned int options, int *err,
 					     int *changed_ret,
-					     int *t2_did_lstat)
+					     int *t2_did_lstat,
+					     int *t2_did_scan)
 {
 	struct stat st;
 	struct cache_entry *updated;
@@ -1445,6 +1446,8 @@ static struct cache_entry *refresh_cache_ent(struct index_state *istate,
 		}
 	}
 
+	if (t2_did_scan)
+		*t2_did_scan = 1;
 	if (ie_modified(istate, ce, &st, options)) {
 		if (err)
 			*err = EINVAL;
@@ -1523,6 +1526,7 @@ int refresh_index(struct index_state *istate, unsigned int flags,
 	const char *unmerged_fmt;
 	struct progress *progress = NULL;
 	int t2_sum_lstat = 0;
+	int t2_sum_scan = 0;
 
 	if (flags & REFRESH_PROGRESS && isatty(2))
 		progress = start_delayed_progress(_("Refresh index"),
@@ -1547,6 +1551,7 @@ int refresh_index(struct index_state *istate, unsigned int flags,
 		int changed = 0;
 		int filtered = 0;
 		int t2_did_lstat = 0;
+		int t2_did_scan = 0;
 
 		ce = istate->cache[i];
 		if (ignore_submodules && S_ISGITLINK(ce->ce_mode))
@@ -1574,8 +1579,9 @@ int refresh_index(struct index_state *istate, unsigned int flags,
 
 		new_entry = refresh_cache_ent(istate, ce, options,
 					      &cache_errno, &changed,
-					      &t2_did_lstat);
+					      &t2_did_lstat, &t2_did_scan);
 		t2_sum_lstat += t2_did_lstat;
+		t2_sum_scan += t2_did_scan;
 		if (new_entry == ce)
 			continue;
 		if (progress)
@@ -1612,6 +1618,7 @@ int refresh_index(struct index_state *istate, unsigned int flags,
 		replace_index_entry(istate, i, new_entry);
 	}
 	trace2_data_intmax("index", NULL, "refresh/sum_lstat", t2_sum_lstat);
+	trace2_data_intmax("index", NULL, "refresh/sum_scan", t2_sum_scan);
 	trace2_region_leave("index", "refresh", NULL);
 	if (progress) {
 		display_progress(progress, istate->cache_nr);
@@ -1625,7 +1632,7 @@ struct cache_entry *refresh_cache_entry(struct index_state *istate,
 					struct cache_entry *ce,
 					unsigned int options)
 {
-	return refresh_cache_ent(istate, ce, options, NULL, NULL, NULL);
+	return refresh_cache_ent(istate, ce, options, NULL, NULL, NULL, NULL);
 }
 
 
Signature · 1 line
gitgitgadget
#11 lore raw

PATCH 8/11 fsmonitor: log invocation of FSMonitor hook to trace2

In reply to Jeff Hostetler via GitGitGadget

From: Jeff Hostetler <[email protected]>

Let's measure the time taken to request and receive FSMonitor data via the hook API and the size of the response.

---
 fsmonitor.c | 29 ++++++++++++++++++++++++++++-
 fsmonitor.h |  5 +++++
 2 files changed, 33 insertions(+), 1 deletion(-)
fsmonitor.c +28 -1
index ca031c3abb8..7a2be24cd43 100644
@@ -142,6 +142,7 @@ void write_fsmonitor_extension(struct strbuf *sb, struct index_state *istate)
 static int query_fsmonitor(int version, const char *last_update, struct strbuf *query_result)
 {
 	struct child_process cp = CHILD_PROCESS_INIT;
+	int result;
 
 	if (!core_fsmonitor)
 		return -1;
@@ -152,7 +153,33 @@ static int query_fsmonitor(int version, const char *last_update, struct strbuf *
 	cp.use_shell = 1;
 	cp.dir = get_git_work_tree();
 
-	return capture_command(&cp, query_result, 1024);
+	trace2_region_enter("fsm_hook", "query", NULL);
+
+	result = capture_command(&cp, query_result, 1024);
+
+	if (result)
+		trace2_data_intmax("fsm_hook", NULL, "query/failed", result);
+	else {
+		trace2_data_intmax("fsm_hook", NULL, "query/response-length",
+				   query_result->len);
+
+		if (fsmonitor_is_trivial_response(query_result))
+			trace2_data_intmax("fsm_hook", NULL,
+					   "query/trivial-response", 1);
+	}
+
+	trace2_region_leave("fsm_hook", "query", NULL);
+
+	return result;
+}
+
+int fsmonitor_is_trivial_response(const struct strbuf *query_result)
+{
+	static char trivial_response[3] = { '\0', '/', '\0' };
+	int is_trivial = !memcmp(trivial_response,
+				 &query_result->buf[query_result->len - 3], 3);
+
+	return is_trivial;
 }
 
 static void fsmonitor_refresh_callback(struct index_state *istate, const char *name)
fsmonitor.h +5 -0
index 739318ab6d1..7f1794b90b0 100644
@@ -44,6 +44,11 @@ void tweak_fsmonitor(struct index_state *istate);
  */
 void refresh_fsmonitor(struct index_state *istate);
 
+/*
+ * Does the received result contain the "trivial" response?
+ */
+int fsmonitor_is_trivial_response(const struct strbuf *query_result);
+
 /*
  * Set the given cache entries CE_FSMONITOR_VALID bit. This should be
  * called any time the cache entry has been updated to reflect the
Signature · 1 line
gitgitgadget
#12 lore raw

PATCH 9/11 fsmonitor: log FSMN token when reading and writing the index

In reply to Jeff Hostetler via GitGitGadget

From: Jeff Hostetler <[email protected]>

---
 fsmonitor.c | 12 ++++++++++--
 1 file changed, 10 insertions(+), 2 deletions(-)
fsmonitor.c +10 -2
index 7a2be24cd43..3105dc370ab 100644
@@ -87,7 +87,11 @@ int read_fsmonitor_extension(struct index_state *istate, const void *data,
 		BUG("fsmonitor_dirty has more entries than the index (%"PRIuMAX" > %u)",
 		    (uintmax_t)istate->fsmonitor_dirty->bit_size, istate->cache_nr);
 
-	trace_printf_key(&trace_fsmonitor, "read fsmonitor extension successful");
+	trace2_data_string("index", NULL, "extension/fsmn/read/token",
+			   istate->fsmonitor_last_update);
+	trace_printf_key(&trace_fsmonitor,
+			 "read fsmonitor extension successful '%s'",
+			 istate->fsmonitor_last_update);
 	return 0;
 }
 
@@ -133,7 +137,11 @@ void write_fsmonitor_extension(struct strbuf *sb, struct index_state *istate)
 	put_be32(&ewah_size, sb->len - ewah_start);
 	memcpy(sb->buf + fixup, &ewah_size, sizeof(uint32_t));
 
-	trace_printf_key(&trace_fsmonitor, "write fsmonitor extension successful");
+	trace2_data_string("index", NULL, "extension/fsmn/write/token",
+			   istate->fsmonitor_last_update);
+	trace_printf_key(&trace_fsmonitor,
+			 "write fsmonitor extension successful '%s'",
+			 istate->fsmonitor_last_update);
 }
 
 /*
Signature · 1 line
gitgitgadget
#13 lore raw

PATCH 10/11 fsmonitor: allow all entries for a folder to be invalidated

In reply to Jeff Hostetler via GitGitGadget

From: Kevin Willford <[email protected]>

Allow fsmonitor to report directory changes by reporting paths with a trailing slash.

---
 fsmonitor.c | 31 ++++++++++++++++++++++++++-----
 1 file changed, 26 insertions(+), 5 deletions(-)
fsmonitor.c +26 -5
index 3105dc370ab..64deeda597e 100644
@@ -190,13 +190,34 @@ int fsmonitor_is_trivial_response(const struct strbuf *query_result)
 	return is_trivial;
 }
 
-static void fsmonitor_refresh_callback(struct index_state *istate, const char *name)
+static void fsmonitor_refresh_callback(struct index_state *istate, char *name)
 {
-	int pos = index_name_pos(istate, name, strlen(name));
+	int i, len = strlen(name);
+	if (name[len - 1] == '/') {
+
+		/*
+		 * TODO We should binary search to find the first path with
+		 * TODO this directory prefix.  Then linearly update entries
+		 * TODO while the prefix matches.  Taking care to search without
+		 * TODO the trailing slash -- because '/' sorts after a few
+		 * TODO interesting special chars, like '.' and ' '.
+		 */
+
+		/* Mark all entries for the folder invalid */
+		for (i = 0; i < istate->cache_nr; i++) {
+			if (istate->cache[i]->ce_flags & CE_FSMONITOR_VALID &&
+			    starts_with(istate->cache[i]->name, name))
+				istate->cache[i]->ce_flags &= ~CE_FSMONITOR_VALID;
+		}
+		/* Need to remove the / from the path for the untracked cache */
+		name[len - 1] = '\0';
+	} else {
+		int pos = index_name_pos(istate, name, strlen(name));
 
-	if (pos >= 0) {
-		struct cache_entry *ce = istate->cache[pos];
-		ce->ce_flags &= ~CE_FSMONITOR_VALID;
+		if (pos >= 0) {
+			struct cache_entry *ce = istate->cache[pos];
+			ce->ce_flags &= ~CE_FSMONITOR_VALID;
+		}
 	}
 
 	/*
Signature · 1 line
gitgitgadget
#14 lore raw

PATCH 11/11 fsmonitor: refactor initialization of fsmonitor_last_update token

In reply to Jeff Hostetler via GitGitGadget

From: Jeff Hostetler <[email protected]>

Isolate and document initialization of istate->fsmonitor_last_update. This field should contain a fsmonitor-specific opaque token, but we need to initialize it before we can actually talk to a fsmonitor process, so we create a generic default value.

---
 fsmonitor.c | 35 ++++++++++++++++++++++++++++++++---
 1 file changed, 32 insertions(+), 3 deletions(-)
fsmonitor.c +32 -3
index 64deeda597e..e12214b3007 100644
@@ -343,16 +343,45 @@ void refresh_fsmonitor(struct index_state *istate)
 	istate->fsmonitor_last_update = strbuf_detach(&last_update_token, NULL);
 }
 
+/*
+ * The caller wants to turn on FSMonitor.  And when the caller writes
+ * the index to disk, a FSMonitor extension should be included.  This
+ * requires that `istate->fsmonitor_last_update` not be NULL.  But we
+ * have not actually talked to a FSMonitor process yet, so we don't
+ * have an initial value for this field.
+ *
+ * For a protocol V1 FSMonitor process, this field is a formatted
+ * "nanoseconds since epoch" field.  However, for a protocol V2
+ * FSMonitor process, this field is an opaque token.
+ *
+ * Historically, `add_fsmonitor()` has initialized this field to the
+ * current time for protocol V1 processes.  There are lots of race
+ * conditions here, but that code has shipped...
+ *
+ * The only true solution is to use a V2 FSMonitor and get a current
+ * or default token value (that it understands), but we cannot do that
+ * until we have actually talked to an instance of the FSMonitor process
+ * (but the protocol requires that we send a token first...).
+ *
+ * For simplicity, just initialize like we have a V1 process and require
+ * that V2 processes adapt.
+ */
+static void initialize_fsmonitor_last_update(struct index_state *istate)
+{
+	struct strbuf last_update = STRBUF_INIT;
+
+	strbuf_addf(&last_update, "%"PRIu64"", getnanotime());
+	istate->fsmonitor_last_update = strbuf_detach(&last_update, NULL);
+}
+
 void add_fsmonitor(struct index_state *istate)
 {
 	unsigned int i;
-	struct strbuf last_update = STRBUF_INIT;
 
 	if (!istate->fsmonitor_last_update) {
 		trace_printf_key(&trace_fsmonitor, "add fsmonitor");
 		istate->cache_changed |= FSMONITOR_CHANGED;
-		strbuf_addf(&last_update, "%"PRIu64"", getnanotime());
-		istate->fsmonitor_last_update = strbuf_detach(&last_update, NULL);
+		initialize_fsmonitor_last_update(istate);
 
 		/* reset the fsmonitor state */
 		for (i = 0; i < istate->cache_nr; i++)
Signature · 1 line
gitgitgadget
#15 lore raw

v2 cover FSMonitor Preliminary Commits

In reply to Jeff Hostetler via GitGitGadget

Here is version 2 of this series.

In version 1, I replaced the non-portable "xargs -d" with "xargs -0", but it turns out that that too is not universally available. In this version I replace the need for either one by filtering out the problematic paths (such as ones with LFs) and quoting paths to handle whitespace. The resulting paths can be passed to xargs without any arguments.

Also, I updated the test to use test-tool chmtime rather than touch to ensure that the files actually look dirty on low-resolution file systems.

Jeff Hostetler (10):
p7519: do not rely on "xargs -d" in test
p7519: fix watchman watch-list test on Windows
p7519: move watchman cleanup earlier in the test
p7519: add trace logging during perf test
preload-index: log the number of lstat calls to trace2
read-cache: log the number of lstat calls to trace2
read-cache: log the number of scanned files to trace2
fsmonitor: log invocation of FSMonitor hook to trace2
fsmonitor: log FSMN token when reading and writing the index
fsmonitor: refactor initialization of fsmonitor_last_update token

Kevin Willford (1):
fsmonitor: allow all entries for a folder to be invalidated

 fsmonitor.c               | 107 ++++++++++++++++++++++++++++++++++----
 fsmonitor.h               |   5 ++
 preload-index.c           |  10 ++++
 read-cache.c              |  24 +++++++--
 t/perf/.gitignore         |   1 +
 t/perf/Makefile           |   4 +-
 t/perf/p7519-fsmonitor.sh |  71 +++++++++++++++++++++----
 7 files changed, 196 insertions(+), 26 deletions(-)

base-commit: 71ca53e8125e36efbda17293c50027d31681a41f
Published-As: https://github.com/gitgitgadget/git/releases/tag/pr-860%2Fjeffhostetler%2Ffsmonitor-prework-v2
Fetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-860/jeffhostetler/fsmonitor-prework-v2
Pull-Request: https://github.com/gitgitgadget/git/pull/860

Range-diff vs v1:

1: cf252e24b8c ! 1: e570f7316cc p7519: use xargs -0 rather than -d in test
@@ Metadata
Author: Jeff Hostetler <[email protected]>

## Commit message ##
- p7519: use xargs -0 rather than -d in test
+ p7519: do not rely on "xargs -d" in test

- The Mac version of xargs does not support the "-d" option. Convert the test
- setup to pipe the data set thru lf_to_nul | xargs -0 instead.
+ Convert the test to use a more portable method to update the mtime on a
+ large number of files under version control.
+
+ The Mac version of xargs does not support the "-d" option.
+ Likewise, the "-0" and "--null" options are not portable.
+
+ Furthermore, use test-tool chmtime rather than touch to update the
+ mtime to ensure that it is actually updated (especially on file systems
+ with only whole second resolution).

## t/perf/p7519-fsmonitor.sh ##
@@ t/perf/p7519-fsmonitor.sh: test_fsmonitor_suite() {
+ git status -uall
'

++ # Update the mtimes on upto 100k files to make status think
++ # that they are dirty. For simplicity, omit any files with
++ # LFs (i.e. anything that ls-files thinks it needs to dquote).
++ # Then fully backslash-quote the paths to capture any
++ # whitespace so that they pass thru xargs properly.
++ #
test_perf_w_drop_caches "status (dirty) ($DESC)" '
- git ls-files | head -100000 | xargs -d "\n" touch -h &&
-+ git ls-files | head -100000 | lf_to_nul | xargs -0 touch -h &&
++ git ls-files | \
++ head -100000 | \
++ grep -v \" | \
++ sed '\''s/\(.\)/\\\1/g'\'' | \
++ xargs test-tool chmtime -300 &&
git status
'

  2:  a641f9e357c =  2:  3042fc92fe6 p7519: fix watchman watch-list test on Windows
  3:  2af6858716f =  3:  9ceba5e6942 p7519: move watchman cleanup earlier in the test
  4:  8de9985a706 =  4:  f6ea0a51f50 p7519: add trace logging during perf test
  5:  cdd49f1fdb1 =  5:  3c5035e4649 preload-index: log the number of lstat calls to trace2
  6:  65488f7a1bf =  6:  d150a2d4576 read-cache: log the number of lstat calls to trace2
  7:  c84531f6244 =  7:  33cc0b838fa read-cache: log the number of scanned files to trace2
  8:  ef64b60c7a0 =  8:  c043bccc8af fsmonitor: log invocation of FSMonitor hook to trace2
  9:  edb88ffe39e =  9:  6ec4a4468f6 fsmonitor: log FSMN token when reading and writing the index
 10:  384d2eff863 = 10:  2ac66f07a59 fsmonitor: allow all entries for a folder to be invalidated
 11:  4686196bbc6 = 11:  5410d3ab61d fsmonitor: refactor initialization of fsmonitor_last_update token
Signature · 1 line
gitgitgadget
#16 lore raw

PATCH v2 1/11 p7519: do not rely on "xargs -d" in test

From: Jeff Hostetler <[email protected]>

Convert the test to use a more portable method to update the mtime on a large number of files under version control.

The Mac version of xargs does not support the "-d" option. Likewise, the "-0" and "--null" options are not portable.

Furthermore, use test-tool chmtime rather than touch to update the mtime to ensure that it is actually updated (especially on file systems with only whole second resolution).

---
 t/perf/p7519-fsmonitor.sh | 12 +++++++++++-
 1 file changed, 11 insertions(+), 1 deletion(-)
t/perf/p7519-fsmonitor.sh +11 -1
index 9b43342806b..6677e0ef7ab 100755
@@ -164,8 +164,18 @@ test_fsmonitor_suite() {
 		git status -uall
 	'
 
+	# Update the mtimes on upto 100k files to make status think
+	# that they are dirty.  For simplicity, omit any files with
+	# LFs (i.e. anything that ls-files thinks it needs to dquote).
+	# Then fully backslash-quote the paths to capture any
+	# whitespace so that they pass thru xargs properly.
+	#
 	test_perf_w_drop_caches "status (dirty) ($DESC)" '
-		git ls-files | head -100000 | xargs -d "\n" touch -h &&
+		git ls-files | \
+			head -100000 | \
+			grep -v \" | \
+			sed '\''s/\(.\)/\\\1/g'\'' | \
+			xargs test-tool chmtime -300 &&
 		git status
 	'
 
Signature · 1 line
gitgitgadget
#17 lore raw

PATCH v2 2/11 p7519: fix watchman watch-list test on Windows

In reply to Jeff Hostetler via GitGitGadget

From: Jeff Hostetler <[email protected]>

Only use the final portion of the test trash directory file name when verifying that Watchman was started.

On Windows and under the SDK, $GIT_WORKTREE is a cygwin-style path with forward slashes and a "/c/" drive name. However watchman watch-list reports a proper Windows-style pathname with drive letters and backslashes. This causes the grep to fail. Since we don't really care about the full pathname (and we really don't want to bother with normalizaing them), just see if the test-name portion of the path is found.

---
 t/perf/p7519-fsmonitor.sh | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)
t/perf/p7519-fsmonitor.sh +1 -1
index 6677e0ef7ab..21d525541d5 100755
@@ -101,7 +101,7 @@ test_expect_success "one time repo setup" '
 	# If Watchman exists, watch the work tree and attempt a query.
 	if test_have_prereq WATCHMAN; then
 		watchman watch "$GIT_WORK_TREE" &&
-		watchman watch-list | grep -q -F "$GIT_WORK_TREE"
+		watchman watch-list | grep -q -F "p7519-fsmonitor"
 	fi
 '
 
Signature · 1 line
gitgitgadget
#18 lore raw

PATCH v2 3/11 p7519: move watchman cleanup earlier in the test

In reply to Jeff Hostetler via GitGitGadget

From: Jeff Hostetler <[email protected]>

Shutdown Watchman after the Watchman-based tests and before the block of "no fsmonitor" tests.

This helps ensure that Watchman cannot affect the test results for the other.

---
 t/perf/p7519-fsmonitor.sh | 25 +++++++++++++++++--------
 1 file changed, 17 insertions(+), 8 deletions(-)
t/perf/p7519-fsmonitor.sh +17 -8
index 21d525541d5..78e7d2c03f5 100755
@@ -208,6 +208,11 @@ test_fsmonitor_suite() {
 	'
 }
 
+#
+# Run a full set of perf tests using each Hook-based fsmonitor provider,
+# such as Watchman.
+#
+
 if test -n "$GIT_PERF_7519_FSMONITOR"; then
 	for INTEGRATION_PATH in $GIT_PERF_7519_FSMONITOR; do
 		test_expect_success "setup for fsmonitor $INTEGRATION_PATH" 'setup_for_fsmonitor'
@@ -218,14 +223,6 @@ else
 	test_fsmonitor_suite
 fi
 
-test_expect_success "setup without fsmonitor" '
-	unset INTEGRATION_SCRIPT &&
-	git config --unset core.fsmonitor &&
-	git update-index --no-fsmonitor
-'
-
-test_fsmonitor_suite
-
 if test_have_prereq WATCHMAN
 then
 	watchman watch-del "$GIT_WORK_TREE" >/dev/null 2>&1 &&
@@ -235,4 +232,16 @@ then
 	watchman shutdown-server >/dev/null 2>&1
 fi
 
+#
+# Run a full set of perf tests with the fsmonitor feature disabled.
+#
+
+test_expect_success "setup without fsmonitor" '
+	unset INTEGRATION_SCRIPT &&
+	git config --unset core.fsmonitor &&
+	git update-index --no-fsmonitor
+'
+
+test_fsmonitor_suite
+
 test_done
Signature · 1 line
gitgitgadget
#19 lore raw

PATCH v2 4/11 p7519: add trace logging during perf test

In reply to Jeff Hostetler via GitGitGadget

From: Jeff Hostetler <[email protected]>

Add optional trace logging to allow us to better compare performance of various fsmonitor providers and compare results with non-fsmonitor runs.

Currently, this includes Trace2 logging, but may be extended to include other trace targets, such as GIT_TRACE_FSMONITOR if desired.

Using this logging helped me explain an odd behavior on MacOS where the kernel was dropping events and causing the hook to Watchman to timeout.

---
 t/perf/.gitignore         |  1 +
 t/perf/Makefile           |  4 ++--
 t/perf/p7519-fsmonitor.sh | 32 ++++++++++++++++++++++++++++++++
 3 files changed, 35 insertions(+), 2 deletions(-)
t/perf/.gitignore +1 -0
index 982eb8e3a94..72f5d0d3148 100644
@@ -1,3 +1,4 @@
 /build/
 /test-results/
+/test-trace/
 /trash directory*/
t/perf/Makefile +2 -2
index fcb0e8865e4..2465770a782 100644
@@ -7,10 +7,10 @@ perf: pre-clean
 	./run
 
 pre-clean:
-	rm -rf test-results
+	rm -rf test-results test-trace
 
 clean:
-	rm -rf build "trash directory".* test-results
+	rm -rf build "trash directory".* test-results test-trace
 
 test-lint:
 	$(MAKE) -C .. test-lint
t/perf/p7519-fsmonitor.sh +32 -0
index 78e7d2c03f5..aa0ea0e2ec8 100755
@@ -32,6 +32,8 @@ test_description="Test core.fsmonitor"
 #
 # GIT_PERF_7519_DROP_CACHE: if set, the OS caches are dropped between tests
 #
+# GIT_PERF_7519_TRACE: if set, enable trace logging during the test.
+#   Trace logs will be grouped by fsmonitor provider.
 
 test_perf_large_repo
 test_checkout_worktree
@@ -70,6 +72,32 @@ then
 	fi
 fi
 
+trace_start() {
+	if test -n "$GIT_PERF_7519_TRACE"
+	then
+		name="$1"
+		TEST_TRACE_DIR="$TEST_OUTPUT_DIRECTORY/test-trace/p7519/"
+		echo "Writing trace logging to $TEST_TRACE_DIR"
+
+		mkdir -p "$TEST_TRACE_DIR"
+
+		# Start Trace2 logging and any other GIT_TRACE_* logs that you
+		# want for this named test case.
+
+		GIT_TRACE2_PERF="$TEST_TRACE_DIR/$name.trace2perf"
+		export GIT_TRACE2_PERF
+
+		>"$GIT_TRACE2_PERF"
+	fi
+}
+
+trace_stop() {
+	if test -n "$GIT_PERF_7519_TRACE"
+	then
+		unset GIT_TRACE2_PERF
+	fi
+}
+
 test_expect_success "one time repo setup" '
 	# set untrackedCache depending on the environment
 	if test -n "$GIT_PERF_7519_UNTRACKED_CACHE"
@@ -213,6 +241,7 @@ test_fsmonitor_suite() {
 # such as Watchman.
 #
 
+trace_start fsmonitor-watchman
 if test -n "$GIT_PERF_7519_FSMONITOR"; then
 	for INTEGRATION_PATH in $GIT_PERF_7519_FSMONITOR; do
 		test_expect_success "setup for fsmonitor $INTEGRATION_PATH" 'setup_for_fsmonitor'
@@ -231,11 +260,13 @@ then
 	# preventing the removal of the trash directory
 	watchman shutdown-server >/dev/null 2>&1
 fi
+trace_stop
 
 #
 # Run a full set of perf tests with the fsmonitor feature disabled.
 #
 
+trace_start fsmonitor-disabled
 test_expect_success "setup without fsmonitor" '
 	unset INTEGRATION_SCRIPT &&
 	git config --unset core.fsmonitor &&
@@ -243,5 +274,6 @@ test_expect_success "setup without fsmonitor" '
 '
 
 test_fsmonitor_suite
+trace_stop
 
 test_done
Signature · 1 line
gitgitgadget
#20 lore raw

PATCH v2 5/11 preload-index: log the number of lstat calls to trace2

In reply to Jeff Hostetler via GitGitGadget

From: Jeff Hostetler <[email protected]>

Report the total number of calls made to lstat() inside preload_index().

FSMonitor improves the performance of commands like git status by avoiding scanning the disk for changed files. This can be seen in preload_index(). Let's measure this.

---
 preload-index.c | 10 ++++++++++
 1 file changed, 10 insertions(+)
preload-index.c +10 -0
index ed6eaa47388..e5529a58636 100644
@@ -31,6 +31,7 @@ struct thread_data {
 	struct pathspec pathspec;
 	struct progress_data *progress;
 	int offset, nr;
+	int t2_nr_lstat;
 };
 
 static void *preload_thread(void *_data)
@@ -73,6 +74,7 @@ static void *preload_thread(void *_data)
 			continue;
 		if (threaded_has_symlink_leading_path(&cache, ce->name, ce_namelen(ce)))
 			continue;
+		p->t2_nr_lstat++;
 		if (lstat(ce->name, &st))
 			continue;
 		if (ie_match_stat(index, ce, &st, CE_MATCH_RACY_IS_DIRTY|CE_MATCH_IGNORE_FSMONITOR))
@@ -98,6 +100,7 @@ void preload_index(struct index_state *index,
 	int threads, i, work, offset;
 	struct thread_data data[MAX_PARALLEL];
 	struct progress_data pd;
+	int t2_sum_lstat = 0;
 
 	if (!HAVE_THREADS || !core_preload_index)
 		return;
@@ -107,6 +110,9 @@ void preload_index(struct index_state *index,
 		threads = 2;
 	if (threads < 2)
 		return;
+
+	trace2_region_enter("index", "preload", NULL);
+
 	trace_performance_enter();
 	if (threads > MAX_PARALLEL)
 		threads = MAX_PARALLEL;
@@ -141,10 +147,14 @@ void preload_index(struct index_state *index,
 		struct thread_data *p = data+i;
 		if (pthread_join(p->pthread, NULL))
 			die("unable to join threaded lstat");
+		t2_sum_lstat += p->t2_nr_lstat;
 	}
 	stop_progress(&pd.progress);
 
 	trace_performance_leave("preload index");
+
+	trace2_data_intmax("index", NULL, "preload/sum_lstat", t2_sum_lstat);
+	trace2_region_leave("index", "preload", NULL);
 }
 
 int repo_read_index_preload(struct repository *repo,
Signature · 1 line
gitgitgadget
#21 lore raw

PATCH v2 6/11 read-cache: log the number of lstat calls to trace2

In reply to Jeff Hostetler via GitGitGadget

From: Jeff Hostetler <[email protected]>

Report the total number of calls made to lstat() inside of refresh_index().

FSMonitor improves the performance of commands like git status by avoiding scanning the disk for changed files. This can be seen in refresh_index(). Let's measure this.

---
 read-cache.c | 17 ++++++++++++++---
 1 file changed, 14 insertions(+), 3 deletions(-)
read-cache.c +14 -3
index ecf6f689940..893cc41e1d9 100644
@@ -1364,7 +1364,8 @@ int add_index_entry(struct index_state *istate, struct cache_entry *ce, int opti
 static struct cache_entry *refresh_cache_ent(struct index_state *istate,
 					     struct cache_entry *ce,
 					     unsigned int options, int *err,
-					     int *changed_ret)
+					     int *changed_ret,
+					     int *t2_did_lstat)
 {
 	struct stat st;
 	struct cache_entry *updated;
@@ -1406,6 +1407,8 @@ static struct cache_entry *refresh_cache_ent(struct index_state *istate,
 		return NULL;
 	}
 
+	if (t2_did_lstat)
+		*t2_did_lstat = 1;
 	if (lstat(ce->name, &st) < 0) {
 		if (ignore_missing && errno == ENOENT)
 			return ce;
@@ -1519,6 +1522,7 @@ int refresh_index(struct index_state *istate, unsigned int flags,
 	const char *added_fmt;
 	const char *unmerged_fmt;
 	struct progress *progress = NULL;
+	int t2_sum_lstat = 0;
 
 	if (flags & REFRESH_PROGRESS && isatty(2))
 		progress = start_delayed_progress(_("Refresh index"),
@@ -1536,11 +1540,13 @@ int refresh_index(struct index_state *istate, unsigned int flags,
 	 * we only have to do the special cases that are left.
 	 */
 	preload_index(istate, pathspec, 0);
+	trace2_region_enter("index", "refresh", NULL);
 	for (i = 0; i < istate->cache_nr; i++) {
 		struct cache_entry *ce, *new_entry;
 		int cache_errno = 0;
 		int changed = 0;
 		int filtered = 0;
+		int t2_did_lstat = 0;
 
 		ce = istate->cache[i];
 		if (ignore_submodules && S_ISGITLINK(ce->ce_mode))
@@ -1566,7 +1572,10 @@ int refresh_index(struct index_state *istate, unsigned int flags,
 		if (filtered)
 			continue;
 
-		new_entry = refresh_cache_ent(istate, ce, options, &cache_errno, &changed);
+		new_entry = refresh_cache_ent(istate, ce, options,
+					      &cache_errno, &changed,
+					      &t2_did_lstat);
+		t2_sum_lstat += t2_did_lstat;
 		if (new_entry == ce)
 			continue;
 		if (progress)
@@ -1602,6 +1611,8 @@ int refresh_index(struct index_state *istate, unsigned int flags,
 
 		replace_index_entry(istate, i, new_entry);
 	}
+	trace2_data_intmax("index", NULL, "refresh/sum_lstat", t2_sum_lstat);
+	trace2_region_leave("index", "refresh", NULL);
 	if (progress) {
 		display_progress(progress, istate->cache_nr);
 		stop_progress(&progress);
@@ -1614,7 +1625,7 @@ struct cache_entry *refresh_cache_entry(struct index_state *istate,
 					struct cache_entry *ce,
 					unsigned int options)
 {
-	return refresh_cache_ent(istate, ce, options, NULL, NULL);
+	return refresh_cache_ent(istate, ce, options, NULL, NULL, NULL);
 }
 
 
Signature · 1 line
gitgitgadget
#22 lore raw

PATCH v2 7/11 read-cache: log the number of scanned files to trace2

In reply to Jeff Hostetler via GitGitGadget

From: Jeff Hostetler <[email protected]>

Report the number of files in the working directory that were read and their hashes verified in refresh_index().

FSMonitor improves the performance of commands like git status by avoiding scanning the disk for changed files. Let's measure this.

---
 read-cache.c | 13 ++++++++++---
 1 file changed, 10 insertions(+), 3 deletions(-)
read-cache.c +10 -3
index 893cc41e1d9..c9dd7f4015e 100644
@@ -1365,7 +1365,8 @@ static struct cache_entry *refresh_cache_ent(struct index_state *istate,
 					     struct cache_entry *ce,
 					     unsigned int options, int *err,
 					     int *changed_ret,
-					     int *t2_did_lstat)
+					     int *t2_did_lstat,
+					     int *t2_did_scan)
 {
 	struct stat st;
 	struct cache_entry *updated;
@@ -1445,6 +1446,8 @@ static struct cache_entry *refresh_cache_ent(struct index_state *istate,
 		}
 	}
 
+	if (t2_did_scan)
+		*t2_did_scan = 1;
 	if (ie_modified(istate, ce, &st, options)) {
 		if (err)
 			*err = EINVAL;
@@ -1523,6 +1526,7 @@ int refresh_index(struct index_state *istate, unsigned int flags,
 	const char *unmerged_fmt;
 	struct progress *progress = NULL;
 	int t2_sum_lstat = 0;
+	int t2_sum_scan = 0;
 
 	if (flags & REFRESH_PROGRESS && isatty(2))
 		progress = start_delayed_progress(_("Refresh index"),
@@ -1547,6 +1551,7 @@ int refresh_index(struct index_state *istate, unsigned int flags,
 		int changed = 0;
 		int filtered = 0;
 		int t2_did_lstat = 0;
+		int t2_did_scan = 0;
 
 		ce = istate->cache[i];
 		if (ignore_submodules && S_ISGITLINK(ce->ce_mode))
@@ -1574,8 +1579,9 @@ int refresh_index(struct index_state *istate, unsigned int flags,
 
 		new_entry = refresh_cache_ent(istate, ce, options,
 					      &cache_errno, &changed,
-					      &t2_did_lstat);
+					      &t2_did_lstat, &t2_did_scan);
 		t2_sum_lstat += t2_did_lstat;
+		t2_sum_scan += t2_did_scan;
 		if (new_entry == ce)
 			continue;
 		if (progress)
@@ -1612,6 +1618,7 @@ int refresh_index(struct index_state *istate, unsigned int flags,
 		replace_index_entry(istate, i, new_entry);
 	}
 	trace2_data_intmax("index", NULL, "refresh/sum_lstat", t2_sum_lstat);
+	trace2_data_intmax("index", NULL, "refresh/sum_scan", t2_sum_scan);
 	trace2_region_leave("index", "refresh", NULL);
 	if (progress) {
 		display_progress(progress, istate->cache_nr);
@@ -1625,7 +1632,7 @@ struct cache_entry *refresh_cache_entry(struct index_state *istate,
 					struct cache_entry *ce,
 					unsigned int options)
 {
-	return refresh_cache_ent(istate, ce, options, NULL, NULL, NULL);
+	return refresh_cache_ent(istate, ce, options, NULL, NULL, NULL, NULL);
 }
 
 
Signature · 1 line
gitgitgadget
#23 lore raw

PATCH v2 8/11 fsmonitor: log invocation of FSMonitor hook to trace2

In reply to Jeff Hostetler via GitGitGadget

From: Jeff Hostetler <[email protected]>

Let's measure the time taken to request and receive FSMonitor data via the hook API and the size of the response.

---
 fsmonitor.c | 29 ++++++++++++++++++++++++++++-
 fsmonitor.h |  5 +++++
 2 files changed, 33 insertions(+), 1 deletion(-)
fsmonitor.c +28 -1
index ca031c3abb8..7a2be24cd43 100644
@@ -142,6 +142,7 @@ void write_fsmonitor_extension(struct strbuf *sb, struct index_state *istate)
 static int query_fsmonitor(int version, const char *last_update, struct strbuf *query_result)
 {
 	struct child_process cp = CHILD_PROCESS_INIT;
+	int result;
 
 	if (!core_fsmonitor)
 		return -1;
@@ -152,7 +153,33 @@ static int query_fsmonitor(int version, const char *last_update, struct strbuf *
 	cp.use_shell = 1;
 	cp.dir = get_git_work_tree();
 
-	return capture_command(&cp, query_result, 1024);
+	trace2_region_enter("fsm_hook", "query", NULL);
+
+	result = capture_command(&cp, query_result, 1024);
+
+	if (result)
+		trace2_data_intmax("fsm_hook", NULL, "query/failed", result);
+	else {
+		trace2_data_intmax("fsm_hook", NULL, "query/response-length",
+				   query_result->len);
+
+		if (fsmonitor_is_trivial_response(query_result))
+			trace2_data_intmax("fsm_hook", NULL,
+					   "query/trivial-response", 1);
+	}
+
+	trace2_region_leave("fsm_hook", "query", NULL);
+
+	return result;
+}
+
+int fsmonitor_is_trivial_response(const struct strbuf *query_result)
+{
+	static char trivial_response[3] = { '\0', '/', '\0' };
+	int is_trivial = !memcmp(trivial_response,
+				 &query_result->buf[query_result->len - 3], 3);
+
+	return is_trivial;
 }
 
 static void fsmonitor_refresh_callback(struct index_state *istate, const char *name)
fsmonitor.h +5 -0
index 739318ab6d1..7f1794b90b0 100644
@@ -44,6 +44,11 @@ void tweak_fsmonitor(struct index_state *istate);
  */
 void refresh_fsmonitor(struct index_state *istate);
 
+/*
+ * Does the received result contain the "trivial" response?
+ */
+int fsmonitor_is_trivial_response(const struct strbuf *query_result);
+
 /*
  * Set the given cache entries CE_FSMONITOR_VALID bit. This should be
  * called any time the cache entry has been updated to reflect the
Signature · 1 line
gitgitgadget
#24 lore raw

PATCH v2 9/11 fsmonitor: log FSMN token when reading and writing the index

In reply to Jeff Hostetler via GitGitGadget

From: Jeff Hostetler <[email protected]>

---
 fsmonitor.c | 12 ++++++++++--
 1 file changed, 10 insertions(+), 2 deletions(-)
fsmonitor.c +10 -2
index 7a2be24cd43..3105dc370ab 100644
@@ -87,7 +87,11 @@ int read_fsmonitor_extension(struct index_state *istate, const void *data,
 		BUG("fsmonitor_dirty has more entries than the index (%"PRIuMAX" > %u)",
 		    (uintmax_t)istate->fsmonitor_dirty->bit_size, istate->cache_nr);
 
-	trace_printf_key(&trace_fsmonitor, "read fsmonitor extension successful");
+	trace2_data_string("index", NULL, "extension/fsmn/read/token",
+			   istate->fsmonitor_last_update);
+	trace_printf_key(&trace_fsmonitor,
+			 "read fsmonitor extension successful '%s'",
+			 istate->fsmonitor_last_update);
 	return 0;
 }
 
@@ -133,7 +137,11 @@ void write_fsmonitor_extension(struct strbuf *sb, struct index_state *istate)
 	put_be32(&ewah_size, sb->len - ewah_start);
 	memcpy(sb->buf + fixup, &ewah_size, sizeof(uint32_t));
 
-	trace_printf_key(&trace_fsmonitor, "write fsmonitor extension successful");
+	trace2_data_string("index", NULL, "extension/fsmn/write/token",
+			   istate->fsmonitor_last_update);
+	trace_printf_key(&trace_fsmonitor,
+			 "write fsmonitor extension successful '%s'",
+			 istate->fsmonitor_last_update);
 }
 
 /*
Signature · 1 line
gitgitgadget
#25 lore raw

PATCH v2 10/11 fsmonitor: allow all entries for a folder to be invalidated

In reply to Jeff Hostetler via GitGitGadget

From: Kevin Willford <[email protected]>

Allow fsmonitor to report directory changes by reporting paths with a trailing slash.

---
 fsmonitor.c | 31 ++++++++++++++++++++++++++-----
 1 file changed, 26 insertions(+), 5 deletions(-)
fsmonitor.c +26 -5
index 3105dc370ab..64deeda597e 100644
@@ -190,13 +190,34 @@ int fsmonitor_is_trivial_response(const struct strbuf *query_result)
 	return is_trivial;
 }
 
-static void fsmonitor_refresh_callback(struct index_state *istate, const char *name)
+static void fsmonitor_refresh_callback(struct index_state *istate, char *name)
 {
-	int pos = index_name_pos(istate, name, strlen(name));
+	int i, len = strlen(name);
+	if (name[len - 1] == '/') {
+
+		/*
+		 * TODO We should binary search to find the first path with
+		 * TODO this directory prefix.  Then linearly update entries
+		 * TODO while the prefix matches.  Taking care to search without
+		 * TODO the trailing slash -- because '/' sorts after a few
+		 * TODO interesting special chars, like '.' and ' '.
+		 */
+
+		/* Mark all entries for the folder invalid */
+		for (i = 0; i < istate->cache_nr; i++) {
+			if (istate->cache[i]->ce_flags & CE_FSMONITOR_VALID &&
+			    starts_with(istate->cache[i]->name, name))
+				istate->cache[i]->ce_flags &= ~CE_FSMONITOR_VALID;
+		}
+		/* Need to remove the / from the path for the untracked cache */
+		name[len - 1] = '\0';
+	} else {
+		int pos = index_name_pos(istate, name, strlen(name));
 
-	if (pos >= 0) {
-		struct cache_entry *ce = istate->cache[pos];
-		ce->ce_flags &= ~CE_FSMONITOR_VALID;
+		if (pos >= 0) {
+			struct cache_entry *ce = istate->cache[pos];
+			ce->ce_flags &= ~CE_FSMONITOR_VALID;
+		}
 	}
 
 	/*
Signature · 1 line
gitgitgadget
#26 lore raw

PATCH v2 11/11 fsmonitor: refactor initialization of fsmonitor_last_update token

In reply to Jeff Hostetler via GitGitGadget

From: Jeff Hostetler <[email protected]>

Isolate and document initialization of istate->fsmonitor_last_update. This field should contain a fsmonitor-specific opaque token, but we need to initialize it before we can actually talk to a fsmonitor process, so we create a generic default value.

---
 fsmonitor.c | 35 ++++++++++++++++++++++++++++++++---
 1 file changed, 32 insertions(+), 3 deletions(-)
fsmonitor.c +32 -3
index 64deeda597e..e12214b3007 100644
@@ -343,16 +343,45 @@ void refresh_fsmonitor(struct index_state *istate)
 	istate->fsmonitor_last_update = strbuf_detach(&last_update_token, NULL);
 }
 
+/*
+ * The caller wants to turn on FSMonitor.  And when the caller writes
+ * the index to disk, a FSMonitor extension should be included.  This
+ * requires that `istate->fsmonitor_last_update` not be NULL.  But we
+ * have not actually talked to a FSMonitor process yet, so we don't
+ * have an initial value for this field.
+ *
+ * For a protocol V1 FSMonitor process, this field is a formatted
+ * "nanoseconds since epoch" field.  However, for a protocol V2
+ * FSMonitor process, this field is an opaque token.
+ *
+ * Historically, `add_fsmonitor()` has initialized this field to the
+ * current time for protocol V1 processes.  There are lots of race
+ * conditions here, but that code has shipped...
+ *
+ * The only true solution is to use a V2 FSMonitor and get a current
+ * or default token value (that it understands), but we cannot do that
+ * until we have actually talked to an instance of the FSMonitor process
+ * (but the protocol requires that we send a token first...).
+ *
+ * For simplicity, just initialize like we have a V1 process and require
+ * that V2 processes adapt.
+ */
+static void initialize_fsmonitor_last_update(struct index_state *istate)
+{
+	struct strbuf last_update = STRBUF_INIT;
+
+	strbuf_addf(&last_update, "%"PRIu64"", getnanotime());
+	istate->fsmonitor_last_update = strbuf_detach(&last_update, NULL);
+}
+
 void add_fsmonitor(struct index_state *istate)
 {
 	unsigned int i;
-	struct strbuf last_update = STRBUF_INIT;
 
 	if (!istate->fsmonitor_last_update) {
 		trace_printf_key(&trace_fsmonitor, "add fsmonitor");
 		istate->cache_changed |= FSMONITOR_CHANGED;
-		strbuf_addf(&last_update, "%"PRIu64"", getnanotime());
-		istate->fsmonitor_last_update = strbuf_detach(&last_update, NULL);
+		initialize_fsmonitor_last_update(istate);
 
 		/* reset the fsmonitor state */
 		for (i = 0; i < istate->cache_nr; i++)
Signature · 1 line
gitgitgadget
#27 lore raw
In reply to Jeff Hostetler via GitGitGadget
Quoted 1 line · Jeff Hostetler via GitGitGadget

Here is version 2 of this series.

I didn't see this series in the "what's cooking" emails and was wondering if there was something that I still needed to attend to.

Thanks
Jeff

Quoted 97 lines

In version 1, I replaced the non-portable "xargs -d" with "xargs -0", but it turns out that that too is not universally available. In this version I replace the need for either one by filtering out the problematic paths (such as ones with LFs) and quoting paths to handle whitespace. The resulting paths can be passed to xargs without any arguments.

Also, I updated the test to use test-tool chmtime rather than touch to ensure that the files actually look dirty on low-resolution file systems.

Jeff Hostetler (10):
p7519: do not rely on "xargs -d" in test
p7519: fix watchman watch-list test on Windows
p7519: move watchman cleanup earlier in the test
p7519: add trace logging during perf test
preload-index: log the number of lstat calls to trace2
read-cache: log the number of lstat calls to trace2
read-cache: log the number of scanned files to trace2
fsmonitor: log invocation of FSMonitor hook to trace2
fsmonitor: log FSMN token when reading and writing the index
fsmonitor: refactor initialization of fsmonitor_last_update token

Kevin Willford (1):
fsmonitor: allow all entries for a folder to be invalidated

  fsmonitor.c               | 107 ++++++++++++++++++++++++++++++++++----
  fsmonitor.h               |   5 ++
  preload-index.c           |  10 ++++
  read-cache.c              |  24 +++++++--
  t/perf/.gitignore         |   1 +
  t/perf/Makefile           |   4 +-
  t/perf/p7519-fsmonitor.sh |  71 +++++++++++++++++++++----
  7 files changed, 196 insertions(+), 26 deletions(-)

base-commit: 71ca53e8125e36efbda17293c50027d31681a41f
Published-As: https://github.com/gitgitgadget/git/releases/tag/pr-860%2Fjeffhostetler%2Ffsmonitor-prework-v2
Fetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-860/jeffhostetler/fsmonitor-prework-v2
Pull-Request: https://github.com/gitgitgadget/git/pull/860

Range-diff vs v1:

1: cf252e24b8c ! 1: e570f7316cc p7519: use xargs -0 rather than -d in test
@@ Metadata
Author: Jeff Hostetler <[email protected]>

## Commit message ##
- p7519: use xargs -0 rather than -d in test
+ p7519: do not rely on "xargs -d" in test

- The Mac version of xargs does not support the "-d" option. Convert the test
- setup to pipe the data set thru lf_to_nul | xargs -0 instead.
+ Convert the test to use a more portable method to update the mtime on a
+ large number of files under version control.
+
+ The Mac version of xargs does not support the "-d" option.
+ Likewise, the "-0" and "--null" options are not portable.
+
+ Furthermore, use test-tool chmtime rather than touch to update the
+ mtime to ensure that it is actually updated (especially on file systems
+ with only whole second resolution).

## t/perf/p7519-fsmonitor.sh ##
@@ t/perf/p7519-fsmonitor.sh: test_fsmonitor_suite() {
+ git status -uall
'

++ # Update the mtimes on upto 100k files to make status think
++ # that they are dirty. For simplicity, omit any files with
++ # LFs (i.e. anything that ls-files thinks it needs to dquote).
++ # Then fully backslash-quote the paths to capture any
++ # whitespace so that they pass thru xargs properly.
++ #
test_perf_w_drop_caches "status (dirty) ($DESC)" '
- git ls-files | head -100000 | xargs -d "\n" touch -h &&
-+ git ls-files | head -100000 | lf_to_nul | xargs -0 touch -h &&
++ git ls-files | \
++ head -100000 | \
++ grep -v \" | \
++ sed '\''s/\(.\)/\\\1/g'\'' | \
++ xargs test-tool chmtime -300 &&
git status
'

   2:  a641f9e357c =  2:  3042fc92fe6 p7519: fix watchman watch-list test on Windows
   3:  2af6858716f =  3:  9ceba5e6942 p7519: move watchman cleanup earlier in the test
   4:  8de9985a706 =  4:  f6ea0a51f50 p7519: add trace logging during perf test
   5:  cdd49f1fdb1 =  5:  3c5035e4649 preload-index: log the number of lstat calls to trace2
   6:  65488f7a1bf =  6:  d150a2d4576 read-cache: log the number of lstat calls to trace2
   7:  c84531f6244 =  7:  33cc0b838fa read-cache: log the number of scanned files to trace2
   8:  ef64b60c7a0 =  8:  c043bccc8af fsmonitor: log invocation of FSMonitor hook to trace2
   9:  edb88ffe39e =  9:  6ec4a4468f6 fsmonitor: log FSMN token when reading and writing the index
  10:  384d2eff863 = 10:  2ac66f07a59 fsmonitor: allow all entries for a folder to be invalidated
  11:  4686196bbc6 = 11:  5410d3ab61d fsmonitor: refactor initialization of fsmonitor_last_update token
#28 lore raw
Quoted 6 lines · Jeff Hostetler
Quoted 1 line · Jeff Hostetler via GitGitGadget

Here is version 2 of this series.

I didn't see this series in the "what's cooking" emails and was wondering if there was something that I still needed to attend to.

I think it fell through the cracks. It seems that Taylor gave a reviewed-by for the whole set in v2 but as a reply to the cover letter of the original series, and no messages in v2 saw any comments.

I just picked them up and queued. Thanks for pinging.

#29 lore raw
In reply to Jeff Hostetler via GitGitGadget

Hi Jeff,

Quoted 5 lines · Jeff Hostetler via GitGitGadget

This patch series fixes runtime errors in t/perf/p7519 on Windows and MacOS. It adds Trace2 logging to p7519 to make it easier to compare results when Watchman is enabled and disabled. And finally, it adds some Trace2 regions and data events around our usage of Watchman and the existing FSMonitor framework.

I read v2 of this series and it all looked very sane to me. I didn't have much in the way of comments or concerns along the way, so that version of the series has my reviewed-by.

Thanks,
Taylor