pg.ddx.io  pgsql-hackers@postgresql.org mailing list archive  
help / color / mirror / Atom feed
wait event and archive_command
15+ messages / 4 participants
[nested] [flat]

Commits from this thread:
  2021-11-22 1b06d7bac9  Report wait events for local shell commands like archive_command.
* wait event and archive_command
@ 2021-10-21 13:57  Fujii Masao <masao.fujii@oss.nttdata.com>
  0 siblings, 2 replies; 15+ messages in thread

From: Fujii Masao @ 2021-10-21 13:57 UTC (permalink / raw)
  To: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

Hi,

I'd like to propose to add new wait event reported while archiver process
is executing archive_command. This would be helpful to observe
what archiver is doing and check whether it has some troubles or not.
Thought? PoC patch attached.

Also how about adding wait events for other commands like
archive_cleanup_command, restore_command and recovery_end_command?

Regards,

-- 
Fujii Masao
Advanced Computing Technology Center
Research and Development Headquarters
NTT DATA CORPORATION

Attachments:

wait_event_for_archive_command_v1.patch (text/plain, 2.1K) download diff --git a/doc/src/sgml/monitoring.sgml b/doc/src/sgml/monitoring.sgml index 3173ec2566..13c7e991d0 100644 --- a/doc/src/sgml/monitoring.sgml +++ b/doc/src/sgml/monitoring.sgml @@ -1569,7 +1569,12 @@ postgres 27093 0.0 0.0 30096 2752 ? Ss 11:34 0:00 postgres: ser <entry>Waiting for subplan nodes of an <literal>Append</literal> plan node to be ready.</entry> </row> - <row> + <row> + <entry><literal>ArchiveCommand</literal></entry> + <entry>Waiting for <xref linkend="guc-archive-command"/> to + complete.</entry> + </row> + <row> <entry><literal>BackendTermination</literal></entry> <entry>Waiting for the termination of another backend.</entry> </row> diff --git a/src/backend/postmaster/pgarch.c b/src/backend/postmaster/pgarch.c index 74a7d7c4d0..2201f069ea 100644 --- a/src/backend/postmaster/pgarch.c +++ b/src/backend/postmaster/pgarch.c @@ -515,7 +515,10 @@ pgarch_archiveXlog(char *xlog) snprintf(activitymsg, sizeof(activitymsg), "archiving %s", xlog); set_ps_display(activitymsg); + pgstat_report_wait_start(WAIT_EVENT_ARCHIVE_COMMAND); rc = system(xlogarchcmd); + pgstat_report_wait_end(); + if (rc != 0) { /* diff --git a/src/backend/utils/activity/wait_event.c b/src/backend/utils/activity/wait_event.c index 4a5b7502f5..d8e3688ab5 100644 --- a/src/backend/utils/activity/wait_event.c +++ b/src/backend/utils/activity/wait_event.c @@ -313,6 +313,9 @@ pgstat_get_wait_ipc(WaitEventIPC w) case WAIT_EVENT_APPEND_READY: event_name = "AppendReady"; break; + case WAIT_EVENT_ARCHIVE_COMMAND: + event_name = "ArchiveCommand"; + break; case WAIT_EVENT_BACKEND_TERMINATION: event_name = "BackendTermination"; break; diff --git a/src/include/utils/wait_event.h b/src/include/utils/wait_event.h index c22142365f..2edfdd3e51 100644 --- a/src/include/utils/wait_event.h +++ b/src/include/utils/wait_event.h @@ -80,6 +80,7 @@ typedef enum typedef enum { WAIT_EVENT_APPEND_READY = PG_WAIT_IPC, + WAIT_EVENT_ARCHIVE_COMMAND, WAIT_EVENT_BACKEND_TERMINATION, WAIT_EVENT_BACKUP_WAIT_WAL_ARCHIVE, WAIT_EVENT_BGWORKER_SHUTDOWN,
^ permalink raw reply [nested|flat] 15+ messages in thread

* Re: wait event and archive_command
@ 2021-10-21 14:55  Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>
  parent: Fujii Masao <masao.fujii@oss.nttdata.com>
  1 sibling, 1 reply; 15+ messages in thread

From: Bharath Rupireddy @ 2021-10-21 14:55 UTC (permalink / raw)
  To: Fujii Masao <masao.fujii@oss.nttdata.com>; +Cc: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

On Thu, Oct 21, 2021 at 7:28 PM Fujii Masao <masao.fujii@oss.nttdata.com> wrote:
>
> Hi,
>
> I'd like to propose to add new wait event reported while archiver process
> is executing archive_command. This would be helpful to observe
> what archiver is doing and check whether it has some troubles or not.
> Thought? PoC patch attached.
>
> Also how about adding wait events for other commands like
> archive_cleanup_command, restore_command and recovery_end_command?

+1 for the wait event.

The following activitymsg that are being set to ps display in
XLogFileRead and pgarch_archiveXlog have come up for one of our
internal team discussions recently:

            snprintf(activitymsg, sizeof(activitymsg), "waiting for %s",
                     xlogfname);
            set_ps_display(activitymsg);

        snprintf(activitymsg, sizeof(activitymsg), "recovering %s",
                 xlogfname);
        set_ps_display(activitymsg);

    snprintf(activitymsg, sizeof(activitymsg), "archiving %s", xlog);
    set_ps_display(activitymsg);

The ps display info might be useful if we run postgres on a stand
alone box and there's someone monitoring at the ps output, but it
doesn't help debugging after an issue has occurred. How about we have
the following statements which will be useful for someone to look at
the server logs and know what was/is happening during the recovery and
archiving. IMO, we should also have the elog statement.

elog(LOG, "waiting for %s", xlogfname);
elog(LOG, "recovering %s"", xlogfname);
elog(LOG, "archiving %s", xlog);

Another idea could be to have a hook emitting the above info to
outside components, but a hook just for this purpose isn't a great
idea IMO.

Thoughts?

Regards,
Bharath Rupireddy.





^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: wait event and archive_command
@ 2021-10-22 09:32  Michael Paquier <michael@paquier.xyz>
  parent: Fujii Masao <masao.fujii@oss.nttdata.com>
  1 sibling, 1 reply; 15+ messages in thread

From: Michael Paquier @ 2021-10-22 09:32 UTC (permalink / raw)
  To: Fujii Masao <masao.fujii@oss.nttdata.com>; +Cc: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

On Thu, Oct 21, 2021 at 10:57:50PM +0900, Fujii Masao wrote:
> Also how about adding wait events for other commands like
> archive_cleanup_command, restore_command and recovery_end_command?

+1 to add something for all of them as we track the startup process in
pg_stat_activity.  Thinking with a larger picture, this comes down to
the usage of system().  We could introduce a small wrapper of system()
that takes as argument a wait event for the backend.
--
Michael

Attachments:

  signature.asc (application/pgp-signature, 832B) download

^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: wait event and archive_command
@ 2021-11-01 09:01  Fujii Masao <masao.fujii@oss.nttdata.com>
  parent: Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>
  0 siblings, 2 replies; 15+ messages in thread

From: Fujii Masao @ 2021-11-01 09:01 UTC (permalink / raw)
  To: Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>; +Cc: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>



On 2021/10/21 23:55, Bharath Rupireddy wrote:
>> Also how about adding wait events for other commands like
>> archive_cleanup_command, restore_command and recovery_end_command?
> 
> +1 for the wait event.

Thanks!
I added the wait events for also restore_command, etc into the patch.
I attached that updated version of the patch.


> The following activitymsg that are being set to ps display in
> XLogFileRead and pgarch_archiveXlog have come up for one of our
> internal team discussions recently:
> 
>              snprintf(activitymsg, sizeof(activitymsg), "waiting for %s",
>                       xlogfname);
>              set_ps_display(activitymsg);
> 
>          snprintf(activitymsg, sizeof(activitymsg), "recovering %s",
>                   xlogfname);
>          set_ps_display(activitymsg);
> 
>      snprintf(activitymsg, sizeof(activitymsg), "archiving %s", xlog);
>      set_ps_display(activitymsg);
> 
> The ps display info might be useful if we run postgres on a stand
> alone box and there's someone monitoring at the ps output, but it
> doesn't help debugging after an issue has occurred. How about we have
> the following statements which will be useful for someone to look at
> the server logs and know what was/is happening during the recovery and
> archiving.

If an issue occurs while the command is executing,
the error message is logged, isn't it? Isn't that enough for your case?


> IMO, we should also have the elog statement.
> 
> elog(LOG, "waiting for %s", xlogfname);
> elog(LOG, "recovering %s"", xlogfname);
> elog(LOG, "archiving %s", xlog);

I'm afraid that some people think that it's noisy to always log those messages.


> Another idea could be to have a hook emitting the above info to
> outside components, but a hook just for this purpose isn't a great
> idea IMO.

Yes, this idea sounds overkill to me.

Regards,

-- 
Fujii Masao
Advanced Computing Technology Center
Research and Development Headquarters
NTT DATA CORPORATION

Attachments:

wait_event_for_archive_command_v2.patch (text/plain, 7.5K) download diff --git a/doc/src/sgml/monitoring.sgml b/doc/src/sgml/monitoring.sgml index 3173ec2566..af6914872b 100644 --- a/doc/src/sgml/monitoring.sgml +++ b/doc/src/sgml/monitoring.sgml @@ -1569,7 +1569,17 @@ postgres 27093 0.0 0.0 30096 2752 ? Ss 11:34 0:00 postgres: ser <entry>Waiting for subplan nodes of an <literal>Append</literal> plan node to be ready.</entry> </row> - <row> + <row> + <entry><literal>ArchiveCleanupCommand</literal></entry> + <entry>Waiting for <xref linkend="guc-archive-cleanup-command"/> to + complete.</entry> + </row> + <row> + <entry><literal>ArchiveCommand</literal></entry> + <entry>Waiting for <xref linkend="guc-archive-command"/> to + complete.</entry> + </row> + <row> <entry><literal>BackendTermination</literal></entry> <entry>Waiting for the termination of another backend.</entry> </row> @@ -1747,6 +1757,11 @@ postgres 27093 0.0 0.0 30096 2752 ? Ss 11:34 0:00 postgres: ser <entry>Waiting for recovery conflict resolution for dropping a tablespace.</entry> </row> + <row> + <entry><literal>RecoveryEndCommand</literal></entry> + <entry>Waiting for <xref linkend="guc-recovery-end-command"/> to + complete.</entry> + </row> <row> <entry><literal>RecoveryPause</literal></entry> <entry>Waiting for recovery to be resumed.</entry> @@ -1761,6 +1776,11 @@ postgres 27093 0.0 0.0 30096 2752 ? Ss 11:34 0:00 postgres: ser <entry>Waiting for a replication slot to become inactive so it can be dropped.</entry> </row> + <row> + <entry><literal>RestoreCommand</literal></entry> + <entry>Waiting for <xref linkend="guc-restore-command"/> to + complete.</entry> + </row> <row> <entry><literal>SafeSnapshot</literal></entry> <entry>Waiting to obtain a valid snapshot for a <literal>READ ONLY diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c index f547efd294..c23229a0ac 100644 --- a/src/backend/access/transam/xlog.c +++ b/src/backend/access/transam/xlog.c @@ -5747,7 +5747,8 @@ CleanupAfterArchiveRecovery(TimeLineID EndOfLogTLI, XLogRecPtr EndOfLog) if (recoveryEndCommand && strcmp(recoveryEndCommand, "") != 0) ExecuteRecoveryCommand(recoveryEndCommand, "recovery_end_command", - true); + true, + WAIT_EVENT_RECOVERY_END_COMMAND); /* * We switched to a new timeline. Clean up segments on the old timeline. @@ -9863,7 +9864,8 @@ CreateRestartPoint(int flags) if (archiveCleanupCommand && strcmp(archiveCleanupCommand, "") != 0) ExecuteRecoveryCommand(archiveCleanupCommand, "archive_cleanup_command", - false); + false, + WAIT_EVENT_ARCHIVE_CLEANUP_COMMAND); return true; } diff --git a/src/backend/access/transam/xlogarchive.c b/src/backend/access/transam/xlogarchive.c index 26b023e754..47a287dd2c 100644 --- a/src/backend/access/transam/xlogarchive.c +++ b/src/backend/access/transam/xlogarchive.c @@ -24,6 +24,7 @@ #include "access/xlogarchive.h" #include "common/archive.h" #include "miscadmin.h" +#include "pgstat.h" #include "postmaster/startup.h" #include "postmaster/pgarch.h" #include "replication/walsender.h" @@ -168,7 +169,9 @@ RestoreArchivedFile(char *path, const char *xlogfname, /* * Copy xlog from archival storage to XLOGDIR */ + pgstat_report_wait_start(WAIT_EVENT_RESTORE_COMMAND); rc = system(xlogRestoreCmd); + pgstat_report_wait_end(); PostRestoreCommand(); pfree(xlogRestoreCmd); @@ -284,7 +287,8 @@ not_available: * This is currently used for recovery_end_command and archive_cleanup_command. */ void -ExecuteRecoveryCommand(const char *command, const char *commandName, bool failOnSignal) +ExecuteRecoveryCommand(const char *command, const char *commandName, + bool failOnSignal, uint32 wait_event_info) { char xlogRecoveryCmd[MAXPGPATH]; char lastRestartPointFname[MAXPGPATH]; @@ -354,7 +358,10 @@ ExecuteRecoveryCommand(const char *command, const char *commandName, bool failOn /* * execute the constructed command */ + pgstat_report_wait_start(wait_event_info); rc = system(xlogRecoveryCmd); + pgstat_report_wait_end(); + if (rc != 0) { /* diff --git a/src/backend/postmaster/pgarch.c b/src/backend/postmaster/pgarch.c index 74a7d7c4d0..2201f069ea 100644 --- a/src/backend/postmaster/pgarch.c +++ b/src/backend/postmaster/pgarch.c @@ -515,7 +515,10 @@ pgarch_archiveXlog(char *xlog) snprintf(activitymsg, sizeof(activitymsg), "archiving %s", xlog); set_ps_display(activitymsg); + pgstat_report_wait_start(WAIT_EVENT_ARCHIVE_COMMAND); rc = system(xlogarchcmd); + pgstat_report_wait_end(); + if (rc != 0) { /* diff --git a/src/backend/utils/activity/wait_event.c b/src/backend/utils/activity/wait_event.c index 4a5b7502f5..4d53f040e8 100644 --- a/src/backend/utils/activity/wait_event.c +++ b/src/backend/utils/activity/wait_event.c @@ -313,6 +313,12 @@ pgstat_get_wait_ipc(WaitEventIPC w) case WAIT_EVENT_APPEND_READY: event_name = "AppendReady"; break; + case WAIT_EVENT_ARCHIVE_CLEANUP_COMMAND: + event_name = "ArchiveCleanupCommand"; + break; + case WAIT_EVENT_ARCHIVE_COMMAND: + event_name = "ArchiveCommand"; + break; case WAIT_EVENT_BACKEND_TERMINATION: event_name = "BackendTermination"; break; @@ -427,6 +433,9 @@ pgstat_get_wait_ipc(WaitEventIPC w) case WAIT_EVENT_RECOVERY_CONFLICT_TABLESPACE: event_name = "RecoveryConflictTablespace"; break; + case WAIT_EVENT_RECOVERY_END_COMMAND: + event_name = "RecoveryEndCommand"; + break; case WAIT_EVENT_RECOVERY_PAUSE: event_name = "RecoveryPause"; break; @@ -436,6 +445,9 @@ pgstat_get_wait_ipc(WaitEventIPC w) case WAIT_EVENT_REPLICATION_SLOT_DROP: event_name = "ReplicationSlotDrop"; break; + case WAIT_EVENT_RESTORE_COMMAND: + event_name = "RestoreCommand"; + break; case WAIT_EVENT_SAFE_SNAPSHOT: event_name = "SafeSnapshot"; break; diff --git a/src/include/access/xlogarchive.h b/src/include/access/xlogarchive.h index 3edd1a976c..91df8641f2 100644 --- a/src/include/access/xlogarchive.h +++ b/src/include/access/xlogarchive.h @@ -21,7 +21,7 @@ extern bool RestoreArchivedFile(char *path, const char *xlogfname, const char *recovername, off_t expectedSize, bool cleanupEnabled); extern void ExecuteRecoveryCommand(const char *command, const char *commandName, - bool failOnSignal); + bool failOnSignal, uint32 wait_event_info); extern void KeepFileRestoredFromArchive(const char *path, const char *xlogfname); extern void XLogArchiveNotify(const char *xlog); extern void XLogArchiveNotifySeg(XLogSegNo segno); diff --git a/src/include/utils/wait_event.h b/src/include/utils/wait_event.h index c22142365f..8785a8e12c 100644 --- a/src/include/utils/wait_event.h +++ b/src/include/utils/wait_event.h @@ -80,6 +80,8 @@ typedef enum typedef enum { WAIT_EVENT_APPEND_READY = PG_WAIT_IPC, + WAIT_EVENT_ARCHIVE_CLEANUP_COMMAND, + WAIT_EVENT_ARCHIVE_COMMAND, WAIT_EVENT_BACKEND_TERMINATION, WAIT_EVENT_BACKUP_WAIT_WAL_ARCHIVE, WAIT_EVENT_BGWORKER_SHUTDOWN, @@ -118,9 +120,11 @@ typedef enum WAIT_EVENT_PROMOTE, WAIT_EVENT_RECOVERY_CONFLICT_SNAPSHOT, WAIT_EVENT_RECOVERY_CONFLICT_TABLESPACE, + WAIT_EVENT_RECOVERY_END_COMMAND, WAIT_EVENT_RECOVERY_PAUSE, WAIT_EVENT_REPLICATION_ORIGIN_DROP, WAIT_EVENT_REPLICATION_SLOT_DROP, + WAIT_EVENT_RESTORE_COMMAND, WAIT_EVENT_SAFE_SNAPSHOT, WAIT_EVENT_SYNC_REP, WAIT_EVENT_WAL_RECEIVER_EXIT,
^ permalink raw reply [nested|flat] 15+ messages in thread

* Re: wait event and archive_command
@ 2021-11-01 09:04  Fujii Masao <masao.fujii@oss.nttdata.com>
  parent: Michael Paquier <michael@paquier.xyz>
  0 siblings, 0 replies; 15+ messages in thread

From: Fujii Masao @ 2021-11-01 09:04 UTC (permalink / raw)
  To: Michael Paquier <michael@paquier.xyz>; +Cc: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>



On 2021/10/22 18:32, Michael Paquier wrote:
> On Thu, Oct 21, 2021 at 10:57:50PM +0900, Fujii Masao wrote:
>> Also how about adding wait events for other commands like
>> archive_cleanup_command, restore_command and recovery_end_command?
> 
> +1 to add something for all of them as we track the startup process in
> pg_stat_activity.  Thinking with a larger picture, this comes down to
> the usage of system().  We could introduce a small wrapper of system()
> that takes as argument a wait event for the backend.

That's an idea, but as far as I implemented the patch, introduing such wrapper
function doesn't seem to simplify or improve the source code.

Regards,

-- 
Fujii Masao
Advanced Computing Technology Center
Research and Development Headquarters
NTT DATA CORPORATION





^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: wait event and archive_command
@ 2021-11-10 11:19  Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>
  parent: Fujii Masao <masao.fujii@oss.nttdata.com>
  1 sibling, 2 replies; 15+ messages in thread

From: Bharath Rupireddy @ 2021-11-10 11:19 UTC (permalink / raw)
  To: Fujii Masao <masao.fujii@oss.nttdata.com>; +Cc: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

On Mon, Nov 1, 2021 at 2:31 PM Fujii Masao <masao.fujii@oss.nttdata.com> wrote:
> On 2021/10/21 23:55, Bharath Rupireddy wrote:
> >> Also how about adding wait events for other commands like
> >> archive_cleanup_command, restore_command and recovery_end_command?
> >
> > +1 for the wait event.
>
> Thanks!
> I added the wait events for also restore_command, etc into the patch.
> I attached that updated version of the patch.

Thanks for the patch. It looks good to me other than the following comment:

1) Can't we determine the wait event type based on commandName in
ExecuteRecoveryCommand instead of passing it as an extra param?

Regards,
Bharath Rupireddy.





^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: wait event and archive_command
@ 2021-11-10 11:25  Sascha Kuhl <yogidabanli@gmail.com>
  parent: Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>
  1 sibling, 0 replies; 15+ messages in thread

From: Sascha Kuhl @ 2021-11-10 11:25 UTC (permalink / raw)
  To: Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>; +Cc: Fujii Masao <masao.fujii@oss.nttdata.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

Great, so great. Thanks you

Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com> schrieb am Mi.,
10. Nov. 2021, 12:20:

> On Mon, Nov 1, 2021 at 2:31 PM Fujii Masao <masao.fujii@oss.nttdata.com>
> wrote:
> > On 2021/10/21 23:55, Bharath Rupireddy wrote:
> > >> Also how about adding wait events for other commands like
> > >> archive_cleanup_command, restore_command and recovery_end_command?
> > >
> > > +1 for the wait event.
> >
> > Thanks!
> > I added the wait events for also restore_command, etc into the patch.
> > I attached that updated version of the patch.
>
> Thanks for the patch. It looks good to me other than the following comment:
>
> 1) Can't we determine the wait event type based on commandName in
> ExecuteRecoveryCommand instead of passing it as an extra param?
>
> Regards,
> Bharath Rupireddy.
>
>
>

^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: wait event and archive_command
@ 2021-11-10 11:30  Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>
  parent: Fujii Masao <masao.fujii@oss.nttdata.com>
  1 sibling, 1 reply; 15+ messages in thread

From: Bharath Rupireddy @ 2021-11-10 11:30 UTC (permalink / raw)
  To: Fujii Masao <masao.fujii@oss.nttdata.com>; +Cc: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

On Mon, Nov 1, 2021 at 2:31 PM Fujii Masao <masao.fujii@oss.nttdata.com> wrote:
> > The following activitymsg that are being set to ps display in
> > XLogFileRead and pgarch_archiveXlog have come up for one of our
> > internal team discussions recently:
> >
> >              snprintf(activitymsg, sizeof(activitymsg), "waiting for %s",
> >                       xlogfname);
> >              set_ps_display(activitymsg);
> >
> >          snprintf(activitymsg, sizeof(activitymsg), "recovering %s",
> >                   xlogfname);
> >          set_ps_display(activitymsg);
> >
> >      snprintf(activitymsg, sizeof(activitymsg), "archiving %s", xlog);
> >      set_ps_display(activitymsg);
> >
> > The ps display info might be useful if we run postgres on a stand
> > alone box and there's someone monitoring at the ps output, but it
> > doesn't help debugging after an issue has occurred. How about we have
> > the following statements which will be useful for someone to look at
> > the server logs and know what was/is happening during the recovery and
> > archiving.
>
> If an issue occurs while the command is executing,
> the error message is logged, isn't it? Isn't that enough for your case?

You are right when an issue occurs. However, these messages will be
useful 1) if the recovery or archiving is taking a lot of time and one
would want to understand how it is progressing. 2) if these commands
pass but an issue occurs in some other area of the code. IMO, we
should have these as LOG messages instead of just setting in the ps
display for temporary purposes which doesn't work well with the
postgres on cloud where users/admins/developers don't get to see the
ps display.

> > IMO, we should also have the elog statement.
> >
> > elog(LOG, "waiting for %s", xlogfname);
> > elog(LOG, "recovering %s"", xlogfname);
> > elog(LOG, "archiving %s", xlog);
>
> I'm afraid that some people think that it's noisy to always log those messages.

I don't think these are noisy messages at all. In fact, they will be
useful to answer (if not exact answers, but an approximation) some of
the customer queries like "what is happening in my server during the
recovery/archiving phase? how much more time recovery might take?".
Today, the server emits lot of LOGs, adding these will not blow up the
server logs at all if the log rotation policy is configured
appropriately.

Having said the above, I plan to discuss these things in a separate thread.

Regards,
Bharath Rupireddy.





^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: wait event and archive_command
@ 2021-11-10 17:40  Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>
  parent: Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>
  0 siblings, 0 replies; 15+ messages in thread

From: Bharath Rupireddy @ 2021-11-10 17:40 UTC (permalink / raw)
  To: Fujii Masao <masao.fujii@oss.nttdata.com>; +Cc: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

On Wed, Nov 10, 2021 at 5:00 PM Bharath Rupireddy
<bharath.rupireddyforpostgres@gmail.com> wrote:
>
> On Mon, Nov 1, 2021 at 2:31 PM Fujii Masao <masao.fujii@oss.nttdata.com> wrote:
> > > The following activitymsg that are being set to ps display in
> > > XLogFileRead and pgarch_archiveXlog have come up for one of our
> > > internal team discussions recently:
> > >
> > >              snprintf(activitymsg, sizeof(activitymsg), "waiting for %s",
> > >                       xlogfname);
> > >              set_ps_display(activitymsg);
> > >
> > >          snprintf(activitymsg, sizeof(activitymsg), "recovering %s",
> > >                   xlogfname);
> > >          set_ps_display(activitymsg);
> > >
> > >      snprintf(activitymsg, sizeof(activitymsg), "archiving %s", xlog);
> > >      set_ps_display(activitymsg);
> > >
> > > The ps display info might be useful if we run postgres on a stand
> > > alone box and there's someone monitoring at the ps output, but it
> > > doesn't help debugging after an issue has occurred. How about we have
> > > the following statements which will be useful for someone to look at
> > > the server logs and know what was/is happening during the recovery and
> > > archiving.
> >
> > If an issue occurs while the command is executing,
> > the error message is logged, isn't it? Isn't that enough for your case?
>
> You are right when an issue occurs. However, these messages will be
> useful 1) if the recovery or archiving is taking a lot of time and one
> would want to understand how it is progressing. 2) if these commands
> pass but an issue occurs in some other area of the code. IMO, we
> should have these as LOG messages instead of just setting in the ps
> display for temporary purposes which doesn't work well with the
> postgres on cloud where users/admins/developers don't get to see the
> ps display.
>
> > > IMO, we should also have the elog statement.
> > >
> > > elog(LOG, "waiting for %s", xlogfname);
> > > elog(LOG, "recovering %s"", xlogfname);
> > > elog(LOG, "archiving %s", xlog);
> >
> > I'm afraid that some people think that it's noisy to always log those messages.
>
> I don't think these are noisy messages at all. In fact, they will be
> useful to answer (if not exact answers, but an approximation) some of
> the customer queries like "what is happening in my server during the
> recovery/archiving phase? how much more time recovery might take?".
> Today, the server emits lot of LOGs, adding these will not blow up the
> server logs at all if the log rotation policy is configured
> appropriately.
>
> Having said the above, I plan to discuss these things in a separate thread.

Just for the records - I've started a new thread for the above
discussion - https://www.postgresql.org/message-id/CALj2ACUfMU%3Dahxivfy%2BZmpVZccd5PASG-_10mLpM55_Y_h4-VA%40mail...

Regards,
Bharath Rupireddy.





^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: wait event and archive_command
@ 2021-11-18 02:23  Fujii Masao <masao.fujii@oss.nttdata.com>
  parent: Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>
  1 sibling, 2 replies; 15+ messages in thread

From: Fujii Masao @ 2021-11-18 02:23 UTC (permalink / raw)
  To: Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>; +Cc: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>



On 2021/11/10 20:19, Bharath Rupireddy wrote:
> Thanks for the patch. It looks good to me other than the following comment:

Thanks for the review!


> 1) Can't we determine the wait event type based on commandName in
> ExecuteRecoveryCommand instead of passing it as an extra param?

Yes, that's possible. But isn't it uglier to make ExecuteRecoveryCommand() have
the map of command name and wait event? So I feel inclined to avoid adding
something like the following code into the function... Thought?

if (strcmp(commandName, "recovery_end_command") == 0)
     wait_event_info = WAIT_EVENT_RECOVERY_END_COMMAND;
else if (strcmp(commandName, "archive_command_command") == 0)
...

Regards,

-- 
Fujii Masao
Advanced Computing Technology Center
Research and Development Headquarters
NTT DATA CORPORATION





^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: wait event and archive_command
@ 2021-11-18 03:43  Michael Paquier <michael@paquier.xyz>
  parent: Fujii Masao <masao.fujii@oss.nttdata.com>
  1 sibling, 0 replies; 15+ messages in thread

From: Michael Paquier @ 2021-11-18 03:43 UTC (permalink / raw)
  To: Fujii Masao <masao.fujii@oss.nttdata.com>; +Cc: Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

On Thu, Nov 18, 2021 at 11:23:17AM +0900, Fujii Masao wrote:
> Yes, that's possible. But isn't it uglier to make ExecuteRecoveryCommand() have
> the map of command name and wait event? So I feel inclined to avoid adding
> something like the following code into the function... Thought?

FWIW, I find cleaner, and less bug-prone, the approach taken by
Fujii-san's patch to have the wait event set as an argument of the
function rather than trying to guess it from the command data.
--
Michael

Attachments:

  signature.asc (application/pgp-signature, 832B) download

^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: wait event and archive_command
@ 2021-11-18 04:34  Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>
  parent: Fujii Masao <masao.fujii@oss.nttdata.com>
  1 sibling, 1 reply; 15+ messages in thread

From: Bharath Rupireddy @ 2021-11-18 04:34 UTC (permalink / raw)
  To: Fujii Masao <masao.fujii@oss.nttdata.com>; +Cc: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

On Thu, Nov 18, 2021 at 7:53 AM Fujii Masao <masao.fujii@oss.nttdata.com> wrote:
> > 1) Can't we determine the wait event type based on commandName in
> > ExecuteRecoveryCommand instead of passing it as an extra param?
>
> Yes, that's possible. But isn't it uglier to make ExecuteRecoveryCommand() have
> the map of command name and wait event? So I feel inclined to avoid adding
> something like the following code into the function... Thought?
>
> if (strcmp(commandName, "recovery_end_command") == 0)
>      wait_event_info = WAIT_EVENT_RECOVERY_END_COMMAND;
> else if (strcmp(commandName, "archive_command_command") == 0)

Yeah let's not do that. I'm fine with the
wait_event_for_archive_command_v2.patch as is.

Regards,
Bharath Rupireddy.





^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: wait event and archive_command
@ 2021-11-19 07:54  Michael Paquier <michael@paquier.xyz>
  parent: Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>
  0 siblings, 1 reply; 15+ messages in thread

From: Michael Paquier @ 2021-11-19 07:54 UTC (permalink / raw)
  To: Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>; +Cc: Fujii Masao <masao.fujii@oss.nttdata.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

On Thu, Nov 18, 2021 at 10:04:57AM +0530, Bharath Rupireddy wrote:
> Yeah let's not do that. I'm fine with the
> wait_event_for_archive_command_v2.patch as is.

Switched the patch as RfC, then.
--
Michael

Attachments:

  signature.asc (application/pgp-signature, 832B) download

^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: wait event and archive_command
@ 2021-11-19 15:19  Fujii Masao <masao.fujii@oss.nttdata.com>
  parent: Michael Paquier <michael@paquier.xyz>
  0 siblings, 1 reply; 15+ messages in thread

From: Fujii Masao @ 2021-11-19 15:19 UTC (permalink / raw)
  To: Michael Paquier <michael@paquier.xyz>; Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>; +Cc: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>



On 2021/11/19 16:54, Michael Paquier wrote:
> On Thu, Nov 18, 2021 at 10:04:57AM +0530, Bharath Rupireddy wrote:
>> Yeah let's not do that. I'm fine with the
>> wait_event_for_archive_command_v2.patch as is.
> 
> Switched the patch as RfC, then.

Thanks! Barring any objection, I will commit the patch.

Regards,


-- 
Fujii Masao
Advanced Computing Technology Center
Research and Development Headquarters
NTT DATA CORPORATION





^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: wait event and archive_command
@ 2021-11-22 01:31  Fujii Masao <masao.fujii@oss.nttdata.com>
  parent: Fujii Masao <masao.fujii@oss.nttdata.com>
  0 siblings, 0 replies; 15+ messages in thread

From: Fujii Masao @ 2021-11-22 01:31 UTC (permalink / raw)
  To: Michael Paquier <michael@paquier.xyz>; Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>; +Cc: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>



On 2021/11/20 0:19, Fujii Masao wrote:
> 
> 
> On 2021/11/19 16:54, Michael Paquier wrote:
>> On Thu, Nov 18, 2021 at 10:04:57AM +0530, Bharath Rupireddy wrote:
>>> Yeah let's not do that. I'm fine with the
>>> wait_event_for_archive_command_v2.patch as is.
>>
>> Switched the patch as RfC, then.
> 
> Thanks! Barring any objection, I will commit the patch.

Pushed. Thanks!

Regards,

-- 
Fujii Masao
Advanced Computing Technology Center
Research and Development Headquarters
NTT DATA CORPORATION





^ permalink  raw  reply  [nested|flat] 15+ messages in thread


end of thread, other threads:[~2021-11-22 01:31 UTC | newest]

Thread overview: 15+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2021-10-21 13:57 wait event and archive_command Fujii Masao <masao.fujii@oss.nttdata.com>
2021-10-21 14:55 ` Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>
2021-11-01 09:01   ` Fujii Masao <masao.fujii@oss.nttdata.com>
2021-11-10 11:19     ` Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>
2021-11-10 11:25       ` Sascha Kuhl <yogidabanli@gmail.com>
2021-11-18 02:23       ` Fujii Masao <masao.fujii@oss.nttdata.com>
2021-11-18 03:43         ` Michael Paquier <michael@paquier.xyz>
2021-11-18 04:34         ` Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>
2021-11-19 07:54           ` Michael Paquier <michael@paquier.xyz>
2021-11-19 15:19             ` Fujii Masao <masao.fujii@oss.nttdata.com>
2021-11-22 01:31               ` Fujii Masao <masao.fujii@oss.nttdata.com>
2021-11-10 11:30     ` Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>
2021-11-10 17:40       ` Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>
2021-10-22 09:32 ` Michael Paquier <michael@paquier.xyz>
2021-11-01 09:04   ` Fujii Masao <masao.fujii@oss.nttdata.com>

This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox