git@vger.kernel.org list mirror (unofficial, one of many)
 help / color / mirror / code / Atom feed
From: "SZEDER Gábor" <szeder.dev@gmail.com>
To: git@vger.kernel.org
Cc: "Ævar Arnfjörð Bjarmason" <avarab@gmail.com>,
	"René Scharfe" <l.s.r@web.de>,
	"SZEDER Gábor" <szeder.dev@gmail.com>
Subject: [PATCH 1/7] progress: introduce GIT_TEST_CHECK_PROGRESS to verify progress counters
Date: Sun, 20 Jun 2021 22:02:57 +0200	[thread overview]
Message-ID: <20210620200303.2328957-2-szeder.dev@gmail.com> (raw)
In-Reply-To: <20210620200303.2328957-1-szeder.dev@gmail.com>

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(-)

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


  reply	other threads:[~2021-06-20 20:03 UTC|newest]

Thread overview: 117+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2021-06-20 20:02 [PATCH 0/7] progress: verify progress counters in the test suite SZEDER Gábor
2021-06-20 20:02 ` SZEDER Gábor [this message]
2021-06-21  7:09   ` [PATCH 1/7] progress: introduce GIT_TEST_CHECK_PROGRESS to verify progress counters Ævar Arnfjörð Bjarmason
2021-06-22 15:55   ` Taylor Blau
2021-06-20 20:02 ` [PATCH 2/7] progress: catch nested/overlapping progresses with GIT_TEST_CHECK_PROGRESS SZEDER Gábor
2021-06-22 16:00   ` Taylor Blau
2021-08-30 21:15     ` SZEDER Gábor
2021-06-20 20:02 ` [PATCH 3/7] progress: catch backwards counting " SZEDER Gábor
2021-06-20 20:03 ` [PATCH 4/7] commit-graph: fix bogus counter in "Scanning merged commits" progress line SZEDER Gábor
2021-06-20 22:13   ` Ævar Arnfjörð Bjarmason
2021-06-21 18:32     ` René Scharfe
2021-06-21 20:08       ` Ævar Arnfjörð Bjarmason
2021-06-26  8:27         ` René Scharfe
2021-06-26 14:11           ` Ævar Arnfjörð Bjarmason
2021-06-26 20:22             ` René Scharfe
2021-06-26 21:38               ` Ævar Arnfjörð Bjarmason
2021-07-04 12:15                 ` René Scharfe
2021-07-05 14:09                   ` Junio C Hamano
2021-07-05 23:28                   ` Ævar Arnfjörð Bjarmason
2021-07-06 16:02                     ` René Scharfe
2021-06-27 17:31               ` Felipe Contreras
2021-06-20 20:03 ` [PATCH 5/7] entry: show finer-grained counter in "Filtering content" " SZEDER Gábor
2021-06-20 20:03 ` [PATCH 6/7] [RFC] entry: don't show "Filtering content: ... done." line in case of errors SZEDER Gábor
2021-06-21 18:32   ` René Scharfe
2021-06-23  1:52     ` Taylor Blau
2021-08-30 21:17       ` SZEDER Gábor
2021-06-20 20:03 ` [PATCH 7/7] test-lib: enable GIT_TEST_CHECK_PROGRESS by default SZEDER Gábor
2021-06-21  0:59 ` [PATCH 0/7] progress: verify progress counters in the test suite Ævar Arnfjörð Bjarmason
2021-06-23  2:04   ` Taylor Blau
2021-06-23 17:48     ` [PATCH 00/25] progress.c: various fixes + SZEDER's RFC code Ævar Arnfjörð Bjarmason
2021-06-23 17:48       ` [PATCH 01/25] progress.c tests: fix breakage with COLUMNS != 80 Ævar Arnfjörð Bjarmason
2021-06-23 17:48       ` [PATCH 02/25] progress.c tests: make start/stop verbs on stdin Ævar Arnfjörð Bjarmason
2021-06-23 17:48       ` [PATCH 03/25] progress.c tests: test some invalid usage Ævar Arnfjörð Bjarmason
2021-06-23 17:48       ` [PATCH 04/25] progress.c tests: add a "signal" verb Ævar Arnfjörð Bjarmason
2021-06-23 17:48       ` [PATCH 05/25] progress.c: move signal handler functions lower Ævar Arnfjörð Bjarmason
2021-06-23 17:48       ` [PATCH 06/25] progress.c: call progress_interval() from progress_test_force_update() Ævar Arnfjörð Bjarmason
2021-06-23 17:48       ` [PATCH 07/25] progress.c: stop eagerly fflush(stderr) when not a terminal Ævar Arnfjörð Bjarmason
2021-06-23 17:48       ` [PATCH 08/25] progress.c: add temporary variable from progress struct Ævar Arnfjörð Bjarmason
2021-06-23 17:48       ` [PATCH 09/25] midx perf: add a perf test for multi-pack-index Ævar Arnfjörð Bjarmason
2021-06-23 17:48       ` [PATCH 10/25] progress.c: remove the "sparse" mode nano-optimization Ævar Arnfjörð Bjarmason
2021-06-23 17:48       ` [PATCH 11/25] pack-bitmap-write.c: add a missing stop_progress() Ævar Arnfjörð Bjarmason
2021-09-17  5:14         ` SZEDER Gábor
2021-09-17  5:56           ` Ævar Arnfjörð Bjarmason
2021-09-17 21:38             ` SZEDER Gábor
2021-06-23 17:48       ` [PATCH 12/25] progress.c: add & assert a "global_progress" variable Ævar Arnfjörð Bjarmason
2021-09-16 18:31         ` SZEDER Gábor
2021-06-23 17:48       ` [PATCH 13/25] progress.[ch]: move the "struct progress" to the header Ævar Arnfjörð Bjarmason
2021-09-16 19:42         ` SZEDER Gábor
2021-06-23 17:48       ` [PATCH 14/25] progress.[ch]: move test-only code away from "extern" variables Ævar Arnfjörð Bjarmason
2021-06-23 17:48       ` [PATCH 15/25] progress.c: pass "is done?" (again) to display() Ævar Arnfjörð Bjarmason
2021-06-23 17:48       ` [PATCH 16/25] progress.[ch]: convert "title" to "struct strbuf" Ævar Arnfjörð Bjarmason
2021-06-23 17:48       ` [PATCH 17/25] progress.c: refactor display() for less confusion, and fix bug Ævar Arnfjörð Bjarmason
2021-06-23 17:48       ` [PATCH 18/25] progress.c: emit progress on first signal, show "stalled" Ævar Arnfjörð Bjarmason
2021-09-16 18:37         ` SZEDER Gábor
2021-06-23 17:48       ` [PATCH 19/25] commit-graph: fix bogus counter in "Scanning merged commits" progress line Ævar Arnfjörð Bjarmason
2021-06-23 17:48       ` [PATCH 20/25] midx: don't provide a total for QSORT() progress Ævar Arnfjörð Bjarmason
2021-06-23 17:48       ` [PATCH 21/25] entry: show finer-grained counter in "Filtering content" progress line Ævar Arnfjörð Bjarmason
2021-06-23 17:48       ` [PATCH 22/25] progress.c: add a stop_progress_early() function Ævar Arnfjörð Bjarmason
2021-06-24 10:35         ` Ævar Arnfjörð Bjarmason
2021-06-25  1:24         ` Andrei Rybak
2021-06-23 17:48       ` [PATCH 23/25] entry: deal with unexpected "Filtering content" total Ævar Arnfjörð Bjarmason
2021-06-23 17:48       ` [RFC/PATCH 24/25] progress: assert last update in stop_progress() Ævar Arnfjörð Bjarmason
2021-06-23 17:48       ` [RFC/PATCH 25/25] progress: assert counting upwards in display() Ævar Arnfjörð Bjarmason
2021-06-23 17:59       ` [PATCH 00/25] progress.c: various fixes + SZEDER's RFC code Randall S. Becker
2021-06-23 20:01         ` Ævar Arnfjörð Bjarmason
2021-06-23 20:25           ` Randall S. Becker
2021-06-23 21:57 ` [PATCH 0/4] WIP/POC check isatty(2)-protected progress lines SZEDER Gábor
2021-06-23 21:57   ` [PATCH 1/4] WIP progress, isatty(2), hidden progress lnies for GIT_TEST_CHECK_PROGRESS SZEDER Gábor
2021-06-23 21:57   ` [PATCH 2/4] blame: fix progress total with line ranges SZEDER Gábor
2021-06-23 21:57   ` [PATCH 3/4] read-cache: avoid overlapping progress lines SZEDER Gábor
2021-06-23 21:57   ` [PATCH 4/4] preload-index: fix "Refreshing index" progress line SZEDER Gábor
2021-06-23 22:11   ` [PATCH 0/4] WIP/POC check isatty(2)-protected progress lines SZEDER Gábor
2021-06-24 10:43     ` Ævar Arnfjörð Bjarmason
2021-06-24 10:45   ` Ævar Arnfjörð Bjarmason
2021-07-22 12:20 ` [PATCH 0/3] progress.c API users: fix bogus counting Ævar Arnfjörð Bjarmason
2021-07-22 12:20   ` [PATCH 1/3] commit-graph: fix bogus counter in "Scanning merged commits" progress line Ævar Arnfjörð Bjarmason
2021-07-23 21:55     ` Junio C Hamano
2021-08-02 21:07     ` SZEDER Gábor
2021-07-22 12:20   ` [PATCH 2/3] midx: don't provide a total for QSORT() progress Ævar Arnfjörð Bjarmason
2021-07-23 21:56     ` Junio C Hamano
2021-08-05 15:07     ` Phillip Wood
2021-08-05 19:07       ` Ævar Arnfjörð Bjarmason
2021-07-22 12:20   ` [PATCH 3/3] entry: show finer-grained counter in "Filtering content" progress line Ævar Arnfjörð Bjarmason
2021-07-23 22:01     ` Junio C Hamano
2021-08-02 22:05       ` SZEDER Gábor
2021-08-02 21:48     ` SZEDER Gábor
2021-08-05 11:01   ` [PATCH v2 0/3] progress.c API users: fix bogus counting Ævar Arnfjörð Bjarmason
2021-08-05 11:01     ` [PATCH v2 1/3] commit-graph: fix bogus counter in "Scanning merged commits" progress line Ævar Arnfjörð Bjarmason
2021-08-05 11:01     ` [PATCH v2 2/3] midx: don't provide a total for QSORT() progress Ævar Arnfjörð Bjarmason
2021-08-05 11:01     ` [PATCH v2 3/3] entry: show finer-grained counter in "Filtering content" progress line Ævar Arnfjörð Bjarmason
2021-08-23 10:29     ` [PATCH v3 0/2] progress.c API users: fix bogus counting Ævar Arnfjörð Bjarmason
2021-08-23 10:29       ` [PATCH v3 1/2] commit-graph: fix bogus counter in "Scanning merged commits" progress line Ævar Arnfjörð Bjarmason
2021-08-23 10:29       ` [PATCH v3 2/2] entry: show finer-grained counter in "Filtering content" " Ævar Arnfjörð Bjarmason
2021-09-09  1:10       ` [PATCH v4 0/2] progress.c API users: fix bogus counting Ævar Arnfjörð Bjarmason
2021-09-09  1:10         ` [PATCH v4 1/2] commit-graph: fix bogus counter in "Scanning merged commits" progress line Ævar Arnfjörð Bjarmason
2021-09-09  1:10         ` [PATCH v4 2/2] entry: show finer-grained counter in "Filtering content" " Ævar Arnfjörð Bjarmason
2021-09-09 20:02         ` [PATCH v4 0/2] progress.c API users: fix bogus counting Junio C Hamano
2021-07-22 12:54 ` [PATCH 0/8] progress: assert "global_progress" + test fixes / cleanup Ævar Arnfjörð Bjarmason
2021-07-22 12:54   ` [PATCH 1/8] progress.c tests: make start/stop verbs on stdin Ævar Arnfjörð Bjarmason
2021-07-22 12:55   ` [PATCH 2/8] progress.c tests: test some invalid usage Ævar Arnfjörð Bjarmason
2021-07-22 12:55   ` [PATCH 3/8] progress.c: move signal handler functions lower Ævar Arnfjörð Bjarmason
2021-07-22 12:55   ` [PATCH 4/8] progress.c: call progress_interval() from progress_test_force_update() Ævar Arnfjörð Bjarmason
2021-07-22 12:55   ` [PATCH 5/8] progress.c: stop eagerly fflush(stderr) when not a terminal Ævar Arnfjörð Bjarmason
2021-07-22 12:55   ` [PATCH 6/8] progress.c: add temporary variable from progress struct Ævar Arnfjörð Bjarmason
2021-07-22 12:55   ` [PATCH 7/8] pack-bitmap-write.c: add a missing stop_progress() Ævar Arnfjörð Bjarmason
2021-07-22 12:55   ` [PATCH 8/8] progress.c: add & assert a "global_progress" variable Ævar Arnfjörð Bjarmason
2021-09-16 21:34     ` [PATCH 12/25] " Ævar Arnfjörð Bjarmason
2021-07-23 22:02   ` [PATCH 0/8] progress: assert "global_progress" + test fixes / cleanup Junio C Hamano
2021-09-20 23:09   ` [PATCH v2 " Ævar Arnfjörð Bjarmason
2021-09-20 23:09     ` [PATCH v2 1/8] progress.c tests: make start/stop verbs on stdin Ævar Arnfjörð Bjarmason
2021-09-20 23:09     ` [PATCH v2 2/8] progress.c tests: test some invalid usage Ævar Arnfjörð Bjarmason
2021-09-20 23:09     ` [PATCH v2 3/8] progress.c: move signal handler functions lower Ævar Arnfjörð Bjarmason
2021-09-20 23:09     ` [PATCH v2 4/8] progress.c: call progress_interval() from progress_test_force_update() Ævar Arnfjörð Bjarmason
2021-09-20 23:09     ` [PATCH v2 5/8] progress.c: stop eagerly fflush(stderr) when not a terminal Ævar Arnfjörð Bjarmason
2021-09-20 23:09     ` [PATCH v2 6/8] progress.c: add temporary variable from progress struct Ævar Arnfjörð Bjarmason
2021-09-20 23:09     ` [PATCH v2 7/8] pack-bitmap-write.c: add a missing stop_progress() Ævar Arnfjörð Bjarmason
2021-09-20 23:09     ` [PATCH v2 8/8] progress.c: add & assert a "global_progress" variable Ævar Arnfjörð Bjarmason

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

  List information: http://vger.kernel.org/majordomo-info.html

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=20210620200303.2328957-2-szeder.dev@gmail.com \
    --to=szeder.dev@gmail.com \
    --cc=avarab@gmail.com \
    --cc=git@vger.kernel.org \
    --cc=l.s.r@web.de \
    --subject='Re: [PATCH 1/7] progress: introduce GIT_TEST_CHECK_PROGRESS to verify progress counters' \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link

Code repositories for project(s) associated with this inbox:

	https://80x24.org/mirrors/git.git

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).