Test the progress display
'progress.c' has seen a few fixes recently [1], and, unfortunately, some of those fixes required further fixes [2]. It seems it's time to have a few tests focusing on the subtleties of the progress display. Add the 'test-tool progress' subcommand to help testing the progress display, reading instructions from standard input and turning them into calls to the display_progress() and display_throughput() functions with the given parameters. The progress display is, however, critically dependent on timing, because it's only updated once every second or, if the toal is known in advance, every 1%, and there is the throughput rate as well. These make the progress display far too undeterministic for testing as-is. To address this, add a few testing-specific variables and functions to 'progress.c', allowing the the new test helper to: - Disable the triggered-every-second SIGALRM and set the 'progress_update' flag explicitly based in the input instructions. This way the progress line will be updated deterministically when the test wants it to be updated. - Specify the time elapsed since start_progress() to make the throughput rate calculations deterministic. Add the new test script 't0500-progress-display.sh' to check a few simple cases with and without throughput, and that a shorter progress line properly covers up the previously displayed line in different situations. [1] See commits 545dc345eb (progress: break too long progress bar lines, 2019-04-12) and 9f1fd84e15 (progress: clear previous progress update dynamically, 2019-04-12). [2] 1aed1a5f25 (progress: avoid empty line when breaking the progress line, 2019-05-19) Signed-off-by: SZEDER Gábor <szeder.dev@gmail.com> Signed-off-by: Junio C Hamano <gitster@pobox.com>
SZEDER Gábor committed
Sep 16, 2019 at 22:54 UTC
2bb74b53a49f92d433057f4d560b33f1fe2f770a
6 files changed
+400
-2
Makefile
+1
@@ -728,6 +728,7 @@ TEST_BUILTINS_OBJS += test-parse-options.o
728
TEST_BUILTINS_OBJS += test-path-utils.o
729
TEST_BUILTINS_OBJS += test-pkt-line.o
730
TEST_BUILTINS_OBJS += test-prio-queue.o
731
+TEST_BUILTINS_OBJS += test-progress.o
732
TEST_BUILTINS_OBJS += test-reach.o
733
TEST_BUILTINS_OBJS += test-read-cache.o
734
TEST_BUILTINS_OBJS += test-read-midx.o
progress.c
+30
-2
@@ -45,6 +45,19 @@ struct progress {
45
46
static volatile sig_atomic_t progress_update;
47
48
+/*
49
+ * These are only intended for testing the progress output, i.e. exclusively
50
+ * for 'test-tool progress'.
51
+ */
52
+int progress_testing;
53
+uint64_t progress_test_ns = 0;
54
+void progress_test_force_update(void); /* To silence -Wmissing-prototypes */
55
+void progress_test_force_update(void)
56
+{
57
+ progress_update = 1;
58
+}
59
+
60
+
61
static void progress_interval(int signum)
62
{
63
progress_update = 1;
@@ -55,6 +68,9 @@ static void set_progress_signal(void)
68
struct sigaction sa;
69
struct itimerval v;
70
71
+ if (progress_testing)
72
+ return;
73
+
74
progress_update = 0;
75
76
memset(&sa, 0, sizeof(sa));
@@ -72,6 +88,10 @@ static void set_progress_signal(void)
88
static void clear_progress_signal(void)
89
{
90
struct itimerval v = {{0,},};
91
+
92
+ if (progress_testing)
93
+ return;
94
+
95
setitimer(ITIMER_REAL, &v, NULL);
96
signal(SIGALRM, SIG_IGN);
97
progress_update = 0;
@@ -154,6 +174,14 @@ static void throughput_string(struct strbuf *buf, uint64_t total,
174
strbuf_humanise_rate(buf, rate * 1024);
175
}
176
177
+static uint64_t progress_getnanotime(struct progress *progress)
178
+{
179
+ if (progress_testing)
180
+ return progress->start_ns + progress_test_ns;
181
+ else
182
+ return getnanotime();
183
+}
184
+
185
void display_throughput(struct progress *progress, uint64_t total)
186
{
187
struct throughput *tp;
@@ -164,7 +192,7 @@ void display_throughput(struct progress *progress, uint64_t total)
192
return;
193
tp = progress->throughput;
194
167
- now_ns = getnanotime();
195
+ now_ns = progress_getnanotime(progress);
196
197
if (!tp) {
198
progress->throughput = tp = xcalloc(1, sizeof(*tp));
@@ -296,7 +324,7 @@ void stop_progress_msg(struct progress **p_progress, const char *msg)
324
struct throughput *tp = progress->throughput;
325
326
if (tp) {
299
- uint64_t now_ns = getnanotime();
327
+ uint64_t now_ns = progress_getnanotime(progress);
328
unsigned int misecs, rate;
329
misecs = ((now_ns - progress->start_ns) * 4398) >> 32;
330
rate = tp->curr_total / (misecs ? misecs : 1);
t/helper/test-progress.c
new
+81
@@ -0,0 +1,81 @@
1
+/*
2
+ * A test helper to exercise the progress display.
3
+ *
4
+ * Reads instructions from standard input, one instruction per line:
5
+ *
6
+ * "progress <items>" - Call display_progress() with the given item count
7
+ * as parameter.
8
+ * "throughput <bytes> <millis> - Call display_throughput() with the given
9
+ * byte count as parameter. The 'millis'
10
+ * specify the time elapsed since the
11
+ * start_progress() call.
12
+ * "update" - Set the 'progress_update' flag.
13
+ *
14
+ * See 't0500-progress-display.sh' for examples.
15
+ */
16
+#include "test-tool.h"
17
+#include "gettext.h"
18
+#include "parse-options.h"
19
+#include "progress.h"
20
+#include "strbuf.h"
21
+
22
+/*
23
+ * These are defined in 'progress.c', but are not exposed in 'progress.h',
24
+ * because they are exclusively for testing.
25
+ */
26
+extern int progress_testing;
27
+extern uint64_t progress_test_ns;
28
+void progress_test_force_update(void);
29
+
30
+int cmd__progress(int argc, const char **argv)
31
+{
32
+ uint64_t total = 0;
33
+ const char *title;
34
+ struct strbuf line = STRBUF_INIT;
35
+ struct progress *progress;
36
+
37
+ const char *usage[] = {
38
+ "test-tool progress [--total=<n>] <progress-title>",
39
+ NULL
40
+ };
41
+ struct option options[] = {
42
+ OPT_INTEGER(0, "total", &total, "total number of items"),
43
+ OPT_END(),
44
+ };
45
+
46
+ argc = parse_options(argc, argv, NULL, options, usage, 0);
47
+ if (argc != 1)
48
+ die("need a title for the progress output");
49
+ title = argv[0];
50
+
51
+ progress_testing = 1;
52
+ progress = start_progress(title, total);
53
+ while (strbuf_getline(&line, stdin) != EOF) {
54
+ char *end;
55
+
56
+ if (skip_prefix(line.buf, "progress ", (const char **) &end)) {
57
+ uint64_t item_count = strtoull(end, &end, 10);
58
+ if (*end != '\0')
59
+ die("invalid input: '%s'\n", line.buf);
60
+ display_progress(progress, item_count);
61
+ } else if (skip_prefix(line.buf, "throughput ",
62
+ (const char **) &end)) {
63
+ uint64_t byte_count, test_ms;
64
+
65
+ byte_count = strtoull(end, &end, 10);
66
+ if (*end != ' ')
67
+ die("invalid input: '%s'\n", line.buf);
68
+ test_ms = strtoull(end + 1, &end, 10);
69
+ if (*end != '\0')
70
+ die("invalid input: '%s'\n", line.buf);
71
+ progress_test_ns = test_ms * 1000 * 1000;
72
+ display_throughput(progress, byte_count);
73
+ } else if (!strcmp(line.buf, "update"))
74
+ progress_test_force_update();
75
+ else
76
+ die("invalid input: '%s'\n", line.buf);
77
+ }
78
+ stop_progress(&progress);
79
+
80
+ return 0;
81
+}
t/helper/test-tool.c
+1
@@ -42,6 +42,7 @@ static struct test_cmd cmds[] = {
42
{ "path-utils", cmd__path_utils },
43
{ "pkt-line", cmd__pkt_line },
44
{ "prio-queue", cmd__prio_queue },
45
+ { "progress", cmd__progress },
46
{ "reach", cmd__reach },
47
{ "read-cache", cmd__read_cache },
48
{ "read-midx", cmd__read_midx },
t/helper/test-tool.h
+1
@@ -32,6 +32,7 @@ int cmd__parse_options(int argc, const char **argv);
32
int cmd__path_utils(int argc, const char **argv);
33
int cmd__pkt_line(int argc, const char **argv);
34
int cmd__prio_queue(int argc, const char **argv);
35
+int cmd__progress(int argc, const char **argv);
36
int cmd__reach(int argc, const char **argv);
37
int cmd__read_cache(int argc, const char **argv);
38
int cmd__read_midx(int argc, const char **argv);
t/t0500-progress-display.sh
new
+286
@@ -0,0 +1,286 @@
1
+#!/bin/sh
2
+
3
+test_description='progress display'
4
+
5
+. ./test-lib.sh
6
+
7
+show_cr () {
8
+ tr '\015' Q | sed -e "s/Q/<CR>\\$LF/g"
9
+}
10
+
11
+test_expect_success 'simple progress display' '
12
+ cat >expect <<-\EOF &&
13
+ Working hard: 1<CR>
14
+ Working hard: 2<CR>
15
+ Working hard: 5<CR>
16
+ Working hard: 5, done.
17
+ EOF
18
+
19
+ cat >in <<-\EOF &&
20
+ update
21
+ progress 1
22
+ update
23
+ progress 2
24
+ progress 3
25
+ progress 4
26
+ update
27
+ progress 5
28
+ EOF
29
+ test-tool progress "Working hard" <in 2>stderr &&
30
+
31
+ show_cr <stderr >out &&
32
+ test_i18ncmp expect out
33
+'
34
+
35
+test_expect_success 'progress display with total' '
36
+ cat >expect <<-\EOF &&
37
+ Working hard: 33% (1/3)<CR>
38
+ Working hard: 66% (2/3)<CR>
39
+ Working hard: 100% (3/3)<CR>
40
+ Working hard: 100% (3/3), done.
41
+ EOF
42
+
43
+ cat >in <<-\EOF &&
44
+ progress 1
45
+ progress 2
46
+ progress 3
47
+ EOF
48
+ test-tool progress --total=3 "Working hard" <in 2>stderr &&
49
+
50
+ show_cr <stderr >out &&
51
+ test_i18ncmp expect out
52
+'
53
+
54
+test_expect_success 'progress display breaks long lines #1' '
55
+ sed -e "s/Z$//" >expect <<\EOF &&
56
+Working hard.......2.........3.........4.........5.........6: 0% (100/100000)<CR>
57
+Working hard.......2.........3.........4.........5.........6: 1% (1000/100000)<CR>
58
+Working hard.......2.........3.........4.........5.........6: Z
59
+ 10% (10000/100000)<CR>
60
+ 100% (100000/100000)<CR>
61
+ 100% (100000/100000), done.
62
+EOF
63
+
64
+ cat >in <<-\EOF &&
65
+ progress 100
66
+ progress 1000
67
+ progress 10000
68
+ progress 100000
69
+ EOF
70
+ test-tool progress --total=100000 \
71
+ "Working hard.......2.........3.........4.........5.........6" \
72
+ <in 2>stderr &&
73
+
74
+ show_cr <stderr >out &&
75
+ test_i18ncmp expect out
76
+'
77
+
78
+test_expect_success 'progress display breaks long lines #2' '
79
+ # Note: we dont need that many spaces after the title to cover up
80
+ # the last line before breaking the progress line.
81
+ sed -e "s/Z$//" >expect <<\EOF &&
82
+Working hard.......2.........3.........4.........5.........6: 0% (1/100000)<CR>
83
+Working hard.......2.........3.........4.........5.........6: 0% (2/100000)<CR>
84
+Working hard.......2.........3.........4.........5.........6: Z
85
+ 10% (10000/100000)<CR>
86
+ 100% (100000/100000)<CR>
87
+ 100% (100000/100000), done.
88
+EOF
89
+
90
+ cat >in <<-\EOF &&
91
+ update
92
+ progress 1
93
+ update
94
+ progress 2
95
+ progress 10000
96
+ progress 100000
97
+ EOF
98
+ test-tool progress --total=100000 \
99
+ "Working hard.......2.........3.........4.........5.........6" \
100
+ <in 2>stderr &&
101
+
102
+ show_cr <stderr >out &&
103
+ test_i18ncmp expect out
104
+'
105
+
106
+test_expect_success 'progress display breaks long lines #3 - even the first is too long' '
107
+ # Note: we dont actually need any spaces at the end of the title
108
+ # line, because there is no previous progress line to cover up.
109
+ sed -e "s/Z$//" >expect <<\EOF &&
110
+Working hard.......2.........3.........4.........5.........6: Z
111
+ 25% (25000/100000)<CR>
112
+ 50% (50000/100000)<CR>
113
+ 75% (75000/100000)<CR>
114
+ 100% (100000/100000)<CR>
115
+ 100% (100000/100000), done.
116
+EOF
117
+
118
+ cat >in <<-\EOF &&
119
+ progress 25000
120
+ progress 50000
121
+ progress 75000
122
+ progress 100000
123
+ EOF
124
+ test-tool progress --total=100000 \
125
+ "Working hard.......2.........3.........4.........5.........6" \
126
+ <in 2>stderr &&
127
+
128
+ show_cr <stderr >out &&
129
+ test_i18ncmp expect out
130
+'
131
+
132
+test_expect_success 'progress display breaks long lines #4 - title line matches terminal width' '
133
+ cat >expect <<\EOF &&
134
+Working hard.......2.........3.........4.........5.........6.........7.........:
135
+ 25% (25000/100000)<CR>
136
+ 50% (50000/100000)<CR>
137
+ 75% (75000/100000)<CR>
138
+ 100% (100000/100000)<CR>
139
+ 100% (100000/100000), done.
140
+EOF
141
+
142
+ cat >in <<-\EOF &&
143
+ progress 25000
144
+ progress 50000
145
+ progress 75000
146
+ progress 100000
147
+ EOF
148
+ test-tool progress --total=100000 \
149
+ "Working hard.......2.........3.........4.........5.........6.........7........." \
150
+ <in 2>stderr &&
151
+
152
+ show_cr <stderr >out &&
153
+ test_i18ncmp expect out
154
+'
155
+
156
+# Progress counter goes backwards, this should not happen in practice.
157
+test_expect_success 'progress shortens - crazy caller' '
158
+ cat >expect <<-\EOF &&
159
+ Working hard: 10% (100/1000)<CR>
160
+ Working hard: 20% (200/1000)<CR>
161
+ Working hard: 0% (1/1000) <CR>
162
+ Working hard: 100% (1000/1000)<CR>
163
+ Working hard: 100% (1000/1000), done.
164
+ EOF
165
+
166
+ cat >in <<-\EOF &&
167
+ progress 100
168
+ progress 200
169
+ progress 1
170
+ progress 1000
171
+ EOF
172
+ test-tool progress --total=1000 "Working hard" <in 2>stderr &&
173
+
174
+ show_cr <stderr >out &&
175
+ test_i18ncmp expect out
176
+'
177
+
178
+test_expect_success 'progress display with throughput' '
179
+ cat >expect <<-\EOF &&
180
+ Working hard: 10<CR>
181
+ Working hard: 20, 200.00 KiB | 100.00 KiB/s<CR>
182
+ Working hard: 30, 300.00 KiB | 100.00 KiB/s<CR>
183
+ Working hard: 40, 400.00 KiB | 100.00 KiB/s<CR>
184
+ Working hard: 40, 400.00 KiB | 100.00 KiB/s, done.
185
+ EOF
186
+
187
+ cat >in <<-\EOF &&
188
+ throughput 102400 1000
189
+ update
190
+ progress 10
191
+ throughput 204800 2000
192
+ update
193
+ progress 20
194
+ throughput 307200 3000
195
+ update
196
+ progress 30
197
+ throughput 409600 4000
198
+ update
199
+ progress 40
200
+ EOF
201
+ test-tool progress "Working hard" <in 2>stderr &&
202
+
203
+ show_cr <stderr >out &&
204
+ test_i18ncmp expect out
205
+'
206
+
207
+test_expect_success 'progress display with throughput and total' '
208
+ cat >expect <<-\EOF &&
209
+ Working hard: 25% (10/40)<CR>
210
+ Working hard: 50% (20/40), 200.00 KiB | 100.00 KiB/s<CR>
211
+ Working hard: 75% (30/40), 300.00 KiB | 100.00 KiB/s<CR>
212
+ Working hard: 100% (40/40), 400.00 KiB | 100.00 KiB/s<CR>
213
+ Working hard: 100% (40/40), 400.00 KiB | 100.00 KiB/s, done.
214
+ EOF
215
+
216
+ cat >in <<-\EOF &&
217
+ throughput 102400 1000
218
+ progress 10
219
+ throughput 204800 2000
220
+ progress 20
221
+ throughput 307200 3000
222
+ progress 30
223
+ throughput 409600 4000
224
+ progress 40
225
+ EOF
226
+ test-tool progress --total=40 "Working hard" <in 2>stderr &&
227
+
228
+ show_cr <stderr >out &&
229
+ test_i18ncmp expect out
230
+'
231
+
232
+test_expect_success 'cover up after throughput shortens' '
233
+ cat >expect <<-\EOF &&
234
+ Working hard: 1<CR>
235
+ Working hard: 2, 800.00 KiB | 400.00 KiB/s<CR>
236
+ Working hard: 3, 1.17 MiB | 400.00 KiB/s <CR>
237
+ Working hard: 4, 1.56 MiB | 400.00 KiB/s<CR>
238
+ Working hard: 4, 1.56 MiB | 400.00 KiB/s, done.
239
+ EOF
240
+
241
+ cat >in <<-\EOF &&
242
+ throughput 409600 1000
243
+ update
244
+ progress 1
245
+ throughput 819200 2000
246
+ update
247
+ progress 2
248
+ throughput 1228800 3000
249
+ update
250
+ progress 3
251
+ throughput 1638400 4000
252
+ update
253
+ progress 4
254
+ EOF
255
+ test-tool progress "Working hard" <in 2>stderr &&
256
+
257
+ show_cr <stderr >out &&
258
+ test_i18ncmp expect out
259
+'
260
+
261
+test_expect_success 'cover up after throughput shortens a lot' '
262
+ cat >expect <<-\EOF &&
263
+ Working hard: 1<CR>
264
+ Working hard: 2, 1000.00 KiB | 1000.00 KiB/s<CR>
265
+ Working hard: 3, 3.00 MiB | 1.50 MiB/s <CR>
266
+ Working hard: 3, 3.00 MiB | 1024.00 KiB/s, done.
267
+ EOF
268
+
269
+ cat >in <<-\EOF &&
270
+ throughput 1 1000
271
+ update
272
+ progress 1
273
+ throughput 1024000 2000
274
+ update
275
+ progress 2
276
+ throughput 3145728 3000
277
+ update
278
+ progress 3
279
+ EOF
280
+ test-tool progress "Working hard" <in 2>stderr &&
281
+
282
+ show_cr <stderr >out &&
283
+ test_i18ncmp expect out
284
+'
285
+
286
+test_done