Hi all, On Thu, Jan 8, 2026 at 11:06 PM Michael Banck <[email protected]> wrote: > > Hi, > > On Thu, Jan 08, 2026 at 11:58:43AM +0530, Soumya S Murali wrote: > > On Wed, Jan 7, 2026 at 1:37 PM Michael Banck <[email protected]> wrote: > > > On Wed, Jan 07, 2026 at 12:35:08PM +0530, Soumya S Murali wrote: > > I have reworked the patch to factor out the checkpoint reason logic to > > use the same wording for both checkpoint start and completion log > > (including wal, time, fast, force, and wait). The format has been > > aligned with existing conventions and has been verified by running > > make check and recovery TAP tests including t/019_replslot_limit.pl > > successfully. > > Kindly review my patch and let me know the feedback. > > Thanks for the new patch. > > > index 22d0a2e8c3..9f7439f9a2 100644 > > --- a/src/backend/access/transam/xlog.c > > +++ b/src/backend/access/transam/xlog.c > [...] > > +static const char * > > +CheckpointReasonString(int flags) > > +{ > > + static char buf[128]; > > + > > + buf[0] = '\0'; > > + > > + if (flags & CHECKPOINT_IS_SHUTDOWN) > > + strcat(buf, " shutdown"); > > + if (flags & CHECKPOINT_END_OF_RECOVERY) > > + strcat(buf, " end-of-recovery"); > > + if (flags & CHECKPOINT_FAST) > > + strcat(buf, " fast"); > > + if (flags & CHECKPOINT_FORCE) > > + strcat(buf, " force"); > > + if (flags & CHECKPOINT_WAIT) > > + strcat(buf, " wait"); > > + if (flags & CHECKPOINT_CAUSE_XLOG) > > + strcat(buf, " wal"); > > + if (flags & CHECKPOINT_CAUSE_TIME) > > + strcat(buf, " time"); > > + if (flags & CHECKPOINT_FLUSH_UNLOGGED) > > + strcat(buf, " flush-unlogged"); > > + > > + return buf; > > +} > > The way this is coded now prepends the final string with a space > character. This is fine for the checkpoint starting message, but makes > the checkpoint finished message look slightly weird (not the "( wal)"): > > |2026-01-08 18:30:33.691 CET [1666416] LOG: checkpoint complete ( wal): > |wrote 20 buffers (0.1%), wrote 0 SLRU buffers; 0 WAL file(s) added, 4 > |removed, 33 recycled; write=2.221 s, sync=0.019 s, total=2.701 s; sync > |files=3, longest=0.018 s, average=0.007 s; distance=601885 kB, > |estimate=601885 kB; lsn=0/D2D59FC8, redo lsn=0/B492B500 > > Also I think the translators might now complain, but I am not sure how > to best approach this.
Based on the feedback received, I have reworked and implemented a helper function so that both checkpoint start and completion messages use the same wording and would remain in sync, extending the same reason reporting to restart points for completeness and better observability, ensuring consistent terminology with existing log output, had removed the previous use of global state and instead passed checkpoint flags explicitly and have fixed formatting and whitespace issues noted during review. Also, I have tested and validated the logic successfully. I have attached the updated patch for further review. Kindly review the patch and let me know the feedback. Regards, Soumya
From 30e3c62695a643daf96ffca3b504a79d2a761f77 Mon Sep 17 00:00:00 2001 From: Soumya <[email protected]> Date: Mon, 12 Jan 2026 12:36:29 +0530 Subject: [PATCH] Expose checkpoint reason in completion log messages --- src/backend/access/transam/xlog.c | 78 ++++++++++++++++------- src/test/recovery/t/019_replslot_limit.pl | 2 +- 2 files changed, 55 insertions(+), 25 deletions(-) diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c index 22d0a2e8c3..63d1e56ca1 100644 --- a/src/backend/access/transam/xlog.c +++ b/src/backend/access/transam/xlog.c @@ -6714,6 +6714,49 @@ 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 +6766,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 +6828,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 +6853,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 +7448,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 +7916,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
