Thread: pg_waldump stucks with options --follow or -f and --stats or -z

Hi,

pg_waldump options, --follow or -f(to keep polling once per second for
new WAL to appear) and --stats or -z don't work well together i.e. the
command stucks [1]. I think the pg_waldump should emit an error. Note
that the pg_basebakup does error out on incompatible options.

Here's a small patch for fixing above along with a note in the documentation.

Thoughts?

[1] The following commands stuck:
./pg_waldump -p data/ -s 0/7000060 -f -z
./pg_waldump -p data/ -s 0/7000060 -f --stats='record'
./pg_waldump -p data/ -s 0/7000060 -f --stats='rmgr'

[2]
ubuntu3:~/postgres/inst/bin$ ./pg_waldump -p data/ -s 0/7000060 -f -z
pg_waldump: error: --follow and --stats are incompatible options
Try "pg_waldump --help" for more information.
bharath@bharathubuntu3:~/postgres/inst/bin$

Regards,
Bharath Rupireddy.

On Mon, Nov 15, 2021 at 07:32:38PM +0530, Bharath Rupireddy wrote:
> pg_waldump options, --follow or -f(to keep polling once per second for
> new WAL to appear) and --stats or -z don't work well together i.e. the
> command stucks [1]. I think the pg_waldump should emit an error. Note
> that the pg_basebakup does error out on incompatible options.
>
> Here's a small patch for fixing above along with a note in the documentation.
>
> Thoughts?

I don't think that we should block this combination of options as you
are proposing.  The existing behavior is useful for users when it
comes to an end position specified with -e, to be able to gather some
stats on a cluster or an archive where we may not have all the
contents wanted yet.

> [1] The following commands stuck:
> ./pg_waldump -p data/ -s 0/7000060 -f -z
> ./pg_waldump -p data/ -s 0/7000060 -f --stats='record'
> ./pg_waldump -p data/ -s 0/7000060 -f --stats='rmgr'

Saying that, you are not completely wrong either, as following
something while we won't print any stats at all is not really
helpful.  Another thing I can think of here is to make pg_waldump
more responsive to the dump of the stats when interrupted, via
XLogDumpDisplayStats().
--
Michael

On Tue, Nov 16, 2021 at 8:26 AM Michael Paquier <michael@paquier.xyz> wrote:
>
> On Mon, Nov 15, 2021 at 07:32:38PM +0530, Bharath Rupireddy wrote:
> > pg_waldump options, --follow or -f(to keep polling once per second for
> > new WAL to appear) and --stats or -z don't work well together i.e. the
> > command stucks [1]. I think the pg_waldump should emit an error. Note
> > that the pg_basebakup does error out on incompatible options.
> >
> > Here's a small patch for fixing above along with a note in the documentation.
> >
> > Thoughts?
>
> I don't think that we should block this combination of options as you
> are proposing.  The existing behavior is useful for users when it
> comes to an end position specified with -e, to be able to gather some
> stats on a cluster or an archive where we may not have all the
> contents wanted yet.

You are right. The "./pg_waldump -p data/ -s 0/14CC090 -e 0/14CC390 -f
-z" would fail with what I proposed which isn't a good thing at all.
Should we block both the combinations "-s/-f/-z", "-s/-e/-f/-z"?

> > [1] The following commands stuck:
> > ./pg_waldump -p data/ -s 0/7000060 -f -z
> > ./pg_waldump -p data/ -s 0/7000060 -f --stats='record'
> > ./pg_waldump -p data/ -s 0/7000060 -f --stats='rmgr'
>
> Saying that, you are not completely wrong either, as following
> something while we won't print any stats at all is not really
> helpful.  Another thing I can think of here is to make pg_waldump
> more responsive to the dump of the stats when interrupted, via
> XLogDumpDisplayStats().

It looks okay to be more responsive with the -f option so that the
above commands keep emitting stats for every 1 second(the --follow
option waits for 1 second). Should we really be emitting stats for
every 1 second? Isn't there going to be too much information on the
stdout? Or should we be emitting the stats for every 5 or 10 seconds?

If we be more responsive and keep emitting stats per 1 or 5 or 10 etc.
seconds(we can give an option to the user to choose when he/she would
like to see the stats with -f option, but this is going to be an
overkill IMO), can the user make anything out of those loads of stats
getting emitted? Another idea is to give some incremental stats but it
is overkill again IMO. And when the pg_waldump has the capability to
emit the stats, why to block it?

In summary, we have the following options:
1) block  the combinations  "-s/-f/-z", "-s/-e/-f/-z"
2) be more responsive and keep emitting the stats per 1 sec default
with -f option
3)  be more responsive and keep emitting the stats per user's choice
of seconds (a new option that can be used with the -s/-e/-f/-z).

Thoughts?

Regards,
Bharath Rupireddy.

On Tue, Nov 16, 2021 at 09:34:25AM +0530, Bharath Rupireddy wrote:
> It looks okay to be more responsive with the -f option so that the
> above commands keep emitting stats for every 1 second(the --follow
> option waits for 1 second). Should we really be emitting stats for
> every 1 second? Isn't there going to be too much information on the
> stdout? Or should we be emitting the stats for every 5 or 10 seconds?

I don't have a perfect answer to this question, but dumping the stats
with a fixed frequency is not going to be useful if we don't have in
those logs a current timestamp and/or a current LSN.  This is
basically about how much we want to call XLogDumpDisplayStats() and
how useful it is, but note that my argument is a bit different than
what you are describing here: we could try to make
XLogDumpDisplayStats() responsive on SIGINT or SIGTERM to show
statistics reports.  This way, a --follow without an --end LSN
specified could still provide some information rather than nothing.
That could also be useful if defining an --end but interrupting the
call.

At the same time, we could also just let things as they are.  --follow
and --stats being specified together is what the user looked for, so
they get what they wanted.

> In summary, we have the following options:
> 1) block  the combinations  "-s/-f/-z", "-s/-e/-f/-z"
> 2) be more responsive and keep emitting the stats per 1 sec default
> with -f option
> 3)  be more responsive and keep emitting the stats per user's choice
> of seconds (a new option that can be used with the -s/-e/-f/-z).

A frequency cannot be measured only in time here, but also in bytes in
terms of a minimum amount of WAL replayed between two reports.  I
don't like much the idea of multiple stats reports emitted in a single
pg_waldump call, TBH.  This makes things more complicated than they
should, and the gain is not obvious, at least to me.
--
Michael

On Wed, Nov 17, 2021 at 7:49 AM Michael Paquier <michael@paquier.xyz> wrote:
>
> At the same time, we could also just let things as they are.  --follow
> and --stats being specified together is what the user looked for, so
> they get what they wanted.

I think the existing way of pg_waldump getting stuck with the
combination of options  "-s/-f/-z" and "-s/-e/-f/-z" doesn't look good
for an end user. In the simplest way, the pg_waldump can just emit an
error for these combinations. That shouldn't a big problem as we do
emit errors for a lot of mutually exclusive combination of options
other SQL statements/commands.

Regards,
Bharath Rupireddy.

On 2021-Nov-17, Bharath Rupireddy wrote:

> On Wed, Nov 17, 2021 at 7:49 AM Michael Paquier <michael@paquier.xyz> wrote:
> >
> > At the same time, we could also just let things as they are.  --follow
> > and --stats being specified together is what the user looked for, so
> > they get what they wanted.
> 
> I think the existing way of pg_waldump getting stuck with the
> combination of options  "-s/-f/-z" and "-s/-e/-f/-z" doesn't look good
> for an end user.

I agree that it's not right, but I don't think the solution is to ban
the combination.  I think what we should do is change the behavior to
make the combination potentially useful, so that it waits until program
termination and print the summary then.  Consider "strace -c" as a
precedent: it will also "become stuck" until you kill it, and then it'll
print a nice table, just like the pg_waldump -z gives you.

I think I would even have had occasion to use this as a feature in the
past ...

-- 
Álvaro Herrera           39°49'30"S 73°17'W  —  https://www.EnterpriseDB.com/

On Thu, Nov 18, 2021 at 12:05 AM Alvaro Herrera <alvherre@alvh.no-ip.org> wrote:
>
> On 2021-Nov-17, Bharath Rupireddy wrote:
>
> > On Wed, Nov 17, 2021 at 7:49 AM Michael Paquier <michael@paquier.xyz> wrote:
> > >
> > > At the same time, we could also just let things as they are.  --follow
> > > and --stats being specified together is what the user looked for, so
> > > they get what they wanted.
> >
> > I think the existing way of pg_waldump getting stuck with the
> > combination of options  "-s/-f/-z" and "-s/-e/-f/-z" doesn't look good
> > for an end user.
>
> I agree that it's not right, but I don't think the solution is to ban
> the combination.  I think what we should do is change the behavior to
> make the combination potentially useful, so that it waits until program
> termination and print the summary then.  Consider "strace -c" as a
> precedent: it will also "become stuck" until you kill it, and then it'll
> print a nice table, just like the pg_waldump -z gives you.
>
> I think I would even have had occasion to use this as a feature in the
> past ...

Hm. So, the pg_waldump can have handlers for SIGINT, SIGTERM, SIGQUIT
and then it should emit the computed stats in those handlers the
comobinations - "-s/-f/-z" and "-s/-e/-f/-z". I'm okay with this
behaviour. Michael Paquier had suggested the same upthread. If okay, I
will work on that patch.

Thoughts?

Regards,
Bharath Rupireddy.

On Thu, Nov 18, 2021 at 01:32:08PM +0530, Bharath Rupireddy wrote:
> Hm. So, the pg_waldump can have handlers for SIGINT, SIGTERM, SIGQUIT
> and then it should emit the computed stats in those handlers the
> comobinations - "-s/-f/-z" and "-s/-e/-f/-z". I'm okay with this
> behaviour. Michael Paquier had suggested the same upthread. If okay, I
> will work on that patch.

While on it, I am pretty sure that we should add in the stats report
the start and end LSNs matching with the reports.  If you use --follow
and the call is interrupted, we would not really know to which part of
the WAL stream a report applies to without this information, likely in
the shape of an extra header.
--
Michael

On Thu, Nov 18, 2021 at 2:03 PM Bharath Rupireddy
<bharath.rupireddyforpostgres@gmail.com> wrote:
>
> On Thu, Nov 18, 2021 at 1:51 PM Michael Paquier <michael@paquier.xyz> wrote:
> >
> > On Thu, Nov 18, 2021 at 01:32:08PM +0530, Bharath Rupireddy wrote:
> > > Hm. So, the pg_waldump can have handlers for SIGINT, SIGTERM, SIGQUIT
> > > and then it should emit the computed stats in those handlers the
> > > comobinations - "-s/-f/-z" and "-s/-e/-f/-z". I'm okay with this
> > > behaviour. Michael Paquier had suggested the same upthread. If okay, I
> > > will work on that patch.
> >
> > While on it, I am pretty sure that we should add in the stats report
> > the start and end LSNs matching with the reports.  If you use --follow
> > and the call is interrupted, we would not really know to which part of
> > the WAL stream a report applies to without this information, likely in
> > the shape of an extra header.
>
> Currently, the SIGINT, SIGTERM, SIGQUIT interruptions will cause the pg_waldump process with --follow option to get
killed.And it is a good idea to specify the range of LSNs (start and end) upto which the stats are computed. Maybe as
anotherprintf message at the end of the stats report, after the "Total" section or at the beginning of the stats
report.Something like "summary of the statistics computed from << LSN >> to <<LSN>> are:", see [1]. 

Here's the v2 patch with the above changes i.e. pg_waldump now eimits
the computed stats at the time of termination. Please review it.

Regards,
Bharath Rupireddy.

On Sat, Nov 20, 2021 at 10:03:27AM +0530, Bharath Rupireddy wrote:
> Here's the v2 patch with the above changes i.e. pg_waldump now eimits
> the computed stats at the time of termination. Please review it.

+#define MAX_XLINFO_TYPES 16
+#define fatal_error(...) do { pg_log_fatal(__VA_ARGS__);
exit(EXIT_FAILURE); } while(0)
 typedef struct XLogDumpPrivate
Moving around those declarations does not relate to this patch, so I
would recommend to leave this out to ease reviews.

+   /*
+    * Although the pg_free calls (above and below) are unnecessary here on the
+    * process exit, let's not leak any memory knowingly.
+    */
+   pg_free(opts);
+
+   exit(EXIT_FAILURE);
There is no need to care about the two pg_free() calls here, so let's
remove all that.

+   pg_free(opts);
+   pg_free(stats);
+
    return EXIT_SUCCESS;
[...]
 bad_argument:
    fprintf(stderr, _("Try \"%s --help\" for more information.\n"),
    progname);
+   pg_free(opts);
    return EXIT_FAILURE;
Same here.

+static void
+SignalHandlerForTermination(int signum)
+{
+   /* Display the stats only if they are valid */
+   if (stats &&
+       !XLogRecPtrIsInvalid(stats_startptr) &&
+       !XLogRecPtrIsInvalid(stats_endptr))
+   {
+       XLogDumpDisplayStats();
+       pg_free(stats);
+   }
+
+   /*
+    * Although the pg_free calls (above and below) are unnecessary here on the
+    * process exit, let's not leak any memory knowingly.
+    */
+   pg_free(opts);
+
+   exit(EXIT_FAILURE);
+}
Doing the dump of the stats followed by the exit() within the signal
handler callback is incorrect.  The only safe thing that can be set
and manipulated in a signal handler is roughly a sig_atomic_t flag.
What you should do is to set such a flag in the signal handler, and
then check its value in the main loop of pg_waldump, dumping the stats
if it is detected as turned on because of a signal.
--
Michael

On Sat, Nov 20, 2021 at 11:10 AM Michael Paquier <michael@paquier.xyz> wrote:
> What you should do is to set such a flag in the signal handler, and
> then check its value in the main loop of pg_waldump, dumping the stats
> if it is detected as turned on because of a signal.

Thanks. Here's the v3 patch, a much simpler one. Please review it.

Regards,
Bharath Rupireddy.

On Sat, Nov 20, 2021 at 11:46:35AM +0530, Bharath Rupireddy wrote:
> Thanks. Here's the v3 patch, a much simpler one. Please review it.

+   pqsignal(SIGINT, SignalHandlerForTermination);
+   pqsignal(SIGTERM, SignalHandlerForTermination);
+   pqsignal(SIGQUIT, SignalHandlerForTermination);
FWIW, I think that we should do this stuff only on SIGINT.  I would
imagine that this behavior becomes handy mainly when one wishes to
Ctrl+C the terminal running pg_waldump but still get some
information.

     XLogDumpCountRecord(&config, &stats, xlogreader_state);
+    stats.endptr = xlogreader_state->currRecPtr;
Isn't what you are looking for here EndRecPtr rather than currRecPtr,
to track the end of the last record read?

+    When <option>--follow</option> is used with <option>--stats</option> and
+    the <application>pg_waldump</application> is terminated or interrupted
+    with signal <systemitem>SIGINT</systemitem> or <systemitem>SIGTERM</systemitem>
+    or <systemitem>SIGQUIT</systemitem>, the summary statistics computed
+    as of the termination will be displayed.
This description is not completely correct, as the set of stats would
show up only by using --stats, in non-quiet mode.  Rather than
describing this behavior at the end of the docs, I think that it would
be better to add a new paragraph in the description of --stats.
--
Michael

On Fri, Nov 26, 2021 at 11:50 AM Michael Paquier <michael@paquier.xyz> wrote:
>
> On Sat, Nov 20, 2021 at 11:46:35AM +0530, Bharath Rupireddy wrote:
> > Thanks. Here's the v3 patch, a much simpler one. Please review it.
>
> +   pqsignal(SIGINT, SignalHandlerForTermination);
> +   pqsignal(SIGTERM, SignalHandlerForTermination);
> +   pqsignal(SIGQUIT, SignalHandlerForTermination);
> FWIW, I think that we should do this stuff only on SIGINT.  I would
> imagine that this behavior becomes handy mainly when one wishes to
> Ctrl+C the terminal running pg_waldump but still get some
> information.

Done.

>      XLogDumpCountRecord(&config, &stats, xlogreader_state);
> +    stats.endptr = xlogreader_state->currRecPtr;
> Isn't what you are looking for here EndRecPtr rather than currRecPtr,
> to track the end of the last record read?

You are right.

> +    When <option>--follow</option> is used with <option>--stats</option> and
> +    the <application>pg_waldump</application> is terminated or interrupted
> +    with signal <systemitem>SIGINT</systemitem> or <systemitem>SIGTERM</systemitem>
> +    or <systemitem>SIGQUIT</systemitem>, the summary statistics computed
> +    as of the termination will be displayed.
> This description is not completely correct, as the set of stats would
> show up only by using --stats, in non-quiet mode.  Rather than
> describing this behavior at the end of the docs, I think that it would
> be better to add a new paragraph in the description of --stats.

Done.

PSA v4 patch.

Regards,
Bharath Rupireddy.

On Fri, Nov 26, 2021 at 03:47:30PM +0530, Bharath Rupireddy wrote:
> On Fri, Nov 26, 2021 at 11:50 AM Michael Paquier <michael@paquier.xyz> wrote:
>> +    When <option>--follow</option> is used with <option>--stats</option> and
>> +    the <application>pg_waldump</application> is terminated or interrupted
>> +    with signal <systemitem>SIGINT</systemitem> or <systemitem>SIGTERM</systemitem>
>> +    or <systemitem>SIGQUIT</systemitem>, the summary statistics computed
>> +    as of the termination will be displayed.
>> This description is not completely correct, as the set of stats would
>> show up only by using --stats, in non-quiet mode.  Rather than
>> describing this behavior at the end of the docs, I think that it would
>> be better to add a new paragraph in the description of --stats.
>
> Done.

v4 is just moving this paragraph in its correct subsection.  My
wording may have been confusing here, sorry about that.  What I meant
is that there is no need to mention --follow at all, as an
interruption done before reaching the end LSN or the end of WAL would
still print out the stats accumulated up to the interrupted point.
--
Michael

On Sun, Nov 28, 2021 at 9:50 AM Michael Paquier <michael@paquier.xyz> wrote:
> v4 is just moving this paragraph in its correct subsection.  My
> wording may have been confusing here, sorry about that.  What I meant
> is that there is no need to mention --follow at all, as an
> interruption done before reaching the end LSN or the end of WAL would
> still print out the stats accumulated up to the interrupted point.

Thanks. Here's the v5.

Regards,
Bharath Rupireddy.

On Sun, Nov 28, 2021 at 12:13:08PM +0530, Bharath Rupireddy wrote:
> Thanks. Here's the v5.

By the way, one thing that I completely forgot here is that SIGINT is
not handled on Windows.  If we want to make that work for a WIN32
terminal, we would need to do something similar to
src/fe_utils/cancel.c where we need to use SetConsoleCtrlHandler() and
handle the stats print when facing CTRL_C_EVENT or CTRL_BREAK_EVENT as
events.  Perhaps we should try to think harder and have a more
centralized facility for the handler part between a WIN32 terminal and
SIGINT, as it is not the first time that we need this level of
handling.  Or we could just discard this issue, document its WIN32
limitation and paint some "#ifdef WIN32" around all the handler
portions of the patch.

I would be fine with just doing the latter for now, as this stuff is
still useful for most users, but that's worth mentioning.  Any
opinions?
--
Michael

On Mon, Nov 29, 2021 at 11:09 AM Michael Paquier <michael@paquier.xyz> wrote:
>
> On Sun, Nov 28, 2021 at 12:13:08PM +0530, Bharath Rupireddy wrote:
> > Thanks. Here's the v5.
>
> By the way, one thing that I completely forgot here is that SIGINT is
> not handled on Windows.  If we want to make that work for a WIN32
> terminal, we would need to do something similar to
> src/fe_utils/cancel.c where we need to use SetConsoleCtrlHandler() and
> handle the stats print when facing CTRL_C_EVENT or CTRL_BREAK_EVENT as
> events.  Perhaps we should try to think harder and have a more
> centralized facility for the handler part between a WIN32 terminal and
> SIGINT, as it is not the first time that we need this level of
> handling.  Or we could just discard this issue, document its WIN32
> limitation and paint some "#ifdef WIN32" around all the handler
> portions of the patch.
>
> I would be fine with just doing the latter for now, as this stuff is
> still useful for most users, but that's worth mentioning.  Any
> opinions?

I'm okay to have the same behaviour as pg_receivewal and pg_recvlogical tools.

On my Windows 64-bit setup (see below), the CTRL+C works and the
summary stats are printed as with Linux. I believe on 32-bit platforms
we don't have CTRL+C with SIGINT handling right? If yes, I'm not sure
how we go about mentioning it in the pg_waldump documentation. I see
that the pg_receivewal and pg_recvlogical don't mention anything in
the documentation even though their SIGINT handler is defined for
#ifndef WIN32 platforms.
postgres=# select version();
                            version
---------------------------------------------------------------
 PostgreSQL 15devel, compiled by Visual C++ build 1916, 64-bit
(1 row)
postgres=#

Regards,
Bharath Rupireddy.

On Mon, Nov 29, 2021 at 1:16 PM Bharath Rupireddy
<bharath.rupireddyforpostgres@gmail.com> wrote:
>
> On Mon, Nov 29, 2021 at 11:09 AM Michael Paquier <michael@paquier.xyz> wrote:
> >
> > On Sun, Nov 28, 2021 at 12:13:08PM +0530, Bharath Rupireddy wrote:
> > > Thanks. Here's the v5.
> >
> > By the way, one thing that I completely forgot here is that SIGINT is
> > not handled on Windows.  If we want to make that work for a WIN32
> > terminal, we would need to do something similar to
> > src/fe_utils/cancel.c where we need to use SetConsoleCtrlHandler() and
> > handle the stats print when facing CTRL_C_EVENT or CTRL_BREAK_EVENT as
> > events.  Perhaps we should try to think harder and have a more
> > centralized facility for the handler part between a WIN32 terminal and
> > SIGINT, as it is not the first time that we need this level of
> > handling.  Or we could just discard this issue, document its WIN32
> > limitation and paint some "#ifdef WIN32" around all the handler
> > portions of the patch.
> >
> > I would be fine with just doing the latter for now, as this stuff is
> > still useful for most users, but that's worth mentioning.  Any
> > opinions?
>
> I'm okay to have the same behaviour as pg_receivewal and pg_recvlogical tools.

Here's the v6 patch that has the SIGINT handling enabled for non-WIN32
platforms (note that I haven't specified anything in the
documentation) much like pg_receivewal and pg_recvlogical.

Regards,
Bharath Rupireddy.

On Wed, Dec 01, 2021 at 11:44:02AM +0530, Bharath Rupireddy wrote:
> Here's the v6 patch that has the SIGINT handling enabled for non-WIN32
> platforms (note that I haven't specified anything in the
> documentation) much like pg_receivewal and pg_recvlogical.

I have added a safeguard in XLogDumpDisplayStats() to not print any
stats if the end LSN is not set yet, which would be possible if
pg_waldump is signaled at a very early stage, and I have added some
more comments.  That looked fine after that, so applied.
--
Michael