Add checkpoint and REDO LSN to log_checkpoints message.

It is useful for debugging purposes to report the checkpoint LSN and
REDO LSN in log_checkpoints message. It can give more context while
analyzing checkpoint-related issues. pg_controldata reports the last
checkpoint LSN and REDO LSN, but having this information alongside
the log message helps analyze issues that happened previously,
connect the dots and identify the root cause.

Author: Bharath Rupireddy, Kyotaro Horiguchi
Reviewed-by: Michael Paquier, Julien Rouhaud, Nathan Bossart, Fujii Masao, Greg Stark
Discussion: https://postgr.es/m/CALj2ACWt6kqriAHrO+AJj+OmP=suwbktHT5JoYAn-nqZe2gd2g@mail.gmail.com
This commit is contained in:
Fujii Masao 2022-07-07 22:37:54 +09:00
parent 8d367a44d3
commit 62c46eee22
1 changed files with 15 additions and 4 deletions

View File

@ -6129,13 +6129,19 @@ LogCheckpointEnd(bool restartpoint)
CheckpointStats.ckpt_sync_rels;
average_msecs = (long) ((average_sync_time + 999) / 1000);
/*
* ControlFileLock is not required to see ControlFile->checkPoint and
* ->checkPointCopy here as we are the only updator of those variables at
* this moment.
*/
if (restartpoint)
ereport(LOG,
(errmsg("restartpoint complete: wrote %d buffers (%.1f%%); "
"%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",
"distance=%d kB, estimate=%d kB; "
"lsn=%X/%X, redo lsn=%X/%X",
CheckpointStats.ckpt_bufs_written,
(double) CheckpointStats.ckpt_bufs_written * 100 / NBuffers,
CheckpointStats.ckpt_segs_added,
@ -6148,14 +6154,17 @@ LogCheckpointEnd(bool restartpoint)
longest_msecs / 1000, (int) (longest_msecs % 1000),
average_msecs / 1000, (int) (average_msecs % 1000),
(int) (PrevCheckPointDistance / 1024.0),
(int) (CheckPointDistanceEstimate / 1024.0))));
(int) (CheckPointDistanceEstimate / 1024.0),
LSN_FORMAT_ARGS(ControlFile->checkPoint),
LSN_FORMAT_ARGS(ControlFile->checkPointCopy.redo))));
else
ereport(LOG,
(errmsg("checkpoint complete: wrote %d buffers (%.1f%%); "
"%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",
"distance=%d kB, estimate=%d kB; "
"lsn=%X/%X, redo lsn=%X/%X",
CheckpointStats.ckpt_bufs_written,
(double) CheckpointStats.ckpt_bufs_written * 100 / NBuffers,
CheckpointStats.ckpt_segs_added,
@ -6168,7 +6177,9 @@ LogCheckpointEnd(bool restartpoint)
longest_msecs / 1000, (int) (longest_msecs % 1000),
average_msecs / 1000, (int) (average_msecs % 1000),
(int) (PrevCheckPointDistance / 1024.0),
(int) (CheckPointDistanceEstimate / 1024.0))));
(int) (CheckPointDistanceEstimate / 1024.0),
LSN_FORMAT_ARGS(ControlFile->checkPoint),
LSN_FORMAT_ARGS(ControlFile->checkPointCopy.redo))));
}
/*