We had to fix a couple of buggy progress lines in the past, where the
progress counter's final value didn't match the expected total [1],
e.g.:
Expanding reachable commits in commit graph: 138606% (824706/595), done.
Writing out commit graph in 3 passes: 166% (4187845/2512707), done.
Let's do better, and, instead of waiting for someone to notice such
issues by mere chance, start verifying progress counters in the test
suite: introduce the GIT_TEST_CHECK_PROGRESS knob to automatically
check that the final value of each progress counter matches the
expected total upon calling stop_progress(), and trigger a BUG() if it
doesn't.
This check should cover progress lines that are too fast to be shown,
because the repositories used in our tests are tiny and most of our
progress lines are delayed. However, in case of a delayed progress
line the variable holding the value of the progress counter
('progress->last_value') is only updated after that delay is up, and,
consequently, we can't compare the progress counter with the expected
total in stop_progress() in these cases.
So let's update 'progress->last_value' already during the initial
delay as well. This doesn't affect the visible behavior of progress
lines, though it results in additional invocations of the internal
display() function during the initial delay, but those don't make any
difference, because display() returns early without displaying
anything until the delay is up anyway.
Note that this can only check progress lines that are actually
started, i.e. that are shown by default even when standard error is
not a terminal, or that are forced to show with the '--progress'
option of whichever Git command displaying them.
Nonetheless, running the test suite with this new knob enabled results
in failures in 't0021-conversion.sh' and 't5510-fetch.sh', revealing
two more progress lines whose counter doesn't reach the expected
total. These will be fixed in later patches in this series, and after
that GIT_TEST_CHECK_PROGRESS will be enabled by default in the test
suite.
[1] c4ff24bbb3 (commit-graph.c: display correct number of chunks when
writing, 2021-02-24)
1cbdbf3bef (commit-graph: drop count_distinct_commits() function,
2020-12-07), though this didn't actually fixed, but
instead removed a buggy progress line.
150cd3b61d (commit-graph: fix "Writing out commit graph" progress
counter, 2020-07-09)
67fa6aac5a (commit-graph: don't show progress percentages while
expanding reachable commits, 2019-09-07)
531e6daa03 (prune-packed: advanced progress even for non-existing
fan-out directories, 2009-04-27)
Signed-off-by: SZEDER Gábor <szeder.dev@xxxxxxxxx>
---
progress.c | 16 ++++++++++++++--
t/t0500-progress-display.sh | 34 ++++++++++++++++++++++++++++++++++
2 files changed, 48 insertions(+), 2 deletions(-)
diff --git a/progress.c b/progress.c
index 680c6a8bf9..255995406f 100644
--- a/progress.c
+++ b/progress.c
@@ -47,6 +47,8 @@ struct progress {
static volatile sig_atomic_t progress_update;
+static int test_check_progress;
+
/*
* These are only intended for testing the progress output, i.e. exclusively
* for 'test-tool progress'.
@@ -111,10 +113,11 @@ static void display(struct progress *progress, uint64_t n, const char *done)
int show_update = 0;
int last_count_len = counters_sb->len;
+ progress->last_value = n;
+
if (progress->delay && (!progress_update || --progress->delay))
return;
- progress->last_value = n;
tp = (progress->throughput) ? progress->throughput->display.buf : "";
if (progress->total) {
unsigned percent = n * 100 / progress->total;
@@ -252,7 +255,11 @@ void display_progress(struct progress *progress, uint64_t n)
static struct progress *start_progress_delay(const char *title, uint64_t total,
unsigned delay, unsigned sparse)
{
- struct progress *progress = xmalloc(sizeof(*progress));
+ struct progress *progress;
+
+ test_check_progress = git_env_bool("GIT_TEST_CHECK_PROGRESS", 0);
+
+ progress = xmalloc(sizeof(*progress));
progress->title = title;
progress->total = total;
progress->last_value = -1;
@@ -349,6 +356,11 @@ void stop_progress_msg(struct progress **p_progress, const char *msg)
progress = *p_progress;
if (!progress)
return;
+ if (test_check_progress && progress->total &&
+ progress->total != progress->last_value)
+ BUG("total progress does not match for \"%s\": expected: %"PRIuMAX" got: %"PRIuMAX,
+ progress->title, (uintmax_t)progress->total,
+ (uintmax_t)progress->last_value);
*p_progress = NULL;
if (progress->last_value != -1) {
/* Force the last update */
diff --git a/t/t0500-progress-display.sh b/t/t0500-progress-display.sh
index 22058b503a..641fa0964e 100755
--- a/t/t0500-progress-display.sh
+++ b/t/t0500-progress-display.sh
@@ -308,4 +308,38 @@ test_expect_success 'progress generates traces' '
grep "\"key\":\"total_bytes\",\"value\":\"409600\"" trace.event
'
+test_expect_success 'GIT_TEST_CHECK_PROGRESS catches non-matching total' '
+ cat >in <<-\EOF &&
+ progress 1
+ progress 2
+ progress 4
+ EOF
+
+ test_must_fail env GIT_TEST_CHECK_PROGRESS=1 \
+ test-tool progress --total=3 "Not enough" <in 2>stderr &&
+ grep "BUG:.*total progress does not match" stderr &&
+
+ test_must_fail env GIT_TEST_CHECK_PROGRESS=1 \
+ test-tool progress --total=5 "Too much" <in 2>stderr &&
+ grep "BUG:.*total progress does not match" stderr
+'
+
+test_expect_success 'tolerate bogus progress without GIT_TEST_CHECK_PROGRESS' '
+ cat >expect <<-\EOF &&
+ Working hard: 33% (1/3)<CR>
+ Working hard: 33% (1/3), done.
+ EOF
+
+ cat >in <<-\EOF &&
+ progress 1
+ EOF
+ (
+ sane_unset GIT_TEST_CHECK_PROGRESS &&
+ test-tool progress --total=3 "Working hard" <in 2>stderr
+ ) &&
+
+ show_cr <stderr >out &&
+ test_cmp expect out
+'
+
test_done
--
2.32.0.289.g44fbea0957
