Re: t4216-log-bloom.sh fails with -v (but not --verbose-log)

On Thu, Nov 25, 2021 at 01:14:45PM +0100, Ævar Arnfjörð Bjarmason wrote:

I haven't looked much into $subject, but there's an interesting
regression in 2ca245f8be5 (csum-file.h: increase hashfile buffer size,
2021-05-18) where it fails with -v, but not --verbose-log. Discovered
while running it manually.

This is a regression in v2.33.0 (not v2.34.0!), so nothing urgent, and
this is pretty obscure anyway.

For the original change see:
https://lore.kernel.org/git/64ffddd791160895b8e6730ebcddfac8458653f2.1621362768.git.gitgitgadget@gmail.com/ (local)

Interesting. This patch makes it go away (the "5" is cargo-culted from
earlier in the script):

diff --git a/t/t4216-log-bloom.sh b/t/t4216-log-bloom.sh
index 50f206db55..2f3a1cd210 100755
--- a/t/t4216-log-bloom.sh
+++ b/t/t4216-log-bloom.sh

@@ -231,6 +231,7 @@ test_expect_success 'correctly report changes over limit' '
 
 		# Commit has 7 file and 4 directory adds
 		GIT_TEST_BLOOM_SETTINGS_MAX_CHANGED_PATHS=10 \
+			GIT_TRACE2_EVENT_NESTING=5 \
 			GIT_TRACE2_EVENT="$(pwd)/trace" \
 			git commit-graph write --reachable --changed-paths &&
 		test_max_changed_paths 10 trace &&

@@ -263,6 +264,7 @@ test_expect_success 'correctly report changes over limit' '
 		# start from scratch and rebuild
 		rm -f .git/objects/info/commit-graph &&
 		GIT_TEST_BLOOM_SETTINGS_MAX_CHANGED_PATHS=10 \
+			GIT_TRACE2_EVENT_NESTING=5 \
 			GIT_TRACE2_EVENT="$(pwd)/trace-edit" \
 			git commit-graph write --reachable --changed-paths &&
 		test_max_changed_paths 10 trace-edit &&

@@ -280,6 +282,7 @@ test_expect_success 'correctly report changes over limit' '
 		# start from scratch and rebuild
 		rm -f .git/objects/info/commit-graph &&
 		GIT_TEST_BLOOM_SETTINGS_MAX_CHANGED_PATHS=11 \
+			GIT_TRACE2_EVENT_NESTING=5 \
 			GIT_TRACE2_EVENT="$(pwd)/trace-update" \
 			git commit-graph write --reachable --changed-paths &&
 		test_max_changed_paths 11 trace-update &&

The commit in question (2ca245f8be) puts the writing into a new trace2
region ("chunkfile"), so it makes sense that the nesting increases by
one. But what's interesting is that the nesting is different depending
on whether stderr is a terminal. I guess because the progress code
starts its own region.

The default nesting max for trace2 is 2. That seems kind of low given
this example, but I don't know enough about the tradeoffs to say what
bad things might happen if it's raised. But the above patch really seems
like a hack, and that this quiet omission would absolutely confuse real
users who are trying to use trace2 for debugging.

-Peff