Update fsmonitor perf suite to support integration comparisons

This patch series builds upon nk/diff-files-vs-fsmonitor

This builds up to a comparison between our perl script and
https://github.com/jgavris/rs-git-fsmonitor. Stats on the comparison are in the final commit message. I've found that rs-git-fsmonitor saves 20-30ms off of every git command compared to the perl script.

It may provide some motivation for supplying a faster implementation of fsmonitor-watchman.

Nipunn Koorapati (10):
t/perf/fsmonitor: separate one time repo initialization t/perf/fsmonitor: move watchman setup to one-time-repo-setup t/perf/fsmonitor: improve error message if typoing hook name t/perf/fsmonitor: factor description out for readability t/perf/fsmonitor: shorten DESC to basename t/perf/fsmonitor: silence initial git commit t/perf/fsmonitor: factor setup for fsmonitor into function t/perf/fsmonitor: initialize test with git reset t/perf/fsmonitor: perf comparison of multiple fsmonitor integrations t/perf/fsmonitor: add benchmark for dirty status

 t/perf/p7519-fsmonitor.sh | 94 ++++++++++++++++++++++++++-------------
 1 file changed, 63 insertions(+), 31 deletions(-)

base-commit: 2bfa953e5daf3253cc5fae2de2c68fbd206dfe12
Published-As: https://github.com/gitgitgadget/git/releases/tag/pr-772%2Fnipunn1313%2Fnk%2Ffsmonitor-perf-suite-v1
Fetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-772/nipunn1313/nk/fsmonitor-perf-suite-v1
Pull-Request: https://github.com/gitgitgadget/git/pull/772

gitgitgadget

From: Nipunn Koorapati <[email protected]>

In preparation for testing multiple fsmonitor hooks

---
 t/perf/p7519-fsmonitor.sh | 19 +++++++++++--------
 1 file changed, 11 insertions(+), 8 deletions(-)

index fb20fe0937..23755012df 100755
@@ -68,7 +68,7 @@ then
 	fi
 fi
 
-test_expect_success "setup for fsmonitor" '
+test_expect_success "one time repo setup" '
 	# set untrackedCache depending on the environment
 	if test -n "$GIT_PERF_7519_UNTRACKED_CACHE"
 	then

@@ -88,6 +88,16 @@ test_expect_success "setup for fsmonitor" '
 		git config core.splitIndex "$GIT_PERF_7519_SPLIT_INDEX"
 	fi &&
 
+	mkdir 1_file 10_files 100_files 1000_files 10000_files &&
+	for i in $(test_seq 1 10); do touch 10_files/$i; done &&
+	for i in $(test_seq 1 100); do touch 100_files/$i; done &&
+	for i in $(test_seq 1 1000); do touch 1000_files/$i; done &&
+	for i in $(test_seq 1 10000); do touch 10000_files/$i; done &&
+	git add 1_file 10_files 100_files 1000_files 10000_files &&
+	git commit -m "Add files"
+'
+
+test_expect_success "setup for fsmonitor" '
 	# set INTEGRATION_SCRIPT depending on the environment
 	if test -n "$GIT_PERF_7519_FSMONITOR"
 	then

@@ -115,13 +125,6 @@ test_expect_success "setup for fsmonitor" '
 
 	git config core.fsmonitor "$INTEGRATION_SCRIPT" &&
 	git update-index --fsmonitor &&
-	mkdir 1_file 10_files 100_files 1000_files 10000_files &&
-	for i in $(test_seq 1 10); do touch 10_files/$i; done &&
-	for i in $(test_seq 1 100); do touch 100_files/$i; done &&
-	for i in $(test_seq 1 1000); do touch 1000_files/$i; done &&
-	for i in $(test_seq 1 10000); do touch 10000_files/$i; done &&
-	git add 1_file 10_files 100_files 1000_files 10000_files &&
-	git commit -m "Add files" &&
 	git status  # Warm caches
 '
 

gitgitgadget

From: Nipunn Koorapati <[email protected]>

It is only required to be set up once. This prepares for testing multiple hooks in one invocation.

---
 t/perf/p7519-fsmonitor.sh | 16 +++++++++-------
 1 file changed, 9 insertions(+), 7 deletions(-)

index 23755012df..4030f569cf 100755
@@ -94,7 +94,13 @@ test_expect_success "one time repo setup" '
 	for i in $(test_seq 1 1000); do touch 1000_files/$i; done &&
 	for i in $(test_seq 1 10000); do touch 10000_files/$i; done &&
 	git add 1_file 10_files 100_files 1000_files 10000_files &&
-	git commit -m "Add files"
+	git commit -m "Add files" &&
+
+	# 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"
+	fi
 '
 
 test_expect_success "setup for fsmonitor" '

@@ -105,17 +111,13 @@ test_expect_success "setup for fsmonitor" '
 	else
 		#
 		# Choose integration script based on existence of Watchman.
-		# If Watchman exists, watch the work tree and attempt a query.
-		# If everything succeeds, use Watchman integration script,
-		# else fall back to an empty integration script.
+		# Fall back to an empty integration script.
 		#
 		mkdir .git/hooks &&
 		if test_have_prereq WATCHMAN
 		then
 			INTEGRATION_SCRIPT=".git/hooks/fsmonitor-watchman" &&
-			cp "$TEST_DIRECTORY/../templates/hooks--fsmonitor-watchman.sample" "$INTEGRATION_SCRIPT" &&
-			watchman watch "$GIT_WORK_TREE" &&
-			watchman watch-list | grep -q -F "$GIT_WORK_TREE"
+			cp "$TEST_DIRECTORY/../templates/hooks--fsmonitor-watchman.sample" "$INTEGRATION_SCRIPT"
 		else
 			INTEGRATION_SCRIPT=".git/hooks/fsmonitor-empty" &&
 			write_script "$INTEGRATION_SCRIPT"<<-\EOF

gitgitgadget

From: Nipunn Koorapati <[email protected]>

Previously - it would silently run the perf suite w/o using fsmonitor - fsmonitor errors are not hard failures. Now it errors loudly.

GIT_PERF_7519_FSMONITOR="$HOME/rs-git-fsmonitorr" ./p7519-fsmonitor.sh -i -v

fatal: cannot run /home/nipunn/rs-git-fsmonitorr:
No such file or directory
not ok 2 - setup for fsmonitor

---
 t/perf/p7519-fsmonitor.sh | 4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

index 4030f569cf..88b3717e2a 100755
@@ -126,7 +126,9 @@ test_expect_success "setup for fsmonitor" '
 	fi &&
 
 	git config core.fsmonitor "$INTEGRATION_SCRIPT" &&
-	git update-index --fsmonitor &&
+	git update-index --fsmonitor 2>error &&
+	cat error &&
+	[ ! -s error ] && # ensure no silent error
 	git status  # Warm caches
 '
 

gitgitgadget

Everything in test-lib should be available - so yes! I can try it out and switch to it in the next roll of this patch series. I did not realize this helper was available. Thank you.
--Nipunn

From: Nipunn Koorapati <[email protected]>

There was much duplication here. Prepares for making changes to the description.

---
 t/perf/p7519-fsmonitor.sh | 22 ++++++++++++----------
 1 file changed, 12 insertions(+), 10 deletions(-)

index 88b3717e2a..aa6b82d756 100755
@@ -141,43 +141,45 @@ test_perf_w_drop_caches () {
 }
 
 test_fsmonitor_suite() {
-	test_perf_w_drop_caches "status (fsmonitor=$INTEGRATION_SCRIPT)" '
+	DESC="fsmonitor=$INTEGRATION_SCRIPT"
+
+	test_perf_w_drop_caches "status ($DESC)" '
 		git status
 	'
 
-	test_perf_w_drop_caches "status -uno (fsmonitor=$INTEGRATION_SCRIPT)" '
+	test_perf_w_drop_caches "status -uno ($DESC)" '
 		git status -uno
 	'
 
-	test_perf_w_drop_caches "status -uall (fsmonitor=$INTEGRATION_SCRIPT)" '
+	test_perf_w_drop_caches "status -uall ($DESC)" '
 		git status -uall
 	'
 
-	test_perf_w_drop_caches "diff (fsmonitor=$INTEGRATION_SCRIPT)" '
+	test_perf_w_drop_caches "diff ($DESC)" '
 		git diff
 	'
 
-	test_perf_w_drop_caches "diff -- 0_files (fsmonitor=$INTEGRATION_SCRIPT)" '
+	test_perf_w_drop_caches "diff -- 0_files ($DESC)" '
 		git diff -- 1_file
 	'
 
-	test_perf_w_drop_caches "diff -- 10_files (fsmonitor=$INTEGRATION_SCRIPT)" '
+	test_perf_w_drop_caches "diff -- 10_files ($DESC)" '
 		git diff -- 10_files
 	'
 
-	test_perf_w_drop_caches "diff -- 100_files (fsmonitor=$INTEGRATION_SCRIPT)" '
+	test_perf_w_drop_caches "diff -- 100_files ($DESC)" '
 		git diff -- 100_files
 	'
 
-	test_perf_w_drop_caches "diff -- 1000_files (fsmonitor=$INTEGRATION_SCRIPT)" '
+	test_perf_w_drop_caches "diff -- 1000_files ($DESC)" '
 		git diff -- 1000_files
 	'
 
-	test_perf_w_drop_caches "diff -- 10000_files (fsmonitor=$INTEGRATION_SCRIPT)" '
+	test_perf_w_drop_caches "diff -- 10000_files ($DESC)" '
 		git diff -- 10000_files
 	'
 
-	test_perf_w_drop_caches "add (fsmonitor=$INTEGRATION_SCRIPT)" '
+	test_perf_w_drop_caches "add ($DESC)" '
 		git add  --all
 	'
 }

gitgitgadget

From: Nipunn Koorapati <[email protected]>

The full name is lengthy and makes it hard to read
Before:
7519.3: status (fsmonitor=/home/nipunn/src/server/.git/hooks/rs-git-fsmonitor) 0.02(0.01+0.00)

After
7519.3: status (fsmonitor=rs-git-fsmonitor) 0.03(0.02+0.00)

---
 t/perf/p7519-fsmonitor.sh | 6 +++++-
 1 file changed, 5 insertions(+), 1 deletion(-)

index aa6b82d756..2c817db1ae 100755
@@ -141,7 +141,11 @@ test_perf_w_drop_caches () {
 }
 
 test_fsmonitor_suite() {
-	DESC="fsmonitor=$INTEGRATION_SCRIPT"
+	if test -n "$INTEGRATION_SCRIPT"; then
+		DESC="fsmonitor=$(basename $INTEGRATION_SCRIPT)"
+	else
+		DESC="fsmonitor=disabled"
+	fi
 
 	test_perf_w_drop_caches "status ($DESC)" '
 		git status

gitgitgadget

From: Nipunn Koorapati <[email protected]>

It is extremely verbose, printing >10K non-useful lines

---
 t/perf/p7519-fsmonitor.sh | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

index 2c817db1ae..970caff3d2 100755
@@ -94,7 +94,7 @@ test_expect_success "one time repo setup" '
 	for i in $(test_seq 1 1000); do touch 1000_files/$i; done &&
 	for i in $(test_seq 1 10000); do touch 10000_files/$i; done &&
 	git add 1_file 10_files 100_files 1000_files 10000_files &&
-	git commit -m "Add files" &&
+	git commit -qm "Add files" &&
 
 	# If Watchman exists, watch the work tree and attempt a query.
 	if test_have_prereq WATCHMAN; then

gitgitgadget

From: Nipunn Koorapati <[email protected]>

This prepares for it being called multiple times when testing different hooks

---
 t/perf/p7519-fsmonitor.sh | 8 ++++++--
 1 file changed, 6 insertions(+), 2 deletions(-)

index 970caff3d2..087f66ecc2 100755
@@ -103,7 +103,7 @@ test_expect_success "one time repo setup" '
 	fi
 '
 
-test_expect_success "setup for fsmonitor" '
+setup_for_fsmonitor() {
 	# set INTEGRATION_SCRIPT depending on the environment
 	if test -n "$GIT_PERF_7519_FSMONITOR"
 	then

@@ -130,7 +130,7 @@ test_expect_success "setup for fsmonitor" '
 	cat error &&
 	[ ! -s error ] && # ensure no silent error
 	git status  # Warm caches
-'
+}
 
 test_perf_w_drop_caches () {
 	if test -n "$GIT_PERF_7519_DROP_CACHE"; then

@@ -188,6 +188,10 @@ test_fsmonitor_suite() {
 	'
 }
 
+test_expect_success "setup for fsmonitor" '
+	setup_for_fsmonitor
+'
+
 test_fsmonitor_suite
 
 test_expect_success "setup without fsmonitor" '

gitgitgadget

From: Nipunn Koorapati <[email protected]>

Previously, the git add of the previous suiterun would pollute the numbers in the second run

Before:
Test this tree
-----------------------------------------------------------------------------

7519.4: status (fsmonitor=fsmonitor-watchman)                 0.40(0.36+0.04)
7519.5: status -uno (fsmonitor=fsmonitor-watchman)            0.19(0.12+0.07)
7519.6: status -uall (fsmonitor=fsmonitor-watchman)           1.36(0.74+0.61)
7519.7: diff (fsmonitor=fsmonitor-watchman)                   0.14(0.10+0.04)
7519.8: diff -- 0_files (fsmonitor=fsmonitor-watchman)        0.14(0.10+0.04)
7519.9: diff -- 10_files (fsmonitor=fsmonitor-watchman)       0.14(0.09+0.05)
7519.10: diff -- 100_files (fsmonitor=fsmonitor-watchman)     0.14(0.10+0.04)
7519.11: diff -- 1000_files (fsmonitor=fsmonitor-watchman)    0.14(0.08+0.06)
7519.12: diff -- 10000_files (fsmonitor=fsmonitor-watchman)   0.14(0.10+0.04)
7519.13: add (fsmonitor=fsmonitor-watchman)                   2.03(1.28+0.69)
7519.16: status (fsmonitor=disabled)                          0.64(0.49+0.90)
7519.17: status -uno (fsmonitor=disabled)                     1.15(0.92+1.00)
7519.18: status -uall (fsmonitor=disabled)                    2.32(1.46+1.55)
7519.19: diff (fsmonitor=disabled)                            1.44(1.12+1.76)
7519.20: diff -- 0_files (fsmonitor=disabled)                 0.11(0.07+0.05)
7519.21: diff -- 10_files (fsmonitor=disabled)                0.11(0.06+0.05)
7519.22: diff -- 100_files (fsmonitor=disabled)               0.11(0.08+0.03)
7519.23: diff -- 1000_files (fsmonitor=disabled)              0.11(0.08+0.04)
7519.24: diff -- 10000_files (fsmonitor=disabled)             0.12(0.06+0.07)
7519.25: add (fsmonitor=disabled)                             2.25(1.47+1.47)

After:
Test this tree
-----------------------------------------------------------------------------

7519.4: status (fsmonitor=fsmonitor-watchman)                 0.41(0.33+0.09)
7519.5: status -uno (fsmonitor=fsmonitor-watchman)            0.20(0.14+0.07)
7519.6: status -uall (fsmonitor=fsmonitor-watchman)           1.37(0.78+0.58)
7519.7: diff (fsmonitor=fsmonitor-watchman)                   0.14(0.10+0.04)
7519.8: diff -- 0_files (fsmonitor=fsmonitor-watchman)        0.14(0.08+0.06)
7519.9: diff -- 10_files (fsmonitor=fsmonitor-watchman)       0.14(0.09+0.05)
7519.10: diff -- 100_files (fsmonitor=fsmonitor-watchman)     0.14(0.10+0.05)
7519.11: diff -- 1000_files (fsmonitor=fsmonitor-watchman)    0.14(0.11+0.04)
7519.12: diff -- 10000_files (fsmonitor=fsmonitor-watchman)   0.14(0.09+0.05)
7519.13: add (fsmonitor=fsmonitor-watchman)                   2.04(1.27+0.71)
7519.16: status (fsmonitor=disabled)                          0.78(0.59+0.99)
7519.17: status -uno (fsmonitor=disabled)                     0.43(0.32+0.88)
7519.18: status -uall (fsmonitor=disabled)                    1.58(0.96+1.38)
7519.19: diff (fsmonitor=disabled)                            0.36(0.31+0.79)
7519.20: diff -- 0_files (fsmonitor=disabled)                 0.11(0.08+0.03)
7519.21: diff -- 10_files (fsmonitor=disabled)                0.11(0.07+0.04)
7519.22: diff -- 100_files (fsmonitor=disabled)               0.11(0.08+0.04)
7519.23: diff -- 1000_files (fsmonitor=disabled)              0.11(0.07+0.05)
7519.24: diff -- 10000_files (fsmonitor=disabled)             0.12(0.08+0.05)
7519.25: add (fsmonitor=disabled)                             2.25(1.48+1.47)

---
 t/perf/p7519-fsmonitor.sh | 8 ++++++--
 1 file changed, 6 insertions(+), 2 deletions(-)

index 087f66ecc2..51c03a2596 100755
@@ -128,8 +128,7 @@ setup_for_fsmonitor() {
 	git config core.fsmonitor "$INTEGRATION_SCRIPT" &&
 	git update-index --fsmonitor 2>error &&
 	cat error &&
-	[ ! -s error ] && # ensure no silent error
-	git status  # Warm caches
+	[ ! -s error ] # ensure no silent error
 }
 
 test_perf_w_drop_caches () {

@@ -147,6 +146,11 @@ test_fsmonitor_suite() {
 		DESC="fsmonitor=disabled"
 	fi
 
+	test_expect_success "test_initialization" '
+		git reset --hard &&
+		git status  # Warm caches
+	'
+
 	test_perf_w_drop_caches "status ($DESC)" '
 		git status
 	'

gitgitgadget

From: Nipunn Koorapati <[email protected]>

Allows for simple perf comparison of different integrations. I ran it to compare our perl script w/ rs-git-fsmonitor and found 20-30ms of overhead on every command.

Output looks like this (extra newlines added for readability)

Test this tree
---------------------------------------------------------------------------

7519.4: status (fsmonitor=query-watchman)                   0.42(0.37+0.05)
7519.5: status -uno (fsmonitor=query-watchman)              0.19(0.12+0.07)
7519.6: status -uall (fsmonitor=query-watchman)             1.36(0.73+0.62)
7519.7: diff (fsmonitor=query-watchman)                     0.14(0.09+0.05)
7519.8: diff -- 0_files (fsmonitor=query-watchman)          0.14(0.11+0.03)
7519.9: diff -- 10_files (fsmonitor=query-watchman)         0.14(0.10+0.04)
7519.10: diff -- 100_files (fsmonitor=query-watchman)       0.14(0.09+0.05)
7519.11: diff -- 1000_files (fsmonitor=query-watchman)      0.14(0.08+0.06)
7519.12: diff -- 10000_files (fsmonitor=query-watchman)     0.14(0.09+0.05)
7519.13: add (fsmonitor=query-watchman)                     2.04(1.32+0.66)

7519.16: status (fsmonitor=rs-git-fsmonitor)                0.39(0.32+0.08)
7519.17: status -uno (fsmonitor=rs-git-fsmonitor)           0.17(0.11+0.06)
7519.18: status -uall (fsmonitor=rs-git-fsmonitor)          1.33(0.71+0.61)
7519.19: diff (fsmonitor=rs-git-fsmonitor)                  0.11(0.07+0.04)
7519.20: diff -- 0_files (fsmonitor=rs-git-fsmonitor)       0.11(0.09+0.03)
7519.21: diff -- 10_files (fsmonitor=rs-git-fsmonitor)      0.11(0.09+0.03)
7519.22: diff -- 100_files (fsmonitor=rs-git-fsmonitor)     0.11(0.07+0.04)
7519.23: diff -- 1000_files (fsmonitor=rs-git-fsmonitor)    0.11(0.06+0.06)
7519.24: diff -- 10000_files (fsmonitor=rs-git-fsmonitor)   0.11(0.06+0.06)
7519.25: add (fsmonitor=rs-git-fsmonitor)                   2.03(1.28+0.69)

7519.28: status (fsmonitor=disabled)                        0.77(0.59+0.99)
7519.29: status -uno (fsmonitor=disabled)                   0.42(0.33+0.85)
7519.30: status -uall (fsmonitor=disabled)                  1.59(1.02+1.34)
7519.31: diff (fsmonitor=disabled)                          0.35(0.30+0.81)
7519.32: diff -- 0_files (fsmonitor=disabled)               0.11(0.08+0.04)
7519.33: diff -- 10_files (fsmonitor=disabled)              0.11(0.07+0.04)
7519.34: diff -- 100_files (fsmonitor=disabled)             0.11(0.08+0.03)
7519.35: diff -- 1000_files (fsmonitor=disabled)            0.11(0.10+0.02)
7519.36: diff -- 10000_files (fsmonitor=disabled)           0.12(0.07+0.06)
7519.37: add (fsmonitor=disabled)                           2.24(1.48+1.44)

---
 t/perf/p7519-fsmonitor.sh | 22 ++++++++++++++--------
 1 file changed, 14 insertions(+), 8 deletions(-)

index 51c03a2596..577f79d455 100755
@@ -22,7 +22,9 @@ test_description="Test core.fsmonitor"
 #
 # GIT_PERF_7519_UNTRACKED_CACHE: used to configure core.untrackedCache
 # GIT_PERF_7519_SPLIT_INDEX: used to configure core.splitIndex
-# GIT_PERF_7519_FSMONITOR: used to configure core.fsMonitor
+# GIT_PERF_7519_FSMONITOR: used to configure core.fsMonitor. May be an
+#   absolute path to an integration. May be a space delimited list of
+#   absolute paths to integrations.
 #
 # The big win for using fsmonitor is the elimination of the need to scan the
 # working directory looking for changed and untracked files. If the file

@@ -105,9 +107,9 @@ test_expect_success "one time repo setup" '
 
 setup_for_fsmonitor() {
 	# set INTEGRATION_SCRIPT depending on the environment
-	if test -n "$GIT_PERF_7519_FSMONITOR"
+	if test -n "$INTEGRATION_PATH"
 	then
-		INTEGRATION_SCRIPT="$GIT_PERF_7519_FSMONITOR"
+		INTEGRATION_SCRIPT="$INTEGRATION_PATH"
 	else
 		#
 		# Choose integration script based on existence of Watchman.

@@ -192,11 +194,15 @@ test_fsmonitor_suite() {
 	'
 }
 
-test_expect_success "setup for fsmonitor" '
-	setup_for_fsmonitor
-'
-
-test_fsmonitor_suite
+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'
+		test_fsmonitor_suite
+	done
+else
+	test_expect_success "setup for fsmonitor" 'setup_for_fsmonitor'
+	test_fsmonitor_suite
+fi
 
 test_expect_success "setup without fsmonitor" '
 	unset INTEGRATION_SCRIPT &&

gitgitgadget

From: Nipunn Koorapati <[email protected]>

This benchmark covers the git status time for a heavily dirty directory - benchmarking fsmonitor's refresh

When running to compare our perl vs rs-git-fsmonitor - we see that the perl script incurs significant overhead - further motivation to provide a faster implementation within git.

7519.7: status (dirty) (fsmonitor=query-watchman) 10.05(7.78+1.56) 7519.20: status (dirty) (fsmonitor=rs-git-fsmonitor) 6.72(4.37+1.64) 7519.33: status (dirty) (fsmonitor=disabled) 5.62(4.24+2.03)

---
 t/perf/p7519-fsmonitor.sh | 5 +++++
 1 file changed, 5 insertions(+)

index 577f79d455..163a13bea3 100755
@@ -165,6 +165,11 @@ test_fsmonitor_suite() {
 		git status -uall
 	'
 
+	test_perf_w_drop_caches "status (dirty) ($DESC)" '
+		git ls-files | head -100000 | xargs -d "\n" touch -h &&
+		git status
+	'
+
 	test_perf_w_drop_caches "diff ($DESC)" '
 		git diff
 	'

gitgitgadget