From 7626192b2832959fd12a09edc134382501a4e3be Mon Sep 17 00:00:00 2001 From: Bharath Rupireddy Date: Wed, 29 Dec 2021 01:19:41 +0000 Subject: [PATCH v7] Add WAL recovery messages with log_wal_traffic GUC --- doc/src/sgml/config.sgml | 18 +++++ src/backend/access/transam/xlog.c | 80 ++++++++++++++++++- src/backend/access/transam/xlogarchive.c | 2 +- src/backend/utils/misc/guc.c | 11 +++ src/backend/utils/misc/postgresql.conf.sample | 1 + src/include/access/xlog.h | 9 +++ 6 files changed, 119 insertions(+), 2 deletions(-) diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index afbb6c35e3..7d8e2caa09 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -3365,6 +3365,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 1e1fbe957f..c77d3c4daa 100644 --- a/src/backend/access/transam/xlog.c +++ b/src/backend/access/transam/xlog.c @@ -91,6 +91,8 @@ extern uint32 bootstrap_data_checksum_version; /* timeline ID to be used when bootstrapping */ #define BootstrapTimeLineID 1 +#define LOG_WAL_TRAFFIC_PER_SEGMENTS 128 + /* User-settable parameters */ int max_wal_size_mb = 1024; /* 1 GB */ int min_wal_size_mb = 80; /* 80 MB */ @@ -115,6 +117,7 @@ int CommitSiblings = 5; /* # concurrent xacts needed to sleep */ int wal_retrieve_retry_interval = 5000; int max_slot_wal_keep_size_mb = -1; bool track_wal_io_timing = false; +int log_wal_traffic = LOG_WAL_TRAFFIC_NONE; #ifdef WAL_DEBUG bool XLOG_DEBUG = false; @@ -184,6 +187,13 @@ const struct config_enum_entry recovery_target_action_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 @@ -999,6 +1009,8 @@ static void WALInsertLockAcquireExclusive(void); static void WALInsertLockRelease(void); static void WALInsertLockUpdateInsertingAt(XLogRecPtr insertingAt); +static bool IsLogWALTraffic(char *last_logged_xlogfname, char *xlogfname); + /* * Insert an XLOG record represented by an already-constructed chain of data * chunks. This is a low-level routine; to construct the WAL record header @@ -3788,6 +3800,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); @@ -3799,6 +3812,11 @@ XLogFileRead(XLogSegNo segno, int emode, TimeLineID tli, xlogfname); set_ps_display(activitymsg); + if (IsLogWALTraffic(last_logged_xlogfname, xlogfname)) + ereport(LOG, + (errmsg("waiting for WAL segment \"%s\" from archive", + xlogfname))); + if (!RestoreArchivedFile(path, xlogfname, "RECOVERYXLOG", wal_segment_size, @@ -3841,6 +3859,32 @@ XLogFileRead(XLogSegNo segno, int emode, TimeLineID tli, xlogfname); set_ps_display(activitymsg); + if (IsLogWALTraffic(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; @@ -3931,7 +3975,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; @@ -13243,3 +13286,38 @@ XLogRequestWalReceiverReply(void) { doRequestWalReceiverReply = true; } + +/* + * Returns true if logging of WAL traffic is allowed, otherwise false. + */ +static bool +IsLogWALTraffic(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 4ddeac1fb9..1f724f4acf 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/utils/misc/guc.c b/src/backend/utils/misc/guc.c index f9504d3aec..e45a263a51 100644 --- a/src/backend/utils/misc/guc.c +++ b/src/backend/utils/misc/guc.c @@ -565,6 +565,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 @@ -4885,6 +4886,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 a1acd46b61..c0ea0d847b 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 34f6c89f06..9a7f6b27be 100644 --- a/src/include/access/xlog.h +++ b/src/include/access/xlog.h @@ -88,6 +88,7 @@ extern char *PrimaryConnInfo; extern char *PrimarySlotName; extern bool wal_receiver_create_temp_slot; extern bool track_wal_io_timing; +extern int log_wal_traffic; /* indirectly set via GUC system */ extern TransactionId recoveryTargetXid; @@ -147,6 +148,14 @@ typedef enum RecoveryPauseState RECOVERY_PAUSED /* recovery is paused */ } RecoveryPauseState; +/* 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)? */ -- 2.25.1