From: Fujii Masao <masao.fujii@oss.nttdata.com>
To: Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>
Cc: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>
Subject: Re: wait event and archive_command
Date: Mon, 1 Nov 2021 18:01:13 +0900
Message-ID: <08f37024-42a0-dcc1-6d92-76387b50d3de@oss.nttdata.com> (raw)
In-Reply-To: <CALj2ACVA=oNp=KwNkLPoBzH6wBVHq7EMavoh-EU+s5OCi83pug@mail.gmail.com>
References: <4ca4f920-6b48-638d-08b2-93598356f5d3@oss.nttdata.com>
<CALj2ACVA=oNp=KwNkLPoBzH6wBVHq7EMavoh-EU+s5OCi83pug@mail.gmail.com>
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) downloaddiff --git a/doc/src/sgml/monitoring.sgml b/doc/src/sgml/monitoring.sgmlindex 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.cindex 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.cindex 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.cindex 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.cindex 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.hindex 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.hindex 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,
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: pgsql-hackers@postgresql.org
Cc: masao.fujii@oss.nttdata.com, bharath.rupireddyforpostgres@gmail.com, pgsql-hackers@lists.postgresql.org
Subject: Re: wait event and archive_command
In-Reply-To: <08f37024-42a0-dcc1-6d92-76387b50d3de@oss.nttdata.com>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
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