From f262eec240c4071e3128468d9d604c5ea958948c Mon Sep 17 00:00:00 2001 From: Bharath Rupireddy Date: Sun, 27 Feb 2022 07:06:17 +0000 Subject: [PATCH v8] Add WAL recovery messages with log_wal_traffic GUC Having the WAL file info (the server is recovering/replaying) along with source (where it is being fetched from archive or stream or pg_wal) in server log messages will be useful to understand how the system is/was doing/progressing with these (sometimes time-intensive) operations. Added a GUC to control the log traffic i.e. log frequently or once in a while per every 128 recovered WAL files or log nothing. --- doc/src/sgml/config.sgml | 18 ++++++++ src/backend/access/transam/xlog.c | 43 +++++++++++++++++++ src/backend/access/transam/xlogarchive.c | 2 +- src/backend/access/transam/xlogrecovery.c | 33 +++++++++++++- src/backend/utils/misc/guc.c | 11 +++++ src/backend/utils/misc/postgresql.conf.sample | 1 + src/include/access/xlog.h | 11 +++++ 7 files changed, 117 insertions(+), 2 deletions(-) diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index 7ed8c82a9d..480d1f7acd 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -3364,6 +3364,24 @@ include_dir 'conf.d' + + log_wal_traffic (enum) + + log_wal_traffic configuration parameter + + + + + Specifies the amount of WAL processing information written to + the server log. Valid values are none (which is the + default), medium and high. The + value none logs no information, medium + logs messages per each 128 WAL segments processed and high + logs messages per each WAL segment processed. + + + + diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c index 0d2bd7a357..ad946a18af 100644 --- a/src/backend/access/transam/xlog.c +++ b/src/backend/access/transam/xlog.c @@ -139,6 +139,7 @@ bool XLOG_DEBUG = false; #endif int wal_segment_size = DEFAULT_XLOG_SEG_SIZE; +int log_wal_traffic = LOG_WAL_TRAFFIC_NONE; /* * Number of WAL insertion locks to use. A higher value allows more insertions @@ -195,6 +196,13 @@ const struct config_enum_entry archive_mode_options[] = { {NULL, 0, false} }; +const struct config_enum_entry log_wal_traffic_options[] = { + {"none", LOG_WAL_TRAFFIC_NONE, false}, + {"medium", LOG_WAL_TRAFFIC_MEDIUM, false}, + {"high", LOG_WAL_TRAFFIC_HIGH, false}, + {NULL, 0, false} +}; + /* * Statistics for current checkpoint are collected in this global struct. * Because only the checkpointer or a stand-alone backend can perform @@ -9197,3 +9205,38 @@ SetWalWriterSleeping(bool sleeping) XLogCtl->WalWriterSleeping = sleeping; SpinLockRelease(&XLogCtl->info_lck); } + +/* + * Returns true if logging of WAL traffic is allowed, otherwise false. + */ +bool +LogWALTraffic(char *last_logged_xlogfname, char *xlogfname) +{ + bool emit_log = false; + + if (log_wal_traffic == LOG_WAL_TRAFFIC_NONE) + return false; + else if (log_wal_traffic == LOG_WAL_TRAFFIC_MEDIUM) + { + /* first time, log the messages */ + if (strlen(last_logged_xlogfname) == 0) + emit_log = true; + else if (IsXLogFileName(last_logged_xlogfname)) + { + uint32 l_tli; + uint32 tli; + XLogSegNo l_segno; + XLogSegNo segno; + + XLogFromFileName(last_logged_xlogfname, &l_tli, &l_segno, wal_segment_size); + XLogFromFileName(xlogfname, &tli, &segno, wal_segment_size); + + if ((segno - l_segno) >= LOG_WAL_TRAFFIC_PER_SEGMENTS) + emit_log = true; + } + } + else if (log_wal_traffic == LOG_WAL_TRAFFIC_HIGH) + return true; + + return emit_log; +} diff --git a/src/backend/access/transam/xlogarchive.c b/src/backend/access/transam/xlogarchive.c index a2657a2005..b6040f9b9d 100644 --- a/src/backend/access/transam/xlogarchive.c +++ b/src/backend/access/transam/xlogarchive.c @@ -214,7 +214,7 @@ RestoreArchivedFile(char *path, const char *xlogfname, else { ereport(LOG, - (errmsg("restored log file \"%s\" from archive", + (errmsg("restored WAL segment \"%s\" from archive", xlogfname))); strcpy(path, xlogpath); return true; diff --git a/src/backend/access/transam/xlogrecovery.c b/src/backend/access/transam/xlogrecovery.c index f9f212680b..bc1dd1b096 100644 --- a/src/backend/access/transam/xlogrecovery.c +++ b/src/backend/access/transam/xlogrecovery.c @@ -3985,6 +3985,7 @@ XLogFileRead(XLogSegNo segno, int emode, TimeLineID tli, char activitymsg[MAXFNAMELEN + 16]; char path[MAXPGPATH]; int fd; + static char last_logged_xlogfname[MAXFNAMELEN] = {'\0'}; XLogFileName(xlogfname, tli, segno, wal_segment_size); @@ -3996,6 +3997,11 @@ XLogFileRead(XLogSegNo segno, int emode, TimeLineID tli, xlogfname); set_ps_display(activitymsg); + if (LogWALTraffic(last_logged_xlogfname, xlogfname)) + ereport(LOG, + (errmsg("waiting for WAL segment \"%s\" from archive", + xlogfname))); + if (!RestoreArchivedFile(path, xlogfname, "RECOVERYXLOG", wal_segment_size, @@ -4038,6 +4044,32 @@ XLogFileRead(XLogSegNo segno, int emode, TimeLineID tli, xlogfname); set_ps_display(activitymsg); + if (LogWALTraffic(last_logged_xlogfname, xlogfname)) + { + switch (source) + { + case XLOG_FROM_ARCHIVE: + ereport(LOG, + (errmsg("recovering WAL segment \"%s\" from archive", + xlogfname))); + break; + case XLOG_FROM_STREAM: + ereport(LOG, + (errmsg("recovering WAL segment \"%s\" from stream", + xlogfname))); + break; + case XLOG_FROM_PG_WAL: + ereport(LOG, + (errmsg("recovering WAL segment \"%s\" from pg_wal", + xlogfname))); + break; + case XLOG_FROM_ANY: + break; + } + + memcpy(last_logged_xlogfname, xlogfname, MAXFNAMELEN); + } + /* Track source of data in assorted state variables */ readSource = source; XLogReceiptSource = source; @@ -4128,7 +4160,6 @@ XLogFileReadAnyTLI(XLogSegNo segno, int emode, XLogSource source) XLOG_FROM_ARCHIVE, true); if (fd != -1) { - elog(DEBUG1, "got WAL segment from archive"); if (!expectedTLEs) expectedTLEs = tles; return fd; diff --git a/src/backend/utils/misc/guc.c b/src/backend/utils/misc/guc.c index 1e3650184b..5dc956f9ef 100644 --- a/src/backend/utils/misc/guc.c +++ b/src/backend/utils/misc/guc.c @@ -570,6 +570,7 @@ extern const struct config_enum_entry archive_mode_options[]; extern const struct config_enum_entry recovery_target_action_options[]; extern const struct config_enum_entry sync_method_options[]; extern const struct config_enum_entry dynamic_shared_memory_options[]; +extern const struct config_enum_entry log_wal_traffic_options[]; /* * GUC option variables that are exported from this module @@ -4911,6 +4912,16 @@ static struct config_enum ConfigureNamesEnum[] = NULL, NULL, NULL }, + { + {"log_wal_traffic", PGC_USERSET, WAL_SETTINGS, + gettext_noop("Sets the amount of WAL processing information written to the server log."), + NULL + }, + &log_wal_traffic, + LOG_WAL_TRAFFIC_NONE, log_wal_traffic_options, + NULL, NULL, NULL + }, + { {"dynamic_shared_memory_type", PGC_POSTMASTER, RESOURCES_MEM, gettext_noop("Selects the dynamic shared memory implementation used."), diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample index 4a094bb38b..cfeebd7cfa 100644 --- a/src/backend/utils/misc/postgresql.conf.sample +++ b/src/backend/utils/misc/postgresql.conf.sample @@ -231,6 +231,7 @@ #commit_delay = 0 # range 0-100000, in microseconds #commit_siblings = 5 # range 1-1000 +#log_wal_traffic = none # none, medium, or high # - Checkpoints - diff --git a/src/include/access/xlog.h b/src/include/access/xlog.h index 4b45ac64db..2420cd77f3 100644 --- a/src/include/access/xlog.h +++ b/src/include/access/xlog.h @@ -50,6 +50,7 @@ extern bool *wal_consistency_checking; extern char *wal_consistency_checking_string; extern bool log_checkpoints; extern bool track_wal_io_timing; +extern int log_wal_traffic; extern int CheckPointSegments; @@ -86,6 +87,14 @@ typedef enum RecoveryState RECOVERY_STATE_DONE /* currently in production */ } RecoveryState; +/* Log WAL traffic states */ +typedef enum LogWalTraffic +{ + LOG_WAL_TRAFFIC_NONE = 0, + LOG_WAL_TRAFFIC_MEDIUM, + LOG_WAL_TRAFFIC_HIGH +} LogWalTraffic; + extern PGDLLIMPORT int wal_level; /* Is WAL archiving enabled (always or only while server is running normally)? */ @@ -149,6 +158,7 @@ extern bool XLOG_DEBUG; #define XLOG_INCLUDE_ORIGIN 0x01 /* include the replication origin */ #define XLOG_MARK_UNIMPORTANT 0x02 /* record not important for durability */ +#define LOG_WAL_TRAFFIC_PER_SEGMENTS 128 /* Checkpoint statistics */ typedef struct CheckpointStatsData @@ -246,6 +256,7 @@ extern void SetWalWriterSleeping(bool sleeping); extern void assign_max_wal_size(int newval, void *extra); extern void assign_checkpoint_completion_target(double newval, void *extra); +extern bool LogWALTraffic(char *last_logged_xlogfname, char *xlogfname); /* * Routines used by xlogrecovery.c to call back into xlog.c during recovery. -- 2.25.1