From 5b68df74d68922685dff4eb665a6431c5046f848 Mon Sep 17 00:00:00 2001 From: Nitin Jadhav Date: Wed, 9 Feb 2022 12:00:11 +0000 Subject: [PATCH] pg_stat_progress_checkpoint view --- doc/src/sgml/monitoring.sgml | 263 +++++++++++++++++++++++++++ src/backend/access/transam/xlog.c | 123 ++++++++++++- src/backend/catalog/system_views.sql | 29 +++ src/backend/storage/buffer/bufmgr.c | 10 + src/backend/storage/sync/sync.c | 10 +- src/backend/utils/adt/pgstatfuncs.c | 2 + src/include/access/xlog.h | 4 + src/include/commands/progress.h | 31 ++++ src/include/storage/sync.h | 2 +- src/include/utils/backend_progress.h | 3 +- 10 files changed, 473 insertions(+), 4 deletions(-) diff --git a/doc/src/sgml/monitoring.sgml b/doc/src/sgml/monitoring.sgml index 62f2a3332b..a6893d4543 100644 --- a/doc/src/sgml/monitoring.sgml +++ b/doc/src/sgml/monitoring.sgml @@ -401,6 +401,13 @@ postgres 27093 0.0 0.0 30096 2752 ? Ss 11:34 0:00 postgres: ser See . + + + pg_stat_progress_checkpointpg_stat_progress_checkpoint + One row only, showing the progress of CHECKPOINT operation. + See . + + @@ -6886,6 +6893,262 @@ SELECT pg_stat_get_backend_pid(s.backendid) AS pid, + + CHECKPOINT Progress Reporting + + + pg_stat_progress_checkpoint + + + + Whenever the checkpoint operation is running, the + pg_stat_progress_checkpoint view will contain a + single row indicating the progress of checkpoint operation. The tables below + describe the information that will be reported and provide information about + how to interpret it. + + + + <structname>pg_stat_progress_checkpoint</structname> View + + + + + Column Type + + + Description + + + + + + + + pid integer + + + Process ID of a CHECKPOINTER process. + + + + + + kinds text + + + Kind of checkpoint. See . + + + + + + phase text + + + Current processing phase. See . + + + + + + total_buffer_writes bigint + + + Total number of buffers to be written. This is estimated and reported + as of the beginning of buffer write operation. + + + + + + buffers_processed bigint + + + Number of buffers processed. This counter increases when the targeted + buffer is processed. This number will eventually become equal to + total_buffer_writes when the checkpoint is + complete. + + + + + + buffers_written bigint + + + Number of buffers written. This counter only advances when the targeted + buffers is written. Note that some of the buffers are processed but may + not required to be written. So this count will always be less than or + equal to total_buffer_writes. + + + + + + total_file_syncs bigint + + + Total number of files to be synced. This is estimated and reported as of + the beginning of sync operation. + + + + + + files_synced bigint + + + Number of files synced. This counter advances when the targeted file is + synced. This number will eventually become equal to + total_file_syncs when the checkpoint is complete. + + + + +
+ + + CHECKPOINT kinds + + + + + + Kinds + Description + + + + + wal + + The checkpoint operation is requested due to XLOG filling. + + + + time + + The checkpoint operation is requested due to timeout. + + + + force + + The checkpoint operation is forced even if no XLOG activity has occurred + since the last one. + + + + +
+ + + CHECKPOINT phases + + + + + + Phase + Description + + + + + initializing + + The CHECKPOINTER process is preparing to begin the checkpoint operation. + This phase is expected to be very brief. + + + + checkpointing replication slots + + The CHECKPOINTER process is currently flushing all the replication slots to + disk. + + + + checkpointing snapshots + + The CHECKPOINTER process is currently removing all the serialized + snapshots that are not required anymore. + + + + checkpointing logical rewrite mappings + + The CHECKPOINTER process is currently removing/flushing the logical + rewrite mappings. + + + + checkpointing CLOG pages + + The CHECKPOINTER process is currently writing CLOG pages to disk. + + + + checkpointing CommitTs pages + + The CHECKPOINTER process is currently writing CommitTs pages to disk. + + + + checkpointing SUBTRANS pages + + The CHECKPOINTER process is currently writing SUBTRANS pages to disk. + + + + checkpointing MULTIXACT pages + + The CHECKPOINTER process is currently writing MULTIXACT pages to disk. + + + + checkpointing SLRU pages + + The CHECKPOINTER process is currently writing SLRU pages to disk. + + + + checkpointing buffers + + The CHECKPOINTER process is currently writing buffers to disk. + + + + performing sync requests + + The CHECKPOINTER process is currently performing sync requests. + + + + performing two phase checkpoint + + The CHECKPOINTER process is currently performing two phase checkpoint. + + + + recycling old XLOG files + + The CHECKPOINTER process is currently recycling old XLOG files. + + + + finalizing + + The CHECKPOINTER process is finalizing the checkpoint operation. + + + + +
+ +
+ diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c index 958220c495..df568eecd8 100644 --- a/src/backend/access/transam/xlog.c +++ b/src/backend/access/transam/xlog.c @@ -9089,6 +9089,9 @@ CreateCheckPoint(int flags) if (RecoveryInProgress() && (flags & CHECKPOINT_END_OF_RECOVERY) == 0) elog(ERROR, "can't create a checkpoint during recovery"); + /* Prepare to report progress of the checkpoint. */ + checkpoint_progress_start(flags); + /* * Prepare to accumulate statistics. * @@ -9432,8 +9435,12 @@ CreateCheckPoint(int flags) KeepLogSeg(recptr, &_logSegNo); } _logSegNo--; + checkpoint_progress_update_param(flags, PROGRESS_CHECKPOINT_PHASE, + PROGRESS_CHECKPOINT_PHASE_OLD_XLOG_RECYCLE); RemoveOldXlogFiles(_logSegNo, RedoRecPtr, recptr, checkPoint.ThisTimeLineID); + checkpoint_progress_update_param(flags, PROGRESS_CHECKPOINT_PHASE, + PROGRESS_CHECKPOINT_PHASE_FINALIZE); /* * Make more log segments if needed. (Do this after recycling old log @@ -9455,6 +9462,9 @@ CreateCheckPoint(int flags) /* Real work is done; log and update stats. */ LogCheckpointEnd(false); + /* Stop reporting progress of the checkpoint. */ + checkpoint_progress_end(flags); + /* Reset the process title */ update_checkpoint_display(flags, false, true); @@ -9568,29 +9578,60 @@ static void CheckPointGuts(XLogRecPtr checkPointRedo, int flags) { CheckPointRelationMap(); + + checkpoint_progress_update_param(flags, PROGRESS_CHECKPOINT_PHASE, + PROGRESS_CHECKPOINT_PHASE_REPLI_SLOTS); CheckPointReplicationSlots(); + + checkpoint_progress_update_param(flags, PROGRESS_CHECKPOINT_PHASE, + PROGRESS_CHECKPOINT_PHASE_SNAPSHOTS); CheckPointSnapBuild(); + + checkpoint_progress_update_param(flags, PROGRESS_CHECKPOINT_PHASE, + PROGRESS_CHECKPOINT_PHASE_LOGICAL_REWRITE_MAPPINGS); CheckPointLogicalRewriteHeap(); CheckPointReplicationOrigin(); /* Write out all dirty data in SLRUs and the main buffer pool */ TRACE_POSTGRESQL_BUFFER_CHECKPOINT_START(flags); CheckpointStats.ckpt_write_t = GetCurrentTimestamp(); + + checkpoint_progress_update_param(flags, PROGRESS_CHECKPOINT_PHASE, + PROGRESS_CHECKPOINT_PHASE_CLOG_PAGES); CheckPointCLOG(); + + checkpoint_progress_update_param(flags, PROGRESS_CHECKPOINT_PHASE, + PROGRESS_CHECKPOINT_PHASE_COMMITTS_PAGES); CheckPointCommitTs(); + + checkpoint_progress_update_param(flags, PROGRESS_CHECKPOINT_PHASE, + PROGRESS_CHECKPOINT_PHASE_SUBTRANS_PAGES); CheckPointSUBTRANS(); + + checkpoint_progress_update_param(flags, PROGRESS_CHECKPOINT_PHASE, + PROGRESS_CHECKPOINT_PHASE_MULTIXACT_PAGES); CheckPointMultiXact(); + + checkpoint_progress_update_param(flags, PROGRESS_CHECKPOINT_PHASE, + PROGRESS_CHECKPOINT_PHASE_SLRU_PAGES); CheckPointPredicate(); + + checkpoint_progress_update_param(flags, PROGRESS_CHECKPOINT_PHASE, + PROGRESS_CHECKPOINT_PHASE_BUFFERS); CheckPointBuffers(flags); /* Perform all queued up fsyncs */ TRACE_POSTGRESQL_BUFFER_CHECKPOINT_SYNC_START(); CheckpointStats.ckpt_sync_t = GetCurrentTimestamp(); - ProcessSyncRequests(); + checkpoint_progress_update_param(flags, PROGRESS_CHECKPOINT_PHASE, + PROGRESS_CHECKPOINT_PHASE_FILE_SYNC); + ProcessSyncRequests(flags); CheckpointStats.ckpt_sync_end_t = GetCurrentTimestamp(); TRACE_POSTGRESQL_BUFFER_CHECKPOINT_DONE(); /* We deliberately delay 2PC checkpointing as long as possible */ + checkpoint_progress_update_param(flags, PROGRESS_CHECKPOINT_PHASE, + PROGRESS_CHECKPOINT_PHASE_TWO_PHASE); CheckPointTwoPhase(checkPointRedo); } @@ -9727,6 +9768,9 @@ CreateRestartPoint(int flags) XLogCtl->RedoRecPtr = lastCheckPoint.redo; SpinLockRelease(&XLogCtl->info_lck); + /* Prepare to report progress of the checkpoint. */ + checkpoint_progress_start(flags); + /* * Prepare to accumulate statistics. * @@ -9837,7 +9881,11 @@ CreateRestartPoint(int flags) if (!RecoveryInProgress()) replayTLI = XLogCtl->InsertTimeLineID; + checkpoint_progress_update_param(flags, PROGRESS_CHECKPOINT_PHASE, + PROGRESS_CHECKPOINT_PHASE_OLD_XLOG_RECYCLE); RemoveOldXlogFiles(_logSegNo, RedoRecPtr, endptr, replayTLI); + checkpoint_progress_update_param(flags, PROGRESS_CHECKPOINT_PHASE, + PROGRESS_CHECKPOINT_PHASE_FINALIZE); /* * Make more log segments if needed. (Do this after recycling old log @@ -9858,6 +9906,9 @@ CreateRestartPoint(int flags) /* Real work is done; log and update stats. */ LogCheckpointEnd(true); + /* Stop reporting progress of the checkpoint. */ + checkpoint_progress_end(flags); + /* Reset the process title */ update_checkpoint_display(flags, true, true); @@ -13242,3 +13293,73 @@ XLogRequestWalReceiverReply(void) { doRequestWalReceiverReply = true; } + +/* + * Start reporting progress of the checkpoint. + */ +void +checkpoint_progress_start(int flags) +{ + /* In bootstrap mode, we don't actually record anything. */ + if (IsBootstrapProcessingMode()) + return; + + /* + * Cannot access pg_stat_progress_checkpoint view in case of checkpoint + * during shutdown and end-of-recovery. + */ + if ((flags & (CHECKPOINT_IS_SHUTDOWN | CHECKPOINT_END_OF_RECOVERY)) == 0) + { + pgstat_progress_start_command(PROGRESS_COMMAND_CHECKPOINT, InvalidOid); + checkpoint_progress_update_param(flags, PROGRESS_CHECKPOINT_PHASE, + PROGRESS_CHECKPOINT_PHASE_INIT); + if (flags & CHECKPOINT_CAUSE_XLOG) + checkpoint_progress_update_param(flags, PROGRESS_CHECKPOINT_KIND, + PROGRESS_CHECKPOINT_KIND_WAL); + else if (flags & CHECKPOINT_CAUSE_TIME) + checkpoint_progress_update_param(flags, PROGRESS_CHECKPOINT_KIND, + PROGRESS_CHECKPOINT_KIND_TIME); + else if (flags & CHECKPOINT_FORCE) + checkpoint_progress_update_param(flags, PROGRESS_CHECKPOINT_KIND, + PROGRESS_CHECKPOINT_KIND_FORCE); + else + checkpoint_progress_update_param(flags, PROGRESS_CHECKPOINT_KIND, + PROGRESS_CHECKPOINT_KIND_UNKNOWN); + } +} + +/* + * Update index'th member in st_progress_param[] array with the latest value. + */ +void +checkpoint_progress_update_param(int flags, int index, int64 val) +{ + /* In bootstrap mode, we don't actually record anything. */ + if (IsBootstrapProcessingMode()) + return; + + /* + * Cannot access pg_stat_progress_checkpoint view in case of checkpoint + * during shutdown and end-of-recovery. + */ + if ((flags & (CHECKPOINT_IS_SHUTDOWN | CHECKPOINT_END_OF_RECOVERY)) == 0) + pgstat_progress_update_param(index, val); +} + +/* + * Stop reporting progress of the checkpoint. + */ +void +checkpoint_progress_end(int flags) +{ + /* In bootstrap mode, we don't actually record anything. */ + if (IsBootstrapProcessingMode()) + return; + + /* + * Cannot access pg_stat_progress_checkpoint view in case of checkpoint + * during shutdown and end-of-recovery. + */ + if ((flags & (CHECKPOINT_IS_SHUTDOWN | CHECKPOINT_END_OF_RECOVERY)) == 0) + pgstat_progress_end_command(); +} \ No newline at end of file diff --git a/src/backend/catalog/system_views.sql b/src/backend/catalog/system_views.sql index 3cb69b1f87..6a90d63fff 100644 --- a/src/backend/catalog/system_views.sql +++ b/src/backend/catalog/system_views.sql @@ -1286,3 +1286,32 @@ CREATE VIEW pg_stat_subscription_workers AS FROM pg_subscription_rel) sr, LATERAL pg_stat_get_subscription_worker(sr.subid, sr.relid) w JOIN pg_subscription s ON (w.subid = s.oid); + +CREATE VIEW pg_stat_progress_checkpoint AS + SELECT + S.pid AS pid, + CASE S.param1 WHEN 0 THEN 'wal' + WHEN 1 THEN 'time' + WHEN 2 THEN 'force' + END AS kind, + CASE S.param2 WHEN 0 THEN 'initializing' + WHEN 1 THEN 'checkpointing replication slots' + WHEN 2 THEN 'checkpointing snapshots' + WHEN 3 THEN 'checkpointing logical rewrite mappings' + WHEN 4 THEN 'checkpointing CLOG pages' + WHEN 5 THEN 'checkpointing CommitTs pages' + WHEN 6 THEN 'checkpointing SUBTRANS pages' + WHEN 7 THEN 'checkpointing MULTIXACT pages' + WHEN 8 THEN 'checkpointing SLRU pages' + WHEN 9 THEN 'checkpointing buffers' + WHEN 10 THEN 'performing sync requests' + WHEN 11 THEN 'performing two phase checkpoint' + WHEN 12 THEN 'recycling old XLOG files' + WHEN 13 THEN 'Finalizing' + END AS phase, + S.param3 AS total_buffer_writes, + S.param4 AS buffers_processed, + S.param5 AS buffers_written, + S.param6 AS total_file_syncs, + S.param7 AS files_synced + FROM pg_stat_get_progress_info('CHECKPOINT') AS S; diff --git a/src/backend/storage/buffer/bufmgr.c b/src/backend/storage/buffer/bufmgr.c index f5459c68f8..cf0ad299f3 100644 --- a/src/backend/storage/buffer/bufmgr.c +++ b/src/backend/storage/buffer/bufmgr.c @@ -38,6 +38,7 @@ #include "access/xlogutils.h" #include "catalog/catalog.h" #include "catalog/storage.h" +#include "commands/progress.h" #include "executor/instrument.h" #include "lib/binaryheap.h" #include "miscadmin.h" @@ -2012,6 +2013,9 @@ BufferSync(int flags) WritebackContextInit(&wb_context, &checkpoint_flush_after); TRACE_POSTGRESQL_BUFFER_SYNC_START(NBuffers, num_to_scan); + checkpoint_progress_update_param(flags, + PROGRESS_CHECKPOINT_TOTAL_BUFFER_WRITES, + num_to_scan); /* * Sort buffers that need to be written to reduce the likelihood of random @@ -2129,6 +2133,9 @@ BufferSync(int flags) bufHdr = GetBufferDescriptor(buf_id); num_processed++; + checkpoint_progress_update_param(flags, + PROGRESS_CHECKPOINT_BUFFERS_PROCESSED, + num_processed); /* * We don't need to acquire the lock here, because we're only looking @@ -2149,6 +2156,9 @@ BufferSync(int flags) TRACE_POSTGRESQL_BUFFER_SYNC_WRITTEN(buf_id); PendingCheckpointerStats.m_buf_written_checkpoints++; num_written++; + checkpoint_progress_update_param(flags, + PROGRESS_CHECKPOINT_BUFFERS_WRITTEN, + num_written); } } diff --git a/src/backend/storage/sync/sync.c b/src/backend/storage/sync/sync.c index 543f691f2d..b8f6aebb7c 100644 --- a/src/backend/storage/sync/sync.c +++ b/src/backend/storage/sync/sync.c @@ -23,6 +23,7 @@ #include "access/multixact.h" #include "access/xlog.h" #include "access/xlogutils.h" +#include "commands/progress.h" #include "commands/tablespace.h" #include "miscadmin.h" #include "pgstat.h" @@ -277,7 +278,7 @@ SyncPostCheckpoint(void) * ProcessSyncRequests() -- Process queued fsync requests. */ void -ProcessSyncRequests(void) +ProcessSyncRequests(int flags) { static bool sync_in_progress = false; @@ -355,6 +356,10 @@ ProcessSyncRequests(void) /* Now scan the hashtable for fsync requests to process */ absorb_counter = FSYNCS_PER_ABSORB; hash_seq_init(&hstat, pendingOps); + checkpoint_progress_update_param(flags, + PROGRESS_CHECKPOINT_TOTAL_FILE_SYNCS, + hash_get_num_entries(pendingOps)); + while ((entry = (PendingFsyncEntry *) hash_seq_search(&hstat)) != NULL) { int failures; @@ -418,6 +423,9 @@ ProcessSyncRequests(void) longest = elapsed; total_elapsed += elapsed; processed++; + checkpoint_progress_update_param(flags, + PROGRESS_CHECKPOINT_FILES_SYNCED, + processed); if (log_checkpoints) elog(DEBUG1, "checkpoint sync: number=%d file=%s time=%.3f ms", diff --git a/src/backend/utils/adt/pgstatfuncs.c b/src/backend/utils/adt/pgstatfuncs.c index 15cb17ace4..7438e0ce84 100644 --- a/src/backend/utils/adt/pgstatfuncs.c +++ b/src/backend/utils/adt/pgstatfuncs.c @@ -494,6 +494,8 @@ pg_stat_get_progress_info(PG_FUNCTION_ARGS) cmdtype = PROGRESS_COMMAND_BASEBACKUP; else if (pg_strcasecmp(cmd, "COPY") == 0) cmdtype = PROGRESS_COMMAND_COPY; + else if (pg_strcasecmp(cmd, "CHECKPOINT") == 0) + cmdtype = PROGRESS_COMMAND_CHECKPOINT; else ereport(ERROR, (errcode(ERRCODE_INVALID_PARAMETER_VALUE), diff --git a/src/include/access/xlog.h b/src/include/access/xlog.h index a4b1c1286f..58c547b2d5 100644 --- a/src/include/access/xlog.h +++ b/src/include/access/xlog.h @@ -353,6 +353,10 @@ extern void do_pg_abort_backup(int code, Datum arg); extern void register_persistent_abort_backup_handler(void); extern SessionBackupState get_backup_status(void); +extern void checkpoint_progress_start(int flags); +extern void checkpoint_progress_update_param(int flags, int index, int64 val); +extern void checkpoint_progress_end(int flags); + /* File path names (all relative to $PGDATA) */ #define RECOVERY_SIGNAL_FILE "recovery.signal" #define STANDBY_SIGNAL_FILE "standby.signal" diff --git a/src/include/commands/progress.h b/src/include/commands/progress.h index a28938caf4..e1c574d053 100644 --- a/src/include/commands/progress.h +++ b/src/include/commands/progress.h @@ -151,4 +151,35 @@ #define PROGRESS_COPY_TYPE_PIPE 3 #define PROGRESS_COPY_TYPE_CALLBACK 4 +/* Progress parameters for checkpoint */ +#define PROGRESS_CHECKPOINT_KIND 0 +#define PROGRESS_CHECKPOINT_PHASE 1 +#define PROGRESS_CHECKPOINT_TOTAL_BUFFER_WRITES 2 +#define PROGRESS_CHECKPOINT_BUFFERS_PROCESSED 3 +#define PROGRESS_CHECKPOINT_BUFFERS_WRITTEN 4 +#define PROGRESS_CHECKPOINT_TOTAL_FILE_SYNCS 5 +#define PROGRESS_CHECKPOINT_FILES_SYNCED 6 + +/* Kinds of checkpoint (as advertised via PROGRESS_CHECKPOINT_KIND) */ +#define PROGRESS_CHECKPOINT_KIND_WAL 0 +#define PROGRESS_CHECKPOINT_KIND_TIME 1 +#define PROGRESS_CHECKPOINT_KIND_FORCE 2 +#define PROGRESS_CHECKPOINT_KIND_UNKNOWN 3 + +/* Phases of checkpoint (as advertised via PROGRESS_CHECKPOINT_PHASE) */ +#define PROGRESS_CHECKPOINT_PHASE_INIT 0 +#define PROGRESS_CHECKPOINT_PHASE_REPLI_SLOTS 1 +#define PROGRESS_CHECKPOINT_PHASE_SNAPSHOTS 2 +#define PROGRESS_CHECKPOINT_PHASE_LOGICAL_REWRITE_MAPPINGS 3 +#define PROGRESS_CHECKPOINT_PHASE_CLOG_PAGES 4 +#define PROGRESS_CHECKPOINT_PHASE_COMMITTS_PAGES 5 +#define PROGRESS_CHECKPOINT_PHASE_SUBTRANS_PAGES 6 +#define PROGRESS_CHECKPOINT_PHASE_MULTIXACT_PAGES 7 +#define PROGRESS_CHECKPOINT_PHASE_SLRU_PAGES 8 +#define PROGRESS_CHECKPOINT_PHASE_BUFFERS 9 +#define PROGRESS_CHECKPOINT_PHASE_FILE_SYNC 10 +#define PROGRESS_CHECKPOINT_PHASE_TWO_PHASE 11 +#define PROGRESS_CHECKPOINT_PHASE_OLD_XLOG_RECYCLE 12 +#define PROGRESS_CHECKPOINT_PHASE_FINALIZE 13 + #endif diff --git a/src/include/storage/sync.h b/src/include/storage/sync.h index 9737e1eb67..fed52efa30 100644 --- a/src/include/storage/sync.h +++ b/src/include/storage/sync.h @@ -58,7 +58,7 @@ typedef struct FileTag extern void InitSync(void); extern void SyncPreCheckpoint(void); extern void SyncPostCheckpoint(void); -extern void ProcessSyncRequests(void); +extern void ProcessSyncRequests(int flags); extern void RememberSyncRequest(const FileTag *ftag, SyncRequestType type); extern bool RegisterSyncRequest(const FileTag *ftag, SyncRequestType type, bool retryOnError); diff --git a/src/include/utils/backend_progress.h b/src/include/utils/backend_progress.h index 47bf8029b0..02d51fb948 100644 --- a/src/include/utils/backend_progress.h +++ b/src/include/utils/backend_progress.h @@ -27,7 +27,8 @@ typedef enum ProgressCommandType PROGRESS_COMMAND_CLUSTER, PROGRESS_COMMAND_CREATE_INDEX, PROGRESS_COMMAND_BASEBACKUP, - PROGRESS_COMMAND_COPY + PROGRESS_COMMAND_COPY, + PROGRESS_COMMAND_CHECKPOINT } ProgressCommandType; #define PGSTAT_NUM_PROGRESS_PARAM 20 -- 2.25.1