| Message ID | 20210620200303.2328957-2-szeder.dev@gmail.com (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
| Series | progress: verify progress counters in the test suite | expand |
On Sun, Jun 20 2021, SZEDER Gábor wrote: > @@ -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)); Is this simply an unrelated cleanup/refactoring? I don't see how this re-arrangement is needed for adding the git_env_bool() call.
On Sun, Jun 20, 2021 at 10:02:57PM +0200, SZEDER Gábor wrote: > + progress->last_value = n; > + > if (progress->delay && (!progress_update || --progress->delay)) > return; > > - progress->last_value = n; Makes sense, and thanks for explaining it explicitly in the patch message. > 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)); Ævar noted below, I think, but this cleanup to move the xmalloc() call to after reading $GIT_TEST_CHECK_PROGRESS is unnecessary. > +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 > +' This and the below test are both good to see. I wondered briefly whether or not it would be worth adding a test to check that the "progress does not match" triggers even when we have a non-zero delay, like: test_must_fail env GIT_PROGRESS_DELAY=100 GIT_TEST_CHECK_PROGRESS=1 \ test-tool progress --total=5 "Too much" <in 2>stderr && grep "BUG:.*total progress does not match" stderr But it's not helpful, because GIT_PROGRESS_DELAY is already 2 by default, and we unset GIT_* environment variables (including GIT_PROGRESS_DELAY) except a few which are left alone. So we are already testing this case implicitly. It may be worth making it explicit, and/or testing the case where GIT_PROGRESS_DELAY=0, but I do not feel strongly about it. Besides, I would much rather err on the side of testing cases we feel are legitimately interesting, rather than filling in a grid of all possible combinations, including uninteresting ones. Thanks, Taylor
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
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@gmail.com> --- progress.c | 16 ++++++++++++++-- t/t0500-progress-display.sh | 34 ++++++++++++++++++++++++++++++++++ 2 files changed, 48 insertions(+), 2 deletions(-)