From 465ed2178a5437f31497ca5f5bb4a38ed0451b7a Mon Sep 17 00:00:00 2001 From: BharatDB Date: Mon, 10 Nov 2025 11:15:24 +0530 Subject: [PATCH] Added enhancement related to checkpoint reason / duration info in logs and stats Signed-off-by: BharatDB --- src/backend/access/transam/xlog.c | 11 +++++- src/backend/catalog/system_views.sql | 4 ++- .../utils/activity/pgstat_checkpointer.c | 34 +++++++++++++++++++ src/backend/utils/adt/pgstatfuncs.c | 21 ++++++++++++ src/include/catalog/pg_proc.dat | 11 ++++++ src/include/pgstat.h | 5 ++- 6 files changed, 83 insertions(+), 3 deletions(-) diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c index ec992d2139..9217508917 100644 --- a/src/backend/access/transam/xlog.c +++ b/src/backend/access/transam/xlog.c @@ -6761,6 +6761,7 @@ LogCheckpointEnd(bool restartpoint, int flags) sync_msecs = TimestampDifferenceMilliseconds(CheckpointStats.ckpt_sync_t, CheckpointStats.ckpt_sync_end_t); + /* Accumulate checkpoint timing summary data, in milliseconds. */ PendingCheckpointerStats.write_time += write_msecs; PendingCheckpointerStats.sync_time += sync_msecs; @@ -6774,7 +6775,15 @@ LogCheckpointEnd(bool restartpoint, int flags) total_msecs = TimestampDifferenceMilliseconds(CheckpointStats.ckpt_start_t, CheckpointStats.ckpt_end_t); - + + + /* Store in PendingCheckpointerStats */ + PendingCheckpointerStats.checkpoint_total_time += (double) total_msecs; + PendingCheckpointerStats.last_checkpoint_time = CheckpointStats.ckpt_end_t; + + /* Publishing it */ + pgstat_report_checkpointer(); + /* * Timing values returned from CheckpointStats are in microseconds. * Convert to milliseconds for consistent printing. diff --git a/src/backend/catalog/system_views.sql b/src/backend/catalog/system_views.sql index dec8df4f8e..903e001d95 100644 --- a/src/backend/catalog/system_views.sql +++ b/src/backend/catalog/system_views.sql @@ -1190,7 +1190,9 @@ CREATE VIEW pg_stat_checkpointer AS pg_stat_get_checkpointer_sync_time() AS sync_time, pg_stat_get_checkpointer_buffers_written() AS buffers_written, pg_stat_get_checkpointer_slru_written() AS slru_written, - pg_stat_get_checkpointer_stat_reset_time() AS stats_reset; + pg_stat_get_checkpointer_stat_reset_time() AS stats_reset, + pg_stat_get_checkpointer_checkpoint_total_time() AS checkpoint_total_time, + pg_stat_get_checkpointer_last_checkpoint_time() AS last_checkpoint_time; CREATE VIEW pg_stat_io AS SELECT diff --git a/src/backend/utils/activity/pgstat_checkpointer.c b/src/backend/utils/activity/pgstat_checkpointer.c index e65034a30a..62ef427b82 100644 --- a/src/backend/utils/activity/pgstat_checkpointer.c +++ b/src/backend/utils/activity/pgstat_checkpointer.c @@ -56,8 +56,14 @@ pgstat_report_checkpointer(void) CHECKPOINTER_ACC(sync_time); CHECKPOINTER_ACC(buffers_written); CHECKPOINTER_ACC(slru_written); + CHECKPOINTER_ACC(checkpoint_total_time); #undef CHECKPOINTER_ACC + /* only overwrite if we actually have a new timestamp */ + if (PendingCheckpointerStats.last_checkpoint_time != 0) + stats_shmem->stats.last_checkpoint_time = + PendingCheckpointerStats.last_checkpoint_time; + pgstat_end_changecount_write(&stats_shmem->changecount); /* @@ -71,6 +77,28 @@ pgstat_report_checkpointer(void) pgstat_flush_io(false); } +/* ------------------------------------------------------------ + * Extended checkpointer stats reporting function + * ------------------------------------------------------------ + */ +void +pgstat_report_checkpointer_extended(long total_msecs, TimestampTz end_time) +{ + + PgStat_CheckpointerStats *checkpointer_stats; + + + checkpointer_stats = pgstat_fetch_stat_checkpointer(); + if (!checkpointer_stats) + return; + + + checkpointer_stats->checkpoint_total_time += total_msecs; + checkpointer_stats->last_checkpoint_time = end_time; + +} + + /* * pgstat_fetch_stat_checkpointer() - * @@ -136,5 +164,11 @@ pgstat_checkpointer_snapshot_cb(void) CHECKPOINTER_COMP(sync_time); CHECKPOINTER_COMP(buffers_written); CHECKPOINTER_COMP(slru_written); + CHECKPOINTER_COMP(checkpoint_total_time); #undef CHECKPOINTER_COMP + + pgStatLocal.snapshot.checkpointer.last_checkpoint_time = stats_shmem->stats.last_checkpoint_time; + + elog(LOG, "DBG snapshot_cb: copied last_checkpoint_time=%ld", + (long) pgStatLocal.snapshot.checkpointer.last_checkpoint_time); } diff --git a/src/backend/utils/adt/pgstatfuncs.c b/src/backend/utils/adt/pgstatfuncs.c index a710508979..591ad2ac88 100644 --- a/src/backend/utils/adt/pgstatfuncs.c +++ b/src/backend/utils/adt/pgstatfuncs.c @@ -2292,3 +2292,24 @@ pg_stat_have_stats(PG_FUNCTION_ARGS) PG_RETURN_BOOL(pgstat_have_entry(kind, dboid, objid)); } + +PG_FUNCTION_INFO_V1(pg_stat_get_checkpointer_checkpoint_total_time); + +Datum +pg_stat_get_checkpointer_checkpoint_total_time(PG_FUNCTION_ARGS) +{ + PgStat_CheckpointerStats *stats = pgstat_fetch_stat_checkpointer(); + PG_RETURN_FLOAT8(stats->checkpoint_total_time); +} + +PG_FUNCTION_INFO_V1(pg_stat_get_checkpointer_last_checkpoint_time); + +Datum +pg_stat_get_checkpointer_last_checkpoint_time(PG_FUNCTION_ARGS) +{ + + PgStat_CheckpointerStats *stats = pgstat_fetch_stat_checkpointer(); + if (!stats) PG_RETURN_NULL(); + PG_RETURN_TIMESTAMPTZ(stats->last_checkpoint_time); + +} diff --git a/src/include/catalog/pg_proc.dat b/src/include/catalog/pg_proc.dat index 9121a382f7..a57053c4e2 100644 --- a/src/include/catalog/pg_proc.dat +++ b/src/include/catalog/pg_proc.dat @@ -5980,6 +5980,17 @@ proname => 'pg_stat_get_checkpointer_stat_reset_time', provolatile => 's', proparallel => 'r', prorettype => 'timestamptz', proargtypes => '', prosrc => 'pg_stat_get_checkpointer_stat_reset_time' }, +# New functions for checkpointer +{ oid => '7000', + descr => 'total time spent in last checkpoint in milliseconds', + proname => 'pg_stat_get_checkpointer_checkpoint_total_time', provolatile => 's', + proparallel => 'r', prorettype => 'float8', proargtypes => '', + prosrc => 'pg_stat_get_checkpointer_checkpoint_total_time' }, +{ oid => '7001', + descr => 'timestamp of last checkpoint completion', + proname => 'pg_stat_get_checkpointer_last_checkpoint_time', provolatile => 's', + proparallel => 'r', prorettype => 'timestamptz', proargtypes => '', + prosrc => 'pg_stat_get_checkpointer_last_checkpoint_time' }, { oid => '2772', descr => 'statistics: number of buffers written by the bgwriter for cleaning dirty buffers', proname => 'pg_stat_get_bgwriter_buf_written_clean', provolatile => 's', diff --git a/src/include/pgstat.h b/src/include/pgstat.h index 7ae503e71a..a8eb1f8add 100644 --- a/src/include/pgstat.h +++ b/src/include/pgstat.h @@ -263,7 +263,9 @@ typedef struct PgStat_CheckpointerStats PgStat_Counter sync_time; PgStat_Counter buffers_written; PgStat_Counter slru_written; - TimestampTz stat_reset_timestamp; + PgStat_Counter checkpoint_total_time; /* new: total ms of last checkpoint */ + TimestampTz last_checkpoint_time; /* new: end time of last checkpoint */ + TimestampTz stat_reset_timestamp; } PgStat_CheckpointerStats; @@ -583,6 +585,7 @@ extern PgStat_BgWriterStats *pgstat_fetch_stat_bgwriter(void); extern void pgstat_report_checkpointer(void); extern PgStat_CheckpointerStats *pgstat_fetch_stat_checkpointer(void); +extern void pgstat_report_checkpointer_extended(long total_msecs, TimestampTz end_time); /* -- 2.34.1