Thread: Re: Fix for Extra Parenthesis in pgbench progress message
>> Maybe. But I am also worried about the case when we would want to
>> change the log line format in the future. We might introduce this kind
>> of bug again. By dynamically calculating the number of necessary
>> spaces, we don't need to think about the concern.
>
> +1
>
> + if (previous_chars != 0)
> + {
> + int n_spaces = chars - previous_chars;
> + fprintf(stderr, "%*s", n_spaces, "");
> + chars += n_spaces;
> + }
>
> Currently, this is added only when use_quiet is false, but shouldn’t
> it also apply when use_quiet is true?
Yes. The patch just showed my idea and I thought I needed to apply the
case when use_quiet is true. But the fix should be applied to after
"else if (use_quiet && (j % 100 == 0))" as shown in your patch.
> Also, what happens if chars is smaller than previous_chars?
My oversight. Better to check if chars is smaller than previous_chars.
> I’m unsure why chars needs to be incremented by n_spaces.
Yeah, it's not necessary.
> I’ve created an updated patch based on your idea―could you take a
> look?
Sure.
I think you need to adjust
fprintf(stderr, "%*c\r", chars - 1, ' '); /* Clear the current line */
to:
fprintf(stderr, "%*c\r", chars, ' '); /* Clear the current line */
since now chars does not consider the EOL char. By clearing chars - 1,
the closing parenthesis will be left on the screen.
Best reagards,
--
Tatsuo Ishii
SRA OSS K.K.
English: http://www.sraoss.co.jp/index_en/
Japanese:http://www.sraoss.co.jp
Hi,
On 2024-11-26 01:32:10 +0900, Fujii Masao wrote:
> On 2024/11/25 8:31, Tatsuo Ishii wrote:
> > Now that two minor releases are out, are you going to commit and
> > back-patch this?
>
> Yes, I will.
>
> But, the patch didn't apply cleanly to some back branches, so I've created
> and attached updated patches for them. Could you review these?
> If they look good, I'll proceed with pushing them.
I just did pgbench -i 100 -q via ssh and noticed it was *way* slower than I
expected. Did it with debian's pgbench, no such issue.
It's due to this patch.
/srv/dev/build/m-opt/src/bin/pgbench/pgbench -i -s 10 -Idtg -h /tmp -q > /tmp/pgiu 2>&1
With HEAD:
pgbench -i -s 10 -Idtg -h /tmp -q 2>&1|wc
1000114 52 1000448
With af35fe501af reverted:
pgbench -i -s 10 -Idtg -h /tmp -q 2>&1|wc
6 52 340
Outputting that many lines to the terminal causes noticeable slowdowns even
locally and make the terminal use a *lot* more cpu cycles.
With HEAD:
perf stat -p $(pidof gnome-terminal-server) /srv/dev/build/m-opt/src/bin/pgbench/pgbench -i -s 100 -Idtg -h /tmp -q
dropping old tables...
creating tables...
generating data (client-side)...
done in 6.31 s (drop tables 0.02 s, create tables 0.00 s, client-side generate 6.28 s).
Performance counter stats for process id '3615':
3,726.37 msec task-clock # 0.590 CPUs utilized
692,360 context-switches # 185.800 K/sec
49 cpu-migrations # 13.150 /sec
2 page-faults # 0.537 /sec
13,340,182,520 instructions # 1.35 insn per cycle
# 0.14 stalled cycles per insn
9,893,907,904 cycles # 2.655 GHz
1,913,148,556 stalled-cycles-frontend # 19.34% frontend cycles idle
2,935,132,872 branches # 787.665 M/sec
17,293,477 branch-misses # 0.59% of all branches
6.315407944 seconds time elapsed
With af35fe501af reverted:
perf stat -p $(pidof gnome-terminal-server) /srv/dev/build/m-opt/src/bin/pgbench/pgbench -i -s 100 -Idtg -h /tmp -q
dropping old tables...
creating tables...
generating data (client-side)...
done in 5.77 s (drop tables 0.02 s, create tables 0.00 s, client-side generate 5.75 s).
Performance counter stats for process id '3615':
228.02 msec task-clock # 0.039 CPUs utilized
239 context-switches # 1.048 K/sec
16 cpu-migrations # 70.170 /sec
0 page-faults # 0.000 /sec
298,383,249 instructions # 0.35 insn per cycle
# 0.28 stalled cycles per insn
857,475,516 cycles # 3.761 GHz
82,918,558 stalled-cycles-frontend # 9.67% frontend cycles idle
48,317,810 branches # 211.903 M/sec
618,525 branch-misses # 1.28% of all branches
5.780547274 seconds time elapsed
IOW, pgbench -i -s 100 -q got ~0.8s slower and made the terminal use 15x more
cycles.
Given the upcoming set of minor releases, I think it may be best for this this
patch ought to be reverted for now.
Greetings,
Andres Freund
On Fri, Feb 07, 2025 at 12:28:16PM -0500, Andres Freund wrote: > I just did pgbench -i 100 -q via ssh and noticed it was *way* slower than I > expected. Did it with debian's pgbench, no such issue. > > It's due to this patch. > > /srv/dev/build/m-opt/src/bin/pgbench/pgbench -i -s 10 -Idtg -h /tmp -q > /tmp/pgiu 2>&1 > > With HEAD: > pgbench -i -s 10 -Idtg -h /tmp -q 2>&1|wc > 1000114 52 1000448 > > With af35fe501af reverted: > pgbench -i -s 10 -Idtg -h /tmp -q 2>&1|wc > 6 52 340 > > Outputting that many lines to the terminal causes noticeable slowdowns even > locally and make the terminal use a *lot* more cpu cycles. Presumably we should only fputc(eol, stderr) when we actually fprintf() above this point. > Given the upcoming set of minor releases, I think it may be best for this this > patch ought to be reverted for now. +1, since we're nearing the freeze and this doesn't seem like a particularly urgent bug fix. -- nathan
Andres Freund <andres@anarazel.de> writes:
> I just did pgbench -i 100 -q via ssh and noticed it was *way* slower than I
> expected. Did it with debian's pgbench, no such issue.
> It's due to this patch.
Oh! The problem is that the hunk
+ /*
+ * If the previous progress message is longer than the current one,
+ * add spaces to the current line to fully overwrite any remaining
+ * characters from the previous message.
+ */
+ if (prev_chars > chars)
+ fprintf(stderr, "%*c", prev_chars - chars, ' ');
+ fputc(eol, stderr);
+ prev_chars = chars;
is executed unconditionally for each data row, when we should only run
it when we printed something. It's kind of invisible if "eol" is \r,
but I can believe that it's driving the terminal nuts. Trying it
here, it also makes the thing practically unresponsive to control-C.
> Given the upcoming set of minor releases, I think it may be best for this this
> patch ought to be reverted for now.
Seems easy enough to fix. But it's now middle of the night Saturday
morning in Japan, so I doubt Masao-san or Ishii-san will see this
for awhile. And the release freeze is coming up fast.
Let me have a go at fixing it, and if it turns out to be harder
than I think, I'll revert it instead.
regards, tom lane
On Fri, Feb 07, 2025 at 12:58:38PM -0500, Tom Lane wrote:
> Let me have a go at fixing it, and if it turns out to be harder
> than I think, I'll revert it instead.
Oops, I was already taking a look at this. I figured it'd just be
something like the following, although maybe there's a more elegant way.
diff --git a/src/bin/pgbench/pgbench.c b/src/bin/pgbench/pgbench.c
index 40592e62606..b73921c36e3 100644
--- a/src/bin/pgbench/pgbench.c
+++ b/src/bin/pgbench/pgbench.c
@@ -4990,6 +4990,7 @@ initPopulateTable(PGconn *con, const char *table, int64 base,
for (k = 0; k < total; k++)
{
int64 j = k + 1;
+ bool printed = false;
init_row(&sql, k);
if (PQputline(con, sql.data))
@@ -5011,6 +5012,7 @@ initPopulateTable(PGconn *con, const char *table, int64 base,
j, total,
(int) ((j * 100) / total),
table, elapsed_sec, remaining_sec);
+ printed = true;
}
/* let's not call the timing for each row, but only each 100 rows */
else if (use_quiet && (j % 100 == 0))
@@ -5025,6 +5027,7 @@ initPopulateTable(PGconn *con, const char *table, int64 base,
j, total,
(int) ((j * 100) / total),
table, elapsed_sec, remaining_sec);
+ printed = true;
/* skip to the next interval */
log_interval = (int) ceil(elapsed_sec / LOG_STEP_SECONDS);
@@ -5038,7 +5041,8 @@ initPopulateTable(PGconn *con, const char *table, int64 base,
*/
if (prev_chars > chars)
fprintf(stderr, "%*c", prev_chars - chars, ' ');
- fputc(eol, stderr);
+ if (printed)
+ fputc(eol, stderr);
prev_chars = chars;
}
--
nathan
Nathan Bossart <nathandbossart@gmail.com> writes:
> On Fri, Feb 07, 2025 at 12:58:38PM -0500, Tom Lane wrote:
>> Let me have a go at fixing it, and if it turns out to be harder
>> than I think, I'll revert it instead.
> Oops, I was already taking a look at this. I figured it'd just be
> something like the following, although maybe there's a more elegant way.
Well, the stuff with prev_chars really ought to be skipped as well.
(Yeah, it's probably a no-op, but readers shouldn't have to figure
that out.)
My thought was that duplicating the logic isn't so bad, as attached.
regards, tom lane
diff --git a/src/bin/pgbench/pgbench.c b/src/bin/pgbench/pgbench.c
index 40592e6260..f303bdeec8 100644
--- a/src/bin/pgbench/pgbench.c
+++ b/src/bin/pgbench/pgbench.c
@@ -5011,6 +5011,16 @@ initPopulateTable(PGconn *con, const char *table, int64 base,
j, total,
(int) ((j * 100) / total),
table, elapsed_sec, remaining_sec);
+
+ /*
+ * If the previous progress message is longer than the current
+ * one, add spaces to the current line to fully overwrite any
+ * remaining characters from the previous message.
+ */
+ if (prev_chars > chars)
+ fprintf(stderr, "%*c", prev_chars - chars, ' ');
+ fputc(eol, stderr);
+ prev_chars = chars;
}
/* let's not call the timing for each row, but only each 100 rows */
else if (use_quiet && (j % 100 == 0))
@@ -5026,20 +5036,20 @@ initPopulateTable(PGconn *con, const char *table, int64 base,
(int) ((j * 100) / total),
table, elapsed_sec, remaining_sec);
+ /*
+ * If the previous progress message is longer than the current
+ * one, add spaces to the current line to fully overwrite any
+ * remaining characters from the previous message.
+ */
+ if (prev_chars > chars)
+ fprintf(stderr, "%*c", prev_chars - chars, ' ');
+ fputc(eol, stderr);
+ prev_chars = chars;
+
/* skip to the next interval */
log_interval = (int) ceil(elapsed_sec / LOG_STEP_SECONDS);
}
}
-
- /*
- * If the previous progress message is longer than the current one,
- * add spaces to the current line to fully overwrite any remaining
- * characters from the previous message.
- */
- if (prev_chars > chars)
- fprintf(stderr, "%*c", prev_chars - chars, ' ');
- fputc(eol, stderr);
- prev_chars = chars;
}
if (chars != 0 && eol != '\n')
Hi, On 2025-02-07 12:58:38 -0500, Tom Lane wrote: > Andres Freund <andres@anarazel.de> writes: > > I just did pgbench -i 100 -q via ssh and noticed it was *way* slower than I > > expected. Did it with debian's pgbench, no such issue. > > > It's due to this patch. > > Oh! The problem is that the hunk > > + /* > + * If the previous progress message is longer than the current one, > + * add spaces to the current line to fully overwrite any remaining > + * characters from the previous message. > + */ > + if (prev_chars > chars) > + fprintf(stderr, "%*c", prev_chars - chars, ' '); > + fputc(eol, stderr); > + prev_chars = chars; > > is executed unconditionally for each data row, when we should only run > it when we printed something. Yea, that would do it. > Trying it here, it also makes the thing practically unresponsive to > control-C. Interestingly I don't see that aspect... > > Given the upcoming set of minor releases, I think it may be best for this this > > patch ought to be reverted for now. > > Seems easy enough to fix. But it's now middle of the night Saturday > morning in Japan, so I doubt Masao-san or Ishii-san will see this > for awhile. And the release freeze is coming up fast. > > Let me have a go at fixing it, and if it turns out to be harder > than I think, I'll revert it instead. Makes sense! Greetings, Andres Freund
On Fri, Feb 07, 2025 at 01:10:04PM -0500, Tom Lane wrote: > Nathan Bossart <nathandbossart@gmail.com> writes: >> Oops, I was already taking a look at this. I figured it'd just be >> something like the following, although maybe there's a more elegant way. > > Well, the stuff with prev_chars really ought to be skipped as well. > (Yeah, it's probably a no-op, but readers shouldn't have to figure > that out.) > > My thought was that duplicating the logic isn't so bad, as attached. WFM! -- nathan
Nathan Bossart <nathandbossart@gmail.com> writes:
> On Fri, Feb 07, 2025 at 01:10:04PM -0500, Tom Lane wrote:
>> My thought was that duplicating the logic isn't so bad, as attached.
> WFM!
It does fix the problem here, so I'll make it so.
regards, tom lane
> Nathan Bossart <nathandbossart@gmail.com> writes: >> On Fri, Feb 07, 2025 at 01:10:04PM -0500, Tom Lane wrote: >>> My thought was that duplicating the logic isn't so bad, as attached. > >> WFM! > > It does fix the problem here, so I'll make it so. Sorry for the problem and thank you for the fix! -- Tatsuo Ishii SRA OSS K.K. English: http://www.sraoss.co.jp/index_en/ Japanese:http://www.sraoss.co.jp