From c2ed1eb81b38c36399b8fbec5bf09326b06fefa0 Mon Sep 17 00:00:00 2001 From: Soumya Date: Tue, 13 Jan 2026 11:50:53 +0530 Subject: [PATCH] Expose checkpoint reason in completion log messages Signed-off-by: Soumya --- src/backend/access/transam/xlog.c | 79 ++++++++++++++++------- src/test/recovery/t/019_replslot_limit.pl | 2 +- 2 files changed, 56 insertions(+), 25 deletions(-) diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c index 22d0a2e8c3..8cdf2b23c3 100644 --- a/src/backend/access/transam/xlog.c +++ b/src/backend/access/transam/xlog.c @@ -6714,6 +6714,50 @@ ShutdownXLOG(int code, Datum arg) } } +/* + * Format checkpoint reason flags consistently for log messages. + * The returned string is suitable for inclusion after + * "checkpoint starting:" or inside "checkpoint complete (...)". + */ +static const char * +CheckpointReasonString(int flags) +{ + static char buf[128]; + bool first = true; + + buf[0] = '\0'; + +#define APPEND_REASON(str) \ + do \ + { \ + if (!first) \ + strcat(buf, " "); \ + strcat(buf, (str)); \ + first = false; \ + } while (0) + + if (flags & CHECKPOINT_IS_SHUTDOWN) + APPEND_REASON("shutdown"); + if (flags & CHECKPOINT_END_OF_RECOVERY) + APPEND_REASON("end-of-recovery"); + if (flags & CHECKPOINT_FAST) + APPEND_REASON("fast"); + if (flags & CHECKPOINT_FORCE) + APPEND_REASON("force"); + if (flags & CHECKPOINT_WAIT) + APPEND_REASON("wait"); + if (flags & CHECKPOINT_CAUSE_XLOG) + APPEND_REASON("wal"); + if (flags & CHECKPOINT_CAUSE_TIME) + APPEND_REASON("time"); + if (flags & CHECKPOINT_FLUSH_UNLOGGED) + APPEND_REASON("flush-unlogged"); + +#undef APPEND_REASON + + return buf; +} + /* * Log start of a checkpoint. */ @@ -6723,34 +6767,19 @@ LogCheckpointStart(int flags, bool restartpoint) if (restartpoint) ereport(LOG, /* translator: the placeholders show checkpoint options */ - (errmsg("restartpoint starting:%s%s%s%s%s%s%s%s", - (flags & CHECKPOINT_IS_SHUTDOWN) ? " shutdown" : "", - (flags & CHECKPOINT_END_OF_RECOVERY) ? " end-of-recovery" : "", - (flags & CHECKPOINT_FAST) ? " fast" : "", - (flags & CHECKPOINT_FORCE) ? " force" : "", - (flags & CHECKPOINT_WAIT) ? " wait" : "", - (flags & CHECKPOINT_CAUSE_XLOG) ? " wal" : "", - (flags & CHECKPOINT_CAUSE_TIME) ? " time" : "", - (flags & CHECKPOINT_FLUSH_UNLOGGED) ? " flush-unlogged" : ""))); + (errmsg("restartpoint starting: %s", + CheckpointReasonString(flags)))); else ereport(LOG, - /* translator: the placeholders show checkpoint options */ - (errmsg("checkpoint starting:%s%s%s%s%s%s%s%s", - (flags & CHECKPOINT_IS_SHUTDOWN) ? " shutdown" : "", - (flags & CHECKPOINT_END_OF_RECOVERY) ? " end-of-recovery" : "", - (flags & CHECKPOINT_FAST) ? " fast" : "", - (flags & CHECKPOINT_FORCE) ? " force" : "", - (flags & CHECKPOINT_WAIT) ? " wait" : "", - (flags & CHECKPOINT_CAUSE_XLOG) ? " wal" : "", - (flags & CHECKPOINT_CAUSE_TIME) ? " time" : "", - (flags & CHECKPOINT_FLUSH_UNLOGGED) ? " flush-unlogged" : ""))); + (errmsg("checkpoint starting: %s", + CheckpointReasonString(flags)))); } /* * Log end of a checkpoint. */ static void -LogCheckpointEnd(bool restartpoint) +LogCheckpointEnd(bool restartpoint, int flags) { long write_msecs, sync_msecs, @@ -6800,12 +6829,13 @@ LogCheckpointEnd(bool restartpoint) */ if (restartpoint) ereport(LOG, - (errmsg("restartpoint complete: wrote %d buffers (%.1f%%), " + (errmsg("restartpoint complete (%s): wrote %d buffers (%.1f%%), " "wrote %d SLRU buffers; %d WAL file(s) added, " "%d removed, %d recycled; write=%ld.%03d s, " "sync=%ld.%03d s, total=%ld.%03d s; sync files=%d, " "longest=%ld.%03d s, average=%ld.%03d s; distance=%d kB, " "estimate=%d kB; lsn=%X/%08X, redo lsn=%X/%08X", + CheckpointReasonString(flags), CheckpointStats.ckpt_bufs_written, (double) CheckpointStats.ckpt_bufs_written * 100 / NBuffers, CheckpointStats.ckpt_slru_written, @@ -6824,12 +6854,13 @@ LogCheckpointEnd(bool restartpoint) LSN_FORMAT_ARGS(ControlFile->checkPointCopy.redo)))); else ereport(LOG, - (errmsg("checkpoint complete: wrote %d buffers (%.1f%%), " + (errmsg("checkpoint complete (%s): wrote %d buffers (%.1f%%), " "wrote %d SLRU buffers; %d WAL file(s) added, " "%d removed, %d recycled; write=%ld.%03d s, " "sync=%ld.%03d s, total=%ld.%03d s; sync files=%d, " "longest=%ld.%03d s, average=%ld.%03d s; distance=%d kB, " "estimate=%d kB; lsn=%X/%08X, redo lsn=%X/%08X", + CheckpointReasonString(flags), CheckpointStats.ckpt_bufs_written, (double) CheckpointStats.ckpt_bufs_written * 100 / NBuffers, CheckpointStats.ckpt_slru_written, @@ -7418,7 +7449,7 @@ CreateCheckPoint(int flags) TruncateSUBTRANS(GetOldestTransactionIdConsideredRunning()); /* Real work is done; log and update stats. */ - LogCheckpointEnd(false); + LogCheckpointEnd(false, flags); /* Reset the process title */ update_checkpoint_display(flags, false, true); @@ -7886,7 +7917,7 @@ CreateRestartPoint(int flags) TruncateSUBTRANS(GetOldestTransactionIdConsideredRunning()); /* Real work is done; log and update stats. */ - LogCheckpointEnd(true); + LogCheckpointEnd(true, flags); /* Reset the process title */ update_checkpoint_display(flags, true, true); diff --git a/src/test/recovery/t/019_replslot_limit.pl b/src/test/recovery/t/019_replslot_limit.pl index 6468784b83..ccc363157e 100644 --- a/src/test/recovery/t/019_replslot_limit.pl +++ b/src/test/recovery/t/019_replslot_limit.pl @@ -203,7 +203,7 @@ is($result, "rep1|f|t|lost|", my $checkpoint_ended = 0; for (my $i = 0; $i < 10 * $PostgreSQL::Test::Utils::timeout_default; $i++) { - if ($node_primary->log_contains("checkpoint complete: ", $logstart)) + if ($node_primary->log_contains(qr/checkpoint complete(?: \([^)]*\))?:/, $logstart)) { $checkpoint_ended = 1; last; -- 2.34.1