public inbox for [email protected]  
help / color / mirror / Atom feed
From: Bharath Rupireddy <[email protected]>
To: Fujii Masao <[email protected]>
Cc: Nathan Bossart <[email protected]>
Cc: Stephen Frost <[email protected]>
Cc: Kyotaro Horiguchi <[email protected]>
Cc: Bossart, Nathan <[email protected]>
Cc: Julien Rouhaud <[email protected]>
Cc: Michael Paquier <[email protected]>
Cc: PostgreSQL Hackers <[email protected]>
Subject: Re: Add checkpoint and redo LSN to LogCheckpointEnd log message
Date: Tue, 1 Feb 2022 10:08:04 +0530
Message-ID: <CALj2ACU9ynpCwfuL0a4Bx0SDbHcjRDk49pwjDwfOzoQ1-kx1pw@mail.gmail.com> (raw)
In-Reply-To: <[email protected]>
References: <CALj2ACVM4wjS+wiNZf4ssdNMhSR-XUhR99fYbV=pC9_-=5wCtw@mail.gmail.com>
	<[email protected]>
	<[email protected]>
	<CALj2ACUaGJQVbQ5Hms_C2tu+6iJX-EWkEdOiXwX1WfrxQX8pHA@mail.gmail.com>
	<20220128054620.GA654866@nathanxps13>
	<CALj2ACXWyK9DujhndkuGXb7idjL9wPJfMpzRPpM-DT1LQ6MB=Q@mail.gmail.com>
	<[email protected]>
	<CALj2ACU5NZ142kp2Bn-PK1S2G8AEENYVBfD=Cyz=fskQ6Vtf1A@mail.gmail.com>
	<20220131183009.GA660545@nathanxps13>
	<CALj2ACUaUJGvwYi4ztcc6-o2ju48BcNvayB0OuDt0-1gYHmHRw@mail.gmail.com>
	<20220201014435.GA738413@nathanxps13>
	<[email protected]>
	<CALj2ACXDHGfhKkwzi81BRqWft4n85AO1zmkeqf6xEg+0xTCH9g@mail.gmail.com>
	<[email protected]>

On Tue, Feb 1, 2022 at 9:49 AM Fujii Masao <[email protected]> wrote:
>
> My previous comment was confusing... Probably I understand why you tried to put this information in checkpoint log message. But I was suggesting to put that information at the end of log message instead of the beginning of it. Because ordinary users would be less interested in this LSN information than other ones like the number of buffers written.

Actually, there's no strong reason to put LSN info at the beginning of
the message except that LSN/REDO LSN next to the
checkpoint/restartpoint complete would make the users understand the
LSN and REDO LSN belong to the checkpoint/restartpoint. Since this
wasn't a strong reason, I agree to keep it at the end.

Modified in v8.

[1]
2022-02-01 04:34:17.657 UTC [3597073] LOG:  checkpoint complete: wrote
21 buffers (0.1%); 0 WAL file(s) added, 0 removed, 0 recycled;
write=0.004 s, sync=0.008 s, total=0.031 s; sync files=18,
longest=0.006 s, average=0.001 s; distance=77 kB, estimate=77 kB;
lsn=0/14D5AF0, redo lsn=0/14D5AB8

Regards,
Bharath Rupireddy.


Attachments:

  [application/octet-stream] v8-0001-Add-checkpoint-and-redo-LSN-to-LogCheckpointEnd-l.patch (2.8K, ../CALj2ACU9ynpCwfuL0a4Bx0SDbHcjRDk49pwjDwfOzoQ1-kx1pw@mail.gmail.com/2-v8-0001-Add-checkpoint-and-redo-LSN-to-LogCheckpointEnd-l.patch)
  download | inline diff:
From adc02d1a4b319e982db0aa6ba96fcacf0b7d94f5 Mon Sep 17 00:00:00 2001
From: Bharath Rupireddy <[email protected]>
Date: Tue, 1 Feb 2022 04:34:54 +0000
Subject: [PATCH v8] Add checkpoint and redo LSN to LogCheckpointEnd log
 message

It is useful (for debugging purposes) if the checkpoint end message
has the checkpoint LSN(end) and REDO LSN(start). It gives more
context while analyzing checkpoint-related issues. The pg_controldata
gives the last checkpoint LSN and REDO LSN, but having this info
alongside the log message helps analyze issues that happened
previously, connect the dots and identify the root cause.
---
 src/backend/access/transam/xlog.c | 14 ++++++++++----
 1 file changed, 10 insertions(+), 4 deletions(-)

diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index dfe2a0bcce..34074b1e6e 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -8923,7 +8923,8 @@ LogCheckpointEnd(bool restartpoint)
 						"%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,
@@ -8936,14 +8937,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,
@@ -8956,7 +8960,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))));
 }
 
 /*
-- 
2.25.1



  [application/octet-stream] v8-0002-Change-location-to-lsn-in-pg_controldata.patch (2.6K, ../CALj2ACU9ynpCwfuL0a4Bx0SDbHcjRDk49pwjDwfOzoQ1-kx1pw@mail.gmail.com/3-v8-0002-Change-location-to-lsn-in-pg_controldata.patch)
  download | inline diff:
From fb235989743e35e973b405af05d4a2962d3a0095 Mon Sep 17 00:00:00 2001
From: Bharath Rupireddy <[email protected]>
Date: Tue, 1 Feb 2022 03:57:04 +0000
Subject: [PATCH v8] Change "location" to "lsn" in pg_controldata

---
 src/bin/pg_controldata/pg_controldata.c    | 10 +++++-----
 src/test/recovery/t/016_min_consistency.pl |  2 +-
 2 files changed, 6 insertions(+), 6 deletions(-)

diff --git a/src/bin/pg_controldata/pg_controldata.c b/src/bin/pg_controldata/pg_controldata.c
index f911f98d94..59f39267df 100644
--- a/src/bin/pg_controldata/pg_controldata.c
+++ b/src/bin/pg_controldata/pg_controldata.c
@@ -235,9 +235,9 @@ main(int argc, char *argv[])
 		   dbState(ControlFile->state));
 	printf(_("pg_control last modified:             %s\n"),
 		   pgctime_str);
-	printf(_("Latest checkpoint location:           %X/%X\n"),
+	printf(_("Latest checkpoint LSN:                %X/%X\n"),
 		   LSN_FORMAT_ARGS(ControlFile->checkPoint));
-	printf(_("Latest checkpoint's REDO location:    %X/%X\n"),
+	printf(_("Latest checkpoint's REDO LSN:         %X/%X\n"),
 		   LSN_FORMAT_ARGS(ControlFile->checkPointCopy.redo));
 	printf(_("Latest checkpoint's REDO WAL file:    %s\n"),
 		   xlogfilename);
@@ -274,13 +274,13 @@ main(int argc, char *argv[])
 		   ckpttime_str);
 	printf(_("Fake LSN counter for unlogged rels:   %X/%X\n"),
 		   LSN_FORMAT_ARGS(ControlFile->unloggedLSN));
-	printf(_("Minimum recovery ending location:     %X/%X\n"),
+	printf(_("Minimum recovery ending LSN:          %X/%X\n"),
 		   LSN_FORMAT_ARGS(ControlFile->minRecoveryPoint));
 	printf(_("Min recovery ending loc's timeline:   %u\n"),
 		   ControlFile->minRecoveryPointTLI);
-	printf(_("Backup start location:                %X/%X\n"),
+	printf(_("Backup start LSN:                     %X/%X\n"),
 		   LSN_FORMAT_ARGS(ControlFile->backupStartPoint));
-	printf(_("Backup end location:                  %X/%X\n"),
+	printf(_("Backup end LSN:                       %X/%X\n"),
 		   LSN_FORMAT_ARGS(ControlFile->backupEndPoint));
 	printf(_("End-of-backup record required:        %s\n"),
 		   ControlFile->backupEndRequired ? _("yes") : _("no"));
diff --git a/src/test/recovery/t/016_min_consistency.pl b/src/test/recovery/t/016_min_consistency.pl
index 86fd6f5546..7ab4d4429d 100644
--- a/src/test/recovery/t/016_min_consistency.pl
+++ b/src/test/recovery/t/016_min_consistency.pl
@@ -126,7 +126,7 @@ my @control_data = split("\n", $stdout);
 my $offline_recovery_lsn = undef;
 foreach (@control_data)
 {
-	if ($_ =~ /^Minimum recovery ending location:\s*(.*)$/mg)
+	if ($_ =~ /^Minimum recovery ending LSN:\s*(.*)$/mg)
 	{
 		$offline_recovery_lsn = $1;
 		last;
-- 
2.25.1



view thread (8+ messages)  latest in thread

reply

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Reply to all the recipients using the --to and --cc options:
  reply via email

  To: [email protected]
  Cc: [email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected]
  Subject: Re: Add checkpoint and redo LSN to LogCheckpointEnd log message
  In-Reply-To: <CALj2ACU9ynpCwfuL0a4Bx0SDbHcjRDk49pwjDwfOzoQ1-kx1pw@mail.gmail.com>

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox