git@vger.kernel.org list mirror (unofficial, one of many)
 help / color / mirror / code / Atom feed
From: "Ævar Arnfjörð Bjarmason" <avarab@gmail.com>
To: git@vger.kernel.org
Cc: "Junio C Hamano" <gitster@pobox.com>,
	"SZEDER Gábor" <szeder.dev@gmail.com>,
	"René Scharfe" <l.s.r@web.de>, "Taylor Blau" <me@ttaylorr.com>,
	"Ævar Arnfjörð Bjarmason" <avarab@gmail.com>
Subject: [RFC/PATCH 24/25] progress: assert last update in stop_progress()
Date: Wed, 23 Jun 2021 19:48:24 +0200	[thread overview]
Message-ID: <patch-24.25-37b3d1e4d9d-20210623T155626Z-avarab@gmail.com> (raw)
In-Reply-To: <cover-00.25-00000000000-20210623T155626Z-avarab@gmail.com>

From: SZEDER Gábor <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. Let's track what the last display_progress() value was, and if
it doesn't match the total at the end invoke BUG().

We need to introduce a "last_update" distinct from "last_value" for
this, since the "last_value" really means "last displayed value", and
the logic in display() relies on it having those semantics.

Using the "last_value" would also leave us with a subtle case where
this assertion wouldn't catch broken API uses, as an earlier version
of this change did.

Even if that was not the case we couldn't rely on it for the purposes
of this assertion. In the case of a delayed progress 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. Thus this check will 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.

What it can't cover is code that doesn't start the progress bar at
all, e.g. due to its own isatty() check, so progress that is only
started and shown when standard error is not a terminal won't be
covered by our tests.

[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>
Signed-off-by: Ævar Arnfjörð Bjarmason <avarab@gmail.com>
---

WARNING: I belive this is subtly buggy, see the discussion in the
cover letter. It needs more fixes of the progress.c API usage in
various places before being ready.

 progress.c                  |  8 ++++++++
 t/t0500-progress-display.sh | 30 +++++++++++++++++++++++++++++-
 2 files changed, 37 insertions(+), 1 deletion(-)

diff --git a/progress.c b/progress.c
index c1cb01ba975..40043bf6601 100644
--- a/progress.c
+++ b/progress.c
@@ -325,6 +325,7 @@ static struct progress *start_progress_delay(const char *title, uint64_t total,
 
 	progress->total = total;
 	progress->last_value = -1;
+	progress->last_update = -1;
 	progress->last_percent = -1;
 	progress->delay = delay;
 	progress->throughput = NULL;
@@ -393,6 +394,13 @@ void stop_progress_msg(struct progress **p_progress, const char *msg)
 	if (!progress)
 		return;
 	*p_progress = NULL;
+
+	if (progress->total &&
+	    progress->total != progress->last_update)
+		BUG("total progress does not match for \"%*s\": expected: %"PRIuMAX" got: %"PRIuMAX,
+		    (int)(progress->status_len_utf8), progress->title.buf,
+		    (uintmax_t)progress->total,
+		    (uintmax_t)progress->last_update);
 	if (progress->last_value != -1) {
 		/* Force the last update */
 		struct throughput *tp = progress->throughput;
diff --git a/t/t0500-progress-display.sh b/t/t0500-progress-display.sh
index bc458cfc28b..3f00e52ce46 100755
--- a/t/t0500-progress-display.sh
+++ b/t/t0500-progress-display.sh
@@ -96,7 +96,8 @@ Working hard.......2.........3.........4.........5.........6.........7:
     0% (0/100), stalled.<CR>
     1% (1/100)          <CR>
    50% (50/100)<CR>
-   50% (50/100), done.
+  100% (100/100)<CR>
+  100% (100/100), done.
 EOF
 
 	cat >in <<-\EOF &&
@@ -104,6 +105,7 @@ EOF
 	signal
 	progress 1
 	progress 50
+	progress 100
 	stop
 	EOF
 	test-tool progress <in 2>stderr &&
@@ -423,4 +425,30 @@ test_expect_success 'BUG: start two concurrent progress bars' '
 	grep -E "^BUG: .*: should have no global_progress in set_progress_signal\(\)$" stderr
 '
 
+test_expect_success 'BUG: display_progress() goes past declared "total"' '
+	cat >in <<-\EOF &&
+	start 3
+	progress 1
+	progress 2
+	progress 4
+	stop
+	EOF
+
+	test_must_fail test-tool progress <in 2>stderr &&
+	grep "BUG:.*total progress does not match" stderr
+'
+
+test_expect_success 'BUG: display_progress() does not reach declared "total"' '
+	cat >in <<-\EOF &&
+	start 5
+	progress 1
+	progress 2
+	progress 4
+	stop
+	EOF
+
+	test_must_fail test-tool progress <in 2>stderr &&
+	grep "BUG:.*total progress does not match" stderr
+'
+
 test_done
-- 
2.32.0.599.g3967b4fa4ac


  parent reply	other threads:[~2021-06-23 17:49 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 ` [PATCH 1/7] progress: introduce GIT_TEST_CHECK_PROGRESS to verify progress counters SZEDER Gábor
2021-06-21  7:09   ` Æ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       ` Ævar Arnfjörð Bjarmason [this message]
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=patch-24.25-37b3d1e4d9d-20210623T155626Z-avarab@gmail.com \
    --to=avarab@gmail.com \
    --cc=git@vger.kernel.org \
    --cc=gitster@pobox.com \
    --cc=l.s.r@web.de \
    --cc=me@ttaylorr.com \
    --cc=szeder.dev@gmail.com \
    --subject='Re: [RFC/PATCH 24/25] progress: assert last update in stop_progress()' \
    /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).