public inbox for [email protected]
help / color / mirror / Atom feedRe: Add checkpoint and redo LSN to LogCheckpointEnd log message
8+ messages / 5 participants
[nested] [flat]
* Re: Add checkpoint and redo LSN to LogCheckpointEnd log message
@ 2022-01-31 18:53 Bharath Rupireddy <[email protected]>
2022-02-01 01:44 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Nathan Bossart <[email protected]>
0 siblings, 1 reply; 8+ messages in thread
From: Bharath Rupireddy @ 2022-01-31 18:53 UTC (permalink / raw)
To: Nathan Bossart <[email protected]>; +Cc: Stephen Frost <[email protected]>; Kyotaro Horiguchi <[email protected]>; Bossart, Nathan <[email protected]>; Julien Rouhaud <[email protected]>; Michael Paquier <[email protected]>; PostgreSQL Hackers <[email protected]>
On Tue, Feb 1, 2022 at 12:00 AM Nathan Bossart <[email protected]> wrote:
>
> On Mon, Jan 31, 2022 at 11:45:19PM +0530, Bharath Rupireddy wrote:
> > Thanks. Here are 2 patches, 0001 for adding checkpoint lsn and redo
> > lsn in the checkpoint completed message and 0002 for changing the
> > "location" to LSN in pg_controdata's output. With the 0002,
> > pg_control_checkpont, pg_controldata and checkpoint completed message
> > will all be in sync with the checkpoint lsn and redo lsn.
>
> I think the pg_controldata change needs some extra spaces for alignment,
> but otherwise these patches seem reasonable to me.
Thanks. My bad it was. Changed in v6.
Regards,
Bharath Rupireddy.
Attachments:
[application/octet-stream] v6-0001-Add-checkpoint-and-redo-LSN-to-LogCheckpointEnd-l.patch (2.4K, ../../CALj2ACUaUJGvwYi4ztcc6-o2ju48BcNvayB0OuDt0-1gYHmHRw@mail.gmail.com/2-v6-0001-Add-checkpoint-and-redo-LSN-to-LogCheckpointEnd-l.patch)
download | inline diff:
From beafea457cd80266c6e517862ed819da7b3c8ec0 Mon Sep 17 00:00:00 2001
From: Bharath Rupireddy <[email protected]>
Date: Mon, 31 Jan 2022 16:51:47 +0000
Subject: [PATCH v6] 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 | 10 ++++++++--
1 file changed, 8 insertions(+), 2 deletions(-)
diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index dfe2a0bcce..71a5239619 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -8919,11 +8919,14 @@ LogCheckpointEnd(bool restartpoint)
if (restartpoint)
ereport(LOG,
- (errmsg("restartpoint complete: wrote %d buffers (%.1f%%); "
+ (errmsg("restartpoint complete: lsn=%X/%X, redo lsn=%X/%X; "
+ "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",
+ LSN_FORMAT_ARGS(ControlFile->checkPointCopy.redo),
+ LSN_FORMAT_ARGS(ControlFile->checkPoint),
CheckpointStats.ckpt_bufs_written,
(double) CheckpointStats.ckpt_bufs_written * 100 / NBuffers,
CheckpointStats.ckpt_segs_added,
@@ -8939,11 +8942,14 @@ LogCheckpointEnd(bool restartpoint)
(int) (CheckPointDistanceEstimate / 1024.0))));
else
ereport(LOG,
- (errmsg("checkpoint complete: wrote %d buffers (%.1f%%); "
+ (errmsg("checkpoint complete: lsn=%X/%X, redo lsn=%X/%X; "
+ "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",
+ LSN_FORMAT_ARGS(ControlFile->checkPointCopy.redo),
+ LSN_FORMAT_ARGS(ControlFile->checkPoint),
CheckpointStats.ckpt_bufs_written,
(double) CheckpointStats.ckpt_bufs_written * 100 / NBuffers,
CheckpointStats.ckpt_segs_added,
--
2.25.1
[application/octet-stream] v6-0002-change-location-to-lsn-in-pg_controldata.patch (2.6K, ../../CALj2ACUaUJGvwYi4ztcc6-o2ju48BcNvayB0OuDt0-1gYHmHRw@mail.gmail.com/3-v6-0002-change-location-to-lsn-in-pg_controldata.patch)
download | inline diff:
From 716be5dc210ee81016d31cdef6337169afd42823 Mon Sep 17 00:00:00 2001
From: Bharath Rupireddy <[email protected]>
Date: Mon, 31 Jan 2022 18:51:52 +0000
Subject: [PATCH v6] 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
^ permalink raw reply [nested|flat] 8+ messages in thread
* Re: Add checkpoint and redo LSN to LogCheckpointEnd log message
2022-01-31 18:53 Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
@ 2022-02-01 01:44 ` Nathan Bossart <[email protected]>
2022-02-01 03:40 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Fujii Masao <[email protected]>
0 siblings, 1 reply; 8+ messages in thread
From: Nathan Bossart @ 2022-02-01 01:44 UTC (permalink / raw)
To: Bharath Rupireddy <[email protected]>; +Cc: Stephen Frost <[email protected]>; Kyotaro Horiguchi <[email protected]>; Bossart, Nathan <[email protected]>; Julien Rouhaud <[email protected]>; Michael Paquier <[email protected]>; PostgreSQL Hackers <[email protected]>
On Tue, Feb 01, 2022 at 12:23:10AM +0530, Bharath Rupireddy wrote:
> On Tue, Feb 1, 2022 at 12:00 AM Nathan Bossart <[email protected]> wrote:
>> I think the pg_controldata change needs some extra spaces for alignment,
>> but otherwise these patches seem reasonable to me.
>
> Thanks. My bad it was. Changed in v6.
LGTM
--
Nathan Bossart
Amazon Web Services: https://aws.amazon.com
^ permalink raw reply [nested|flat] 8+ messages in thread
* Re: Add checkpoint and redo LSN to LogCheckpointEnd log message
2022-01-31 18:53 Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
2022-02-01 01:44 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Nathan Bossart <[email protected]>
@ 2022-02-01 03:40 ` Fujii Masao <[email protected]>
2022-02-01 04:01 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
0 siblings, 1 reply; 8+ messages in thread
From: Fujii Masao @ 2022-02-01 03:40 UTC (permalink / raw)
To: Nathan Bossart <[email protected]>; Bharath Rupireddy <[email protected]>; +Cc: Stephen Frost <[email protected]>; Kyotaro Horiguchi <[email protected]>; Bossart, Nathan <[email protected]>; Julien Rouhaud <[email protected]>; Michael Paquier <[email protected]>; PostgreSQL Hackers <[email protected]>
On 2022/02/01 10:44, Nathan Bossart wrote:
> On Tue, Feb 01, 2022 at 12:23:10AM +0530, Bharath Rupireddy wrote:
>> On Tue, Feb 1, 2022 at 12:00 AM Nathan Bossart <[email protected]> wrote:
>>> I think the pg_controldata change needs some extra spaces for alignment,
>>> but otherwise these patches seem reasonable to me.
>>
>> Thanks. My bad it was. Changed in v6.
- (errmsg("restartpoint complete: wrote %d buffers (%.1f%%); "
+ (errmsg("restartpoint complete: lsn=%X/%X, redo lsn=%X/%X; "
+ "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",
+ LSN_FORMAT_ARGS(ControlFile->checkPointCopy.redo),
+ LSN_FORMAT_ARGS(ControlFile->checkPoint),
The order of arguments for LSN seems wrong. LSN_FORMAT_ARGS(ControlFile->checkPoint) should be specified ahead of LSN_FORMAT_ARGS(ControlFile->checkPointCopy.redo)?
Could you tell me why the information for LSN is reported earlierly in the log message? Since ordinally users would be more interested in the information about I/O by checkpoint, the information for LSN should be placed later? Sorry if this was already discussed.
Regards,
--
Fujii Masao
Advanced Computing Technology Center
Research and Development Headquarters
NTT DATA CORPORATION
^ permalink raw reply [nested|flat] 8+ messages in thread
* Re: Add checkpoint and redo LSN to LogCheckpointEnd log message
2022-01-31 18:53 Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
2022-02-01 01:44 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Nathan Bossart <[email protected]>
2022-02-01 03:40 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Fujii Masao <[email protected]>
@ 2022-02-01 04:01 ` Bharath Rupireddy <[email protected]>
2022-02-01 04:19 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Fujii Masao <[email protected]>
0 siblings, 1 reply; 8+ messages in thread
From: Bharath Rupireddy @ 2022-02-01 04:01 UTC (permalink / raw)
To: Fujii Masao <[email protected]>; +Cc: Nathan Bossart <[email protected]>; Stephen Frost <[email protected]>; Kyotaro Horiguchi <[email protected]>; Bossart, Nathan <[email protected]>; Julien Rouhaud <[email protected]>; Michael Paquier <[email protected]>; PostgreSQL Hackers <[email protected]>
On Tue, Feb 1, 2022 at 9:10 AM Fujii Masao <[email protected]> wrote:
> The order of arguments for LSN seems wrong. LSN_FORMAT_ARGS(ControlFile->checkPoint) should be specified ahead of LSN_FORMAT_ARGS(ControlFile->checkPointCopy.redo)?
Thanks. Corrected.
> Could you tell me why the information for LSN is reported earlierly in the log message? Since ordinally users would be more interested in the information about I/O by checkpoint, the information for LSN should be placed later? Sorry if this was already discussed.
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.
Regards,
Bharath Rupireddy.
Attachments:
[application/octet-stream] v7-0001-Add-checkpoint-and-redo-LSN-to-LogCheckpointEnd-l.patch (2.4K, ../../CALj2ACXDHGfhKkwzi81BRqWft4n85AO1zmkeqf6xEg+0xTCH9g@mail.gmail.com/2-v7-0001-Add-checkpoint-and-redo-LSN-to-LogCheckpointEnd-l.patch)
download | inline diff:
From e92bc19482580bee30dff5044d0ee4b27d3a90eb Mon Sep 17 00:00:00 2001
From: Bharath Rupireddy <[email protected]>
Date: Tue, 1 Feb 2022 03:56:11 +0000
Subject: [PATCH v7] 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 | 10 ++++++++--
1 file changed, 8 insertions(+), 2 deletions(-)
diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index dfe2a0bcce..65d7afae5e 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -8919,11 +8919,14 @@ LogCheckpointEnd(bool restartpoint)
if (restartpoint)
ereport(LOG,
- (errmsg("restartpoint complete: wrote %d buffers (%.1f%%); "
+ (errmsg("restartpoint complete: lsn=%X/%X, redo lsn=%X/%X; "
+ "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",
+ LSN_FORMAT_ARGS(ControlFile->checkPoint),
+ LSN_FORMAT_ARGS(ControlFile->checkPointCopy.redo),
CheckpointStats.ckpt_bufs_written,
(double) CheckpointStats.ckpt_bufs_written * 100 / NBuffers,
CheckpointStats.ckpt_segs_added,
@@ -8939,11 +8942,14 @@ LogCheckpointEnd(bool restartpoint)
(int) (CheckPointDistanceEstimate / 1024.0))));
else
ereport(LOG,
- (errmsg("checkpoint complete: wrote %d buffers (%.1f%%); "
+ (errmsg("checkpoint complete: lsn=%X/%X, redo lsn=%X/%X; "
+ "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",
+ LSN_FORMAT_ARGS(ControlFile->checkPoint),
+ LSN_FORMAT_ARGS(ControlFile->checkPointCopy.redo),
CheckpointStats.ckpt_bufs_written,
(double) CheckpointStats.ckpt_bufs_written * 100 / NBuffers,
CheckpointStats.ckpt_segs_added,
--
2.25.1
[application/octet-stream] v7-0002-Change-location-to-lsn-in-pg_controldata.patch (2.6K, ../../CALj2ACXDHGfhKkwzi81BRqWft4n85AO1zmkeqf6xEg+0xTCH9g@mail.gmail.com/3-v7-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 v7] 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
^ permalink raw reply [nested|flat] 8+ messages in thread
* Re: Add checkpoint and redo LSN to LogCheckpointEnd log message
2022-01-31 18:53 Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
2022-02-01 01:44 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Nathan Bossart <[email protected]>
2022-02-01 03:40 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Fujii Masao <[email protected]>
2022-02-01 04:01 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
@ 2022-02-01 04:19 ` Fujii Masao <[email protected]>
2022-02-01 04:38 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
0 siblings, 1 reply; 8+ messages in thread
From: Fujii Masao @ 2022-02-01 04:19 UTC (permalink / raw)
To: Bharath Rupireddy <[email protected]>; +Cc: Nathan Bossart <[email protected]>; Stephen Frost <[email protected]>; Kyotaro Horiguchi <[email protected]>; Bossart, Nathan <[email protected]>; Julien Rouhaud <[email protected]>; Michael Paquier <[email protected]>; PostgreSQL Hackers <[email protected]>
On 2022/02/01 13:01, Bharath Rupireddy wrote:
> On Tue, Feb 1, 2022 at 9:10 AM Fujii Masao <[email protected]> wrote:
>> The order of arguments for LSN seems wrong. LSN_FORMAT_ARGS(ControlFile->checkPoint) should be specified ahead of LSN_FORMAT_ARGS(ControlFile->checkPointCopy.redo)?
>
> Thanks. Corrected.
Thanks!
>> Could you tell me why the information for LSN is reported earlierly in the log message? Since ordinally users would be more interested in the information about I/O by checkpoint, the information for LSN should be placed later? Sorry if this was already discussed.
>
> 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.
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.
Regards,
--
Fujii Masao
Advanced Computing Technology Center
Research and Development Headquarters
NTT DATA CORPORATION
^ permalink raw reply [nested|flat] 8+ messages in thread
* Re: Add checkpoint and redo LSN to LogCheckpointEnd log message
2022-01-31 18:53 Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
2022-02-01 01:44 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Nathan Bossart <[email protected]>
2022-02-01 03:40 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Fujii Masao <[email protected]>
2022-02-01 04:01 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
2022-02-01 04:19 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Fujii Masao <[email protected]>
@ 2022-02-01 04:38 ` Bharath Rupireddy <[email protected]>
2022-02-01 06:27 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Kyotaro Horiguchi <[email protected]>
0 siblings, 1 reply; 8+ messages in thread
From: Bharath Rupireddy @ 2022-02-01 04:38 UTC (permalink / raw)
To: Fujii Masao <[email protected]>; +Cc: Nathan Bossart <[email protected]>; Stephen Frost <[email protected]>; Kyotaro Horiguchi <[email protected]>; Bossart, Nathan <[email protected]>; Julien Rouhaud <[email protected]>; Michael Paquier <[email protected]>; PostgreSQL Hackers <[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
^ permalink raw reply [nested|flat] 8+ messages in thread
* Re: Add checkpoint and redo LSN to LogCheckpointEnd log message
2022-01-31 18:53 Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
2022-02-01 01:44 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Nathan Bossart <[email protected]>
2022-02-01 03:40 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Fujii Masao <[email protected]>
2022-02-01 04:01 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
2022-02-01 04:19 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Fujii Masao <[email protected]>
2022-02-01 04:38 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
@ 2022-02-01 06:27 ` Kyotaro Horiguchi <[email protected]>
0 siblings, 0 replies; 8+ messages in thread
From: Kyotaro Horiguchi @ 2022-02-01 06:27 UTC (permalink / raw)
To: [email protected]; +Cc: [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]
At Tue, 1 Feb 2022 10:08:04 +0530, Bharath Rupireddy <[email protected]> wrote in
> 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
0001 looks good to me.
I tend to agree to 0002.
FWIW, I collected other user-facing usage of "location" as LSN.
xlog.c:5965, 6128:
(errmsg("recovery stopping before WAL location (LSN) \"%X/%X\"",
xlog.c:6718:
(errmsg("control file contains invalid checkpoint location")));
xlog.c:6846:
(errmsg("starting point-in-time recovery to WAL location (LSN) \"%X/%X\"",
xlog.c:6929:
(errmsg("could not find redo location referenced by checkpoint record"),
xlog.c:11298, 11300: (in backup-label)
appendStringInfo(labelfile, "START WAL LOCATION: %X/%X (file %s)\n",
appendStringInfo(labelfile, "CHECKPOINT LOCATION: %X/%X\n",
(and corresponding reader-code)
xlog,c:11791, 11793: (in backup history file)
fprintf(fp, "START WAL LOCATION: %X/%X (file %s)\n",
fprintf(fp, "STOP WAL LOCATION: %X/%X (file %s)\n",
(and corresponding reader-code)
repl_scanner.l:151:
yyerror("invalid streaming start location");
pg_proc.dat:
many function descriptions use "location" as LSN.
pg_waldump.c:768,777,886,938,1029,1071,1083:
printf(_(" -e, --end=RECPTR stop reading at WAL location RECPTR\n"));
printf(_(" -s, --start=RECPTR start reading at WAL location RECPTR\n"));
pg_log_error("could not parse end WAL location \"%s\"",
pg_log_error("could not parse start WAL location \"%s\"",
pg_log_error("start WAL location %X/%X is not inside file \"%s\"",
pg_log_error("end WAL location %X/%X is not inside file \"%s\"",
pg_log_error("no start WAL location given");
pg_basebackup.c:476, 615: (confusing with file/directory path..)
pg_log_error("could not parse write-ahead log location \"%s\"",
pg_log_error("could not parse write-ahead log location \"%s\"",
pg_rewind.c:346:
pg_log_info("servers diverged at WAL location %X/%X on timeline %u",
pg_rewind/timeline.c:82:
pg_log_error("Expected a write-ahead log switchpoint location.");
regards.
--
Kyotaro Horiguchi
NTT Open Source Software Center
^ permalink raw reply [nested|flat] 8+ messages in thread
* [PATCH v4 2/4] make binaryheap available to frontend
@ 2023-07-22 22:04 Nathan Bossart <[email protected]>
0 siblings, 0 replies; 8+ messages in thread
From: Nathan Bossart @ 2023-07-22 22:04 UTC (permalink / raw)
---
src/backend/lib/Makefile | 1 -
src/backend/lib/meson.build | 1 -
src/common/Makefile | 1 +
src/{backend/lib => common}/binaryheap.c | 17 ++++++++++++++++-
src/common/meson.build | 1 +
5 files changed, 18 insertions(+), 3 deletions(-)
rename src/{backend/lib => common}/binaryheap.c (96%)
diff --git a/src/backend/lib/Makefile b/src/backend/lib/Makefile
index 9dad31398a..b6cefd9cca 100644
--- a/src/backend/lib/Makefile
+++ b/src/backend/lib/Makefile
@@ -13,7 +13,6 @@ top_builddir = ../../..
include $(top_builddir)/src/Makefile.global
OBJS = \
- binaryheap.o \
bipartite_match.o \
bloomfilter.o \
dshash.o \
diff --git a/src/backend/lib/meson.build b/src/backend/lib/meson.build
index 974cab8776..b4e88f54ae 100644
--- a/src/backend/lib/meson.build
+++ b/src/backend/lib/meson.build
@@ -1,7 +1,6 @@
# Copyright (c) 2022-2023, PostgreSQL Global Development Group
backend_sources += files(
- 'binaryheap.c',
'bipartite_match.c',
'bloomfilter.c',
'dshash.c',
diff --git a/src/common/Makefile b/src/common/Makefile
index 113029bf7b..cc5c54dcee 100644
--- a/src/common/Makefile
+++ b/src/common/Makefile
@@ -48,6 +48,7 @@ LIBS += $(PTHREAD_LIBS)
OBJS_COMMON = \
archive.o \
base64.o \
+ binaryheap.o \
checksum_helper.o \
compression.o \
config_info.o \
diff --git a/src/backend/lib/binaryheap.c b/src/common/binaryheap.c
similarity index 96%
rename from src/backend/lib/binaryheap.c
rename to src/common/binaryheap.c
index c7fcfc550b..400a730c85 100644
--- a/src/backend/lib/binaryheap.c
+++ b/src/common/binaryheap.c
@@ -6,15 +6,22 @@
* Portions Copyright (c) 2012-2023, PostgreSQL Global Development Group
*
* IDENTIFICATION
- * src/backend/lib/binaryheap.c
+ * src/common/binaryheap.c
*
*-------------------------------------------------------------------------
*/
+#ifdef FRONTEND
+#include "postgres_fe.h"
+#else
#include "postgres.h"
+#endif
#include <math.h>
+#ifdef FRONTEND
+#include "common/logging.h"
+#endif
#include "lib/binaryheap.h"
static void sift_down(binaryheap *heap, int node_off);
@@ -109,7 +116,11 @@ void
binaryheap_add_unordered(binaryheap *heap, void *d)
{
if (heap->bh_size >= heap->bh_space)
+#ifdef FRONTEND
+ pg_fatal("out of binary heap slots");
+#else
elog(ERROR, "out of binary heap slots");
+#endif
heap->bh_has_heap_property = false;
heap->bh_nodes[heap->bh_size] = d;
heap->bh_size++;
@@ -141,7 +152,11 @@ void
binaryheap_add(binaryheap *heap, void *d)
{
if (heap->bh_size >= heap->bh_space)
+#ifdef FRONTEND
+ pg_fatal("out of binary heap slots");
+#else
elog(ERROR, "out of binary heap slots");
+#endif
heap->bh_nodes[heap->bh_size] = d;
heap->bh_size++;
sift_up(heap, heap->bh_size - 1);
diff --git a/src/common/meson.build b/src/common/meson.build
index 53942a9a61..3b97497d1a 100644
--- a/src/common/meson.build
+++ b/src/common/meson.build
@@ -3,6 +3,7 @@
common_sources = files(
'archive.c',
'base64.c',
+ 'binaryheap.c',
'checksum_helper.c',
'compression.c',
'controldata_utils.c',
--
2.25.1
--qMm9M+Fa2AknHoGS
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
filename="v4-0003-expand-binaryheap-api.patch"
^ permalink raw reply [nested|flat] 8+ messages in thread
end of thread, other threads:[~2023-07-22 22:04 UTC | newest]
Thread overview: 8+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2022-01-31 18:53 Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
2022-02-01 01:44 ` Nathan Bossart <[email protected]>
2022-02-01 03:40 ` Fujii Masao <[email protected]>
2022-02-01 04:01 ` Bharath Rupireddy <[email protected]>
2022-02-01 04:19 ` Fujii Masao <[email protected]>
2022-02-01 04:38 ` Bharath Rupireddy <[email protected]>
2022-02-01 06:27 ` Kyotaro Horiguchi <[email protected]>
2023-07-22 22:04 [PATCH v4 2/4] make binaryheap available to frontend Nathan Bossart <[email protected]>
This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox