public inbox for [email protected]
help / color / mirror / Atom feed[PATCH] Fix handling of ? option
17+ messages / 6 participants
[nested] [flat]
* [PATCH] Fix handling of ? option
@ 2019-08-25 18:45 Quentin Rameau <[email protected]>
0 siblings, 0 replies; 17+ messages in thread
From: Quentin Rameau @ 2019-08-25 18:45 UTC (permalink / raw)
Using optind to check back the original given option this way is bogus
and could lead to dereferencing argv out of bounds with a missing
argument to an option.
The proper way to verify if an error has occured is to check if optopt
has been set.
---
src/bin/psql/startup.c | 3 ++-
1 file changed, 2 insertions(+), 1 deletion(-)
diff --git a/src/bin/psql/startup.c b/src/bin/psql/startup.c
index 4730c73396..333b49985a 100644
--- a/src/bin/psql/startup.c
+++ b/src/bin/psql/startup.c
@@ -507,6 +507,7 @@ parse_psql_options(int argc, char *argv[], struct adhoc_opts *options)
int c;
memset(options, 0, sizeof *options);
+ optopt = 0;
while ((c = getopt_long(argc, argv, "aAbc:d:eEf:F:h:HlL:no:p:P:qR:sStT:U:v:VwWxXz?01",
long_options, &optindex)) != -1)
@@ -667,7 +668,7 @@ parse_psql_options(int argc, char *argv[], struct adhoc_opts *options)
break;
case '?':
/* Actual help option given */
- if (strcmp(argv[optind - 1], "-?") == 0)
+ if (!optopt)
{
usage(NOPAGER);
exit(EXIT_SUCCESS);
--
2.23.0
--MP_/oEcYY8373P4jignUOgMh8T.--
^ permalink raw reply [nested|flat] 17+ messages in thread
* [PATCH] Fix handling of ? option
@ 2019-08-25 18:45 Quentin Rameau <[email protected]>
0 siblings, 0 replies; 17+ messages in thread
From: Quentin Rameau @ 2019-08-25 18:45 UTC (permalink / raw)
Using optind to check back the original given option this way is bogus
and could lead to dereferencing argv out of bounds with a missing
argument to an option.
The proper way to verify if an error has occured is to check if optopt
has been set.
---
src/bin/psql/startup.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/src/bin/psql/startup.c b/src/bin/psql/startup.c
index 4730c73396..e5f6894177 100644
--- a/src/bin/psql/startup.c
+++ b/src/bin/psql/startup.c
@@ -667,7 +667,7 @@ parse_psql_options(int argc, char *argv[], struct adhoc_opts *options)
break;
case '?':
/* Actual help option given */
- if (strcmp(argv[optind - 1], "-?") == 0)
+ if (!optopt)
{
usage(NOPAGER);
exit(EXIT_SUCCESS);
--
2.23.0
--MP_/_eGHSN7B9ucS1dXH.MiKkUY--
^ permalink raw reply [nested|flat] 17+ messages in thread
* Add checkpoint and redo LSN to LogCheckpointEnd log message
@ 2021-12-23 15:05 Bharath Rupireddy <[email protected]>
2021-12-24 05:51 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Kyotaro Horiguchi <[email protected]>
0 siblings, 1 reply; 17+ messages in thread
From: Bharath Rupireddy @ 2021-12-23 15:05 UTC (permalink / raw)
To: PostgreSQL Hackers <[email protected]>
Hi,
It is useful (for debugging purposes) if the checkpoint end message
has the checkpoint LSN and REDO LSN [1]. 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.
Attaching a small patch herewith. Thoughts?
[1]
2021-12-23 14:58:54.694 UTC [1965649] LOG: checkpoint starting:
shutdown immediate
2021-12-23 14:58:54.714 UTC [1965649] LOG: checkpoint complete: wrote
0 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled;
write=0.001 s, sync=0.001 s, total=0.025 s; sync files=0,
longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB;
LSN=0/14D0AD0, REDO LSN=0/14D0AD0
Regards,
Bharath Rupireddy.
Attachments:
[application/octet-stream] v1-0001-Add-checkpoint-and-redo-LSN-to-LogCheckpointEnd-l.patch (2.8K, ../../CALj2ACWt6kqriAHrO+AJj+OmP=suwbktHT5JoYAn-nqZe2gd2g@mail.gmail.com/2-v1-0001-Add-checkpoint-and-redo-LSN-to-LogCheckpointEnd-l.patch)
download | inline diff:
From a641d82e8eb4fa9582a0f83a6f8da5ff468d1710 Mon Sep 17 00:00:00 2001
From: Bharath Rupireddy <[email protected]>
Date: Thu, 23 Dec 2021 15:03:30 +0000
Subject: [PATCH v1] Add checkpoint and redo LSN to LogCheckpointEnd log
message
It is useful (for debugging purposes) if the checkpoint end message
has the checkpoint LSN and REDO LSN. 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 1e1fbe957f..9816f7d328 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -8924,7 +8924,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,
@@ -8937,14 +8938,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,
@@ -8957,7 +8961,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
^ permalink raw reply [nested|flat] 17+ messages in thread
* Re: Add checkpoint and redo LSN to LogCheckpointEnd log message
2021-12-23 15:05 Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
@ 2021-12-24 05:51 ` Kyotaro Horiguchi <[email protected]>
2021-12-24 12:07 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
2021-12-24 12:11 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Michael Paquier <[email protected]>
0 siblings, 2 replies; 17+ messages in thread
From: Kyotaro Horiguchi @ 2021-12-24 05:51 UTC (permalink / raw)
To: [email protected]; +Cc: [email protected]
At Thu, 23 Dec 2021 20:35:54 +0530, Bharath Rupireddy <[email protected]> wrote in
> Hi,
>
> It is useful (for debugging purposes) if the checkpoint end message
> has the checkpoint LSN and REDO LSN [1]. 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.
>
> Attaching a small patch herewith. Thoughts?
A big +1 from me. I thought about proposing the same in the past.
> [1]
> 2021-12-23 14:58:54.694 UTC [1965649] LOG: checkpoint starting:
> shutdown immediate
> 2021-12-23 14:58:54.714 UTC [1965649] LOG: checkpoint complete: wrote
> 0 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled;
> write=0.001 s, sync=0.001 s, total=0.025 s; sync files=0,
> longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB;
> LSN=0/14D0AD0, REDO LSN=0/14D0AD0
I thougt about something like the following, but your proposal may be
clearer.
> WAL range=[0/14D0340, 0/14D0AD0]
regards.
--
Kyotaro Horiguchi
NTT Open Source Software Center
^ permalink raw reply [nested|flat] 17+ messages in thread
* Re: Add checkpoint and redo LSN to LogCheckpointEnd log message
2021-12-23 15:05 Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
2021-12-24 05:51 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Kyotaro Horiguchi <[email protected]>
@ 2021-12-24 12:07 ` Bharath Rupireddy <[email protected]>
1 sibling, 0 replies; 17+ messages in thread
From: Bharath Rupireddy @ 2021-12-24 12:07 UTC (permalink / raw)
To: Kyotaro Horiguchi <[email protected]>; +Cc: PostgreSQL Hackers <[email protected]>
On Fri, Dec 24, 2021 at 11:21 AM Kyotaro Horiguchi
<[email protected]> wrote:
>
> At Thu, 23 Dec 2021 20:35:54 +0530, Bharath Rupireddy <[email protected]> wrote in
> > Hi,
> >
> > It is useful (for debugging purposes) if the checkpoint end message
> > has the checkpoint LSN and REDO LSN [1]. 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.
> >
> > Attaching a small patch herewith. Thoughts?
>
> A big +1 from me. I thought about proposing the same in the past.
Thanks for the review. I've added a CF entry to not lose track -
https://commitfest.postgresql.org/36/3474/.
> > [1]
> > 2021-12-23 14:58:54.694 UTC [1965649] LOG: checkpoint starting:
> > shutdown immediate
> > 2021-12-23 14:58:54.714 UTC [1965649] LOG: checkpoint complete: wrote
> > 0 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled;
> > write=0.001 s, sync=0.001 s, total=0.025 s; sync files=0,
> > longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB;
> > LSN=0/14D0AD0, REDO LSN=0/14D0AD0
>
> I thougt about something like the following, but your proposal may be
> clearer.
>
> > WAL range=[0/14D0340, 0/14D0AD0]
Yeah the proposed in the v1 is clear saying checkpoint/restartpoint
LSN and REDO LSN.
Regards,
Bharath Rupireddy.
^ permalink raw reply [nested|flat] 17+ messages in thread
* Re: Add checkpoint and redo LSN to LogCheckpointEnd log message
2021-12-23 15:05 Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
2021-12-24 05:51 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Kyotaro Horiguchi <[email protected]>
@ 2021-12-24 12:11 ` Michael Paquier <[email protected]>
2021-12-24 12:24 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
1 sibling, 1 reply; 17+ messages in thread
From: Michael Paquier @ 2021-12-24 12:11 UTC (permalink / raw)
To: Kyotaro Horiguchi <[email protected]>; +Cc: [email protected]; [email protected]
On Fri, Dec 24, 2021 at 02:51:34PM +0900, Kyotaro Horiguchi wrote:
> I thougt about something like the following, but your proposal may be
> clearer.
+ "LSN=%X/%X, REDO LSN=%X/%X",
This could be rather confusing for the average user, even if I agree
that this is some information that only an advanced user could
understand. Could it be possible to define those fields in a more
deterministic way? For one, it is hard to understand the relationship
between both fields without looking at the code, particulary if both
share the same value. It is at least rather.. Well, mostly, easy to
guess what each other field means in this context, which is not the
case of what you are proposing here. One idea could be use also
"start point" for REDO, for example.
--
Michael
Attachments:
[application/pgp-signature] signature.asc (833B, ../../[email protected]/2-signature.asc)
download
^ permalink raw reply [nested|flat] 17+ messages in thread
* Re: Add checkpoint and redo LSN to LogCheckpointEnd log message
2021-12-23 15:05 Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
2021-12-24 05:51 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Kyotaro Horiguchi <[email protected]>
2021-12-24 12:11 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Michael Paquier <[email protected]>
@ 2021-12-24 12:24 ` Bharath Rupireddy <[email protected]>
2021-12-28 02:56 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
0 siblings, 1 reply; 17+ messages in thread
From: Bharath Rupireddy @ 2021-12-24 12:24 UTC (permalink / raw)
To: Michael Paquier <[email protected]>; +Cc: Kyotaro Horiguchi <[email protected]>; PostgreSQL Hackers <[email protected]>
On Fri, Dec 24, 2021 at 5:42 PM Michael Paquier <[email protected]> wrote:
>
> On Fri, Dec 24, 2021 at 02:51:34PM +0900, Kyotaro Horiguchi wrote:
> > I thougt about something like the following, but your proposal may be
> > clearer.
>
> + "LSN=%X/%X, REDO LSN=%X/%X",
> This could be rather confusing for the average user, even if I agree
> that this is some information that only an advanced user could
> understand. Could it be possible to define those fields in a more
> deterministic way? For one, it is hard to understand the relationship
> between both fields without looking at the code, particulary if both
> share the same value. It is at least rather.. Well, mostly, easy to
> guess what each other field means in this context, which is not the
> case of what you are proposing here. One idea could be use also
> "start point" for REDO, for example.
How about "location=%X/%X, REDO start location=%X/%X"? The entire log
message can look like below:
2021-12-24 12:20:19.140 UTC [1977834] LOG: checkpoint
complete:location=%X/%X, REDO start location=%X/%X; wrote 7 buffers
(0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.005 s,
sync=0.007 s, total=0.192 s; sync files=5, longest=0.005 s,
average=0.002 s; distance=293 kB, estimate=56584 kB
Another variant:
2021-12-24 12:20:19.140 UTC [1977834] LOG: checkpoint completed at
location=%X/%X with REDO start location=%X/%X: wrote 7 buffers (0.0%);
0 WAL file(s) added, 0 removed, 0 recycled; write=0.005 s, sync=0.007
s, total=0.192 s; sync files=5, longest=0.005 s, average=0.002 s;
distance=293 kB, estimate=56584 kB
2021-12-24 12:20:19.140 UTC [1977834] LOG: restartpoint completed at
location=%X/%X with REDO start location=%X/%X: wrote 7 buffers (0.0%);
0 WAL file(s) added, 0 removed, 0 recycled; write=0.005 s, sync=0.007
s, total=0.192 s; sync files=5, longest=0.005 s, average=0.002 s;
distance=293 kB, estimate=56584 kB
Thoughts?
Regards,
Bharath Rupireddy.
^ permalink raw reply [nested|flat] 17+ messages in thread
* Re: Add checkpoint and redo LSN to LogCheckpointEnd log message
2021-12-23 15:05 Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
2021-12-24 05:51 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Kyotaro Horiguchi <[email protected]>
2021-12-24 12:11 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Michael Paquier <[email protected]>
2021-12-24 12:24 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
@ 2021-12-28 02:56 ` Bharath Rupireddy <[email protected]>
0 siblings, 0 replies; 17+ messages in thread
From: Bharath Rupireddy @ 2021-12-28 02:56 UTC (permalink / raw)
To: Michael Paquier <[email protected]>; +Cc: Kyotaro Horiguchi <[email protected]>; PostgreSQL Hackers <[email protected]>
On Fri, Dec 24, 2021 at 5:54 PM Bharath Rupireddy
<[email protected]> wrote:
>
> On Fri, Dec 24, 2021 at 5:42 PM Michael Paquier <[email protected]> wrote:
> >
> > On Fri, Dec 24, 2021 at 02:51:34PM +0900, Kyotaro Horiguchi wrote:
> > > I thougt about something like the following, but your proposal may be
> > > clearer.
> >
> > + "LSN=%X/%X, REDO LSN=%X/%X",
> > This could be rather confusing for the average user, even if I agree
> > that this is some information that only an advanced user could
> > understand. Could it be possible to define those fields in a more
> > deterministic way? For one, it is hard to understand the relationship
> > between both fields without looking at the code, particulary if both
> > share the same value. It is at least rather.. Well, mostly, easy to
> > guess what each other field means in this context, which is not the
> > case of what you are proposing here. One idea could be use also
> > "start point" for REDO, for example.
>
> How about "location=%X/%X, REDO start location=%X/%X"? The entire log
> message can look like below:
>
> 2021-12-24 12:20:19.140 UTC [1977834] LOG: checkpoint
> complete:location=%X/%X, REDO start location=%X/%X; wrote 7 buffers
> (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.005 s,
> sync=0.007 s, total=0.192 s; sync files=5, longest=0.005 s,
> average=0.002 s; distance=293 kB, estimate=56584 kB
>
> Another variant:
> 2021-12-24 12:20:19.140 UTC [1977834] LOG: checkpoint completed at
> location=%X/%X with REDO start location=%X/%X: wrote 7 buffers (0.0%);
> 0 WAL file(s) added, 0 removed, 0 recycled; write=0.005 s, sync=0.007
> s, total=0.192 s; sync files=5, longest=0.005 s, average=0.002 s;
> distance=293 kB, estimate=56584 kB
> 2021-12-24 12:20:19.140 UTC [1977834] LOG: restartpoint completed at
> location=%X/%X with REDO start location=%X/%X: wrote 7 buffers (0.0%);
> 0 WAL file(s) added, 0 removed, 0 recycled; write=0.005 s, sync=0.007
> s, total=0.192 s; sync files=5, longest=0.005 s, average=0.002 s;
> distance=293 kB, estimate=56584 kB
Here are the 2 patches.
one(v2-1-XXX.patch) adding the info as:
2021-12-28 02:44:34.870 UTC [2384386] LOG: checkpoint complete:
location=0/1B03040, REDO start location=0/1B03008; wrote 466 buffers
(2.8%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.014 s,
sync=0.038 s, total=0.072 s; sync files=21, longest=0.022 s,
average=0.002 s; distance=6346 kB, estimate=6346 kB
another(v2-2-XXX.patch) adding the info as:
2021-12-28 02:52:24.464 UTC [2394396] LOG: checkpoint completed at
location=0/212FFC8 with REDO start location=0/212FF90: wrote 451
buffers (2.8%); 0 WAL file(s) added, 0 removed, 1 recycled;
write=0.012 s, sync=0.032 s, total=0.071 s; sync files=6,
longest=0.022 s, average=0.006 s; distance=6272 kB, estimate=6272 kB
attaching v1-0001-XXX from the initial mail again just for the sake of
completion:
2021-12-23 14:58:54.714 UTC [1965649] LOG: checkpoint complete: wrote
0 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled;
write=0.001 s, sync=0.001 s, total=0.025 s; sync files=0,
longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB;
LSN=0/14D0AD0, REDO LSN=0/14D0AD0
Thoughts?
Regards,
Bharath Rupireddy.
Attachments:
[application/octet-stream] v2-1-Add-checkpoint-and-redo-LSN-to-LogCheckpointEnd-l.patch (2.5K, ../../CALj2ACUP84UYSimewLSs8--rT9dUTA7CUYTgXTnEb-2iHkc9wA@mail.gmail.com/2-v2-1-Add-checkpoint-and-redo-LSN-to-LogCheckpointEnd-l.patch)
download | inline diff:
From 999cfd53ce4e16ccfff94c0022cd80fe8ff84be5 Mon Sep 17 00:00:00 2001
From: Bharath Rupireddy <[email protected]>
Date: Tue, 28 Dec 2021 02:45:51 +0000
Subject: [PATCH v2] Add checkpoint and redo LSN to LogCheckpointEnd log
message
It is useful (for debugging purposes) if the checkpoint end message
has the checkpoint LSN and REDO LSN. 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 1e1fbe957f..26eb2a22f3 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -8920,11 +8920,14 @@ LogCheckpointEnd(bool restartpoint)
if (restartpoint)
ereport(LOG,
- (errmsg("restartpoint complete: wrote %d buffers (%.1f%%); "
+ (errmsg("restartpoint complete: location=%X/%X, REDO start location=%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,
@@ -8940,11 +8943,14 @@ LogCheckpointEnd(bool restartpoint)
(int) (CheckPointDistanceEstimate / 1024.0))));
else
ereport(LOG,
- (errmsg("checkpoint complete: wrote %d buffers (%.1f%%); "
+ (errmsg("checkpoint complete: location=%X/%X, REDO start location=%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] v2-2-Add-checkpoint-and-redo-LSN-to-LogCheckpointEnd-l.patch (2.5K, ../../CALj2ACUP84UYSimewLSs8--rT9dUTA7CUYTgXTnEb-2iHkc9wA@mail.gmail.com/3-v2-2-Add-checkpoint-and-redo-LSN-to-LogCheckpointEnd-l.patch)
download | inline diff:
From c23010c67a66dd21e318ae4d475ee0d85c5c1d08 Mon Sep 17 00:00:00 2001
From: Bharath Rupireddy <[email protected]>
Date: Tue, 28 Dec 2021 02:52:49 +0000
Subject: [PATCH v2] Add checkpoint and redo LSN to LogCheckpointEnd log
message
It is useful (for debugging purposes) if the checkpoint end message
has the checkpoint LSN and REDO LSN. 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 1e1fbe957f..cd3fce6a2c 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -8920,11 +8920,14 @@ LogCheckpointEnd(bool restartpoint)
if (restartpoint)
ereport(LOG,
- (errmsg("restartpoint complete: wrote %d buffers (%.1f%%); "
+ (errmsg("restartpoint completed at location=%X/%X with REDO start location=%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,
@@ -8940,11 +8943,14 @@ LogCheckpointEnd(bool restartpoint)
(int) (CheckPointDistanceEstimate / 1024.0))));
else
ereport(LOG,
- (errmsg("checkpoint complete: wrote %d buffers (%.1f%%); "
+ (errmsg("checkpoint completed at location=%X/%X with REDO start location=%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] v1-0001-Add-checkpoint-and-redo-LSN-to-LogCheckpointEnd-l.patch (2.8K, ../../CALj2ACUP84UYSimewLSs8--rT9dUTA7CUYTgXTnEb-2iHkc9wA@mail.gmail.com/4-v1-0001-Add-checkpoint-and-redo-LSN-to-LogCheckpointEnd-l.patch)
download | inline diff:
From a641d82e8eb4fa9582a0f83a6f8da5ff468d1710 Mon Sep 17 00:00:00 2001
From: Bharath Rupireddy <[email protected]>
Date: Thu, 23 Dec 2021 15:03:30 +0000
Subject: [PATCH v1] Add checkpoint and redo LSN to LogCheckpointEnd log
message
It is useful (for debugging purposes) if the checkpoint end message
has the checkpoint LSN and REDO LSN. 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 1e1fbe957f..9816f7d328 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -8924,7 +8924,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,
@@ -8937,14 +8938,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,
@@ -8957,7 +8961,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
^ permalink raw reply [nested|flat] 17+ messages in thread
* [PATCH v10 2/5] Add checkpoint and redo LSN to LogCheckpointEnd log message
@ 2022-02-01 04:34 Bharath Rupireddy <[email protected]>
0 siblings, 0 replies; 17+ messages in thread
From: Bharath Rupireddy @ 2022-02-01 04:34 UTC (permalink / raw)
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 | 16 ++++++++++++----
1 file changed, 12 insertions(+), 4 deletions(-)
diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index 8c2882b49f..ba1b96bd1d 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,18 @@ 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),
+ /* we are the only updator of these variables */
+ 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 +8961,10 @@ 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),
+ /* we are the only updator of these variables */
+ LSN_FORMAT_ARGS(ControlFile->checkPoint),
+ LSN_FORMAT_ARGS(ControlFile->checkPointCopy.redo))));
}
/*
--
2.27.0
----Next_Part(Mon_Feb_14_14_52_15_2022_460)--
Content-Type: Text/X-Patch; charset=us-ascii
Content-Transfer-Encoding: 7bit
Content-Disposition: inline;
filename="v10-0003-Change-location-to-lsn-in-pg_controldata.patch"
^ permalink raw reply [nested|flat] 17+ messages in thread
* [PATCH v9 2/4] Add checkpoint and redo LSN to LogCheckpointEnd log message
@ 2022-02-01 04:34 Bharath Rupireddy <[email protected]>
0 siblings, 0 replies; 17+ messages in thread
From: Bharath Rupireddy @ 2022-02-01 04:34 UTC (permalink / raw)
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 | 16 ++++++++++++----
1 file changed, 12 insertions(+), 4 deletions(-)
diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index a6c6e67f80..60da34433b 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,18 @@ 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),
+ /* we are the only updator of these variables */
+ 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 +8961,10 @@ 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),
+ /* we are the only updator of these variables */
+ LSN_FORMAT_ARGS(ControlFile->checkPoint),
+ LSN_FORMAT_ARGS(ControlFile->checkPointCopy.redo))));
}
/*
--
2.27.0
----Next_Part(Wed_Feb__9_11_52_04_2022_007)--
Content-Type: Text/X-Patch; charset=us-ascii
Content-Transfer-Encoding: 7bit
Content-Disposition: inline;
filename="v9-0003-Change-location-to-lsn-in-pg_controldata.patch"
^ permalink raw reply [nested|flat] 17+ messages in thread
* [PATCH v12 2/5] Add checkpoint and redo LSN to LogCheckpointEnd log message
@ 2022-03-04 04:22 Bharath Rupireddy <[email protected]>
0 siblings, 0 replies; 17+ messages in thread
From: Bharath Rupireddy @ 2022-03-04 04:22 UTC (permalink / raw)
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 | 22 ++++++++++++++++++----
1 file changed, 18 insertions(+), 4 deletions(-)
diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index bd962763cc..ce3815ea99 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -6120,7 +6120,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,
@@ -6133,14 +6134,21 @@ 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),
+ /*
+ * ControlFileLock is not required as we are the only
+ * updator of these variables.
+ */
+ 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,
@@ -6153,7 +6161,13 @@ 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),
+ /*
+ * ControlFileLock is not required as we are the only
+ * updator of these variables.
+ */
+ LSN_FORMAT_ARGS(ControlFile->checkPoint),
+ LSN_FORMAT_ARGS(ControlFile->checkPointCopy.redo))));
}
/*
--
2.27.0
----Next_Part(Tue_Mar_15_17_23_40_2022_661)--
Content-Type: Text/X-Patch; charset=us-ascii
Content-Transfer-Encoding: 7bit
Content-Disposition: inline;
filename="v12-0003-Change-location-to-lsn-in-pg_controldata.patch"
^ permalink raw reply [nested|flat] 17+ messages in thread
* [PATCH v13] Add checkpoint and redo LSN to LogCheckpointEnd log message
@ 2022-03-04 04:22 Bharath Rupireddy <[email protected]>
0 siblings, 0 replies; 17+ messages in thread
From: Bharath Rupireddy @ 2022-03-04 04:22 UTC (permalink / raw)
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 | 22 ++++++++++++++++++----
1 file changed, 18 insertions(+), 4 deletions(-)
diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index ed16f279b1..b85c76d8f8 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -6121,7 +6121,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,
@@ -6134,14 +6135,21 @@ 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),
+ /*
+ * ControlFileLock is not required as we are the only
+ * updator of these variables.
+ */
+ 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,
@@ -6154,7 +6162,13 @@ 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),
+ /*
+ * ControlFileLock is not required as we are the only
+ * updator of these variables.
+ */
+ LSN_FORMAT_ARGS(ControlFile->checkPoint),
+ LSN_FORMAT_ARGS(ControlFile->checkPointCopy.redo))));
}
/*
--
2.27.0
----Next_Part(Wed_Mar_16_10_29_47_2022_770)----
^ permalink raw reply [nested|flat] 17+ messages in thread
* [PATCH v11 2/5] Add checkpoint and redo LSN to LogCheckpointEnd log message
@ 2022-03-04 04:22 Bharath Rupireddy <[email protected]>
0 siblings, 0 replies; 17+ messages in thread
From: Bharath Rupireddy @ 2022-03-04 04:22 UTC (permalink / raw)
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 | 16 ++++++++++++----
1 file changed, 12 insertions(+), 4 deletions(-)
diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index 3987aa81de..2e1123fd42 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -6120,7 +6120,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,
@@ -6133,14 +6134,18 @@ 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),
+ /* we are the only updator of these variables */
+ 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,
@@ -6153,7 +6158,10 @@ 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),
+ /* we are the only updator of these variables */
+ LSN_FORMAT_ARGS(ControlFile->checkPoint),
+ LSN_FORMAT_ARGS(ControlFile->checkPointCopy.redo))));
}
/*
--
2.27.0
----Next_Part(Fri_Mar__4_14_10_38_2022_481)--
Content-Type: Text/X-Patch; charset=us-ascii
Content-Transfer-Encoding: 7bit
Content-Disposition: inline;
filename="v11-0003-Change-location-to-lsn-in-pg_controldata.patch"
^ permalink raw reply [nested|flat] 17+ messages in thread
* Re: Add checkpoint and redo LSN to LogCheckpointEnd log message
@ 2022-03-28 19:31 ` Greg Stark <[email protected]>
1 sibling, 0 replies; 17+ messages in thread
From: Greg Stark @ 2022-03-28 19:31 UTC (permalink / raw)
To: Kyotaro Horiguchi <[email protected]>; +Cc: Michael Paquier <[email protected]>; Bharath Rupireddy <[email protected]>; [email protected]; [email protected]; Stephen Frost <[email protected]>; Bossart, Nathan <[email protected]>; Julien Rouhaud <[email protected]>; PostgreSQL Hackers <[email protected]>
This patch is currently showing up with a test failure in the CFBot
however I do *not* believe this is a bug in the patch. I think it's a
bug in that test which is being discussed elsewhere.
It's also a very short and straightforward patch that a committer
could probably make a decision about whether it's a good idea or not
and then apply it quickly if so.
Just to give people a leg up and an idea how short the patch is...
Here's the entire patch:
diff --git a/src/backend/access/transam/xlog.c
b/src/backend/access/transam/xlog.c
index ed16f279b1..b85c76d8f8 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -6121,7 +6121,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,
@@ -6134,14 +6135,21 @@ 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),
+ /*
+ * ControlFileLock is not required as we are the only
+ * updator of these variables.
+ */
+ 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,
@@ -6154,7 +6162,13 @@ 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),
+ /*
+ * ControlFileLock is not required as we are the only
+ * updator of these variables.
+ */
+ LSN_FORMAT_ARGS(ControlFile->checkPoint),
+ LSN_FORMAT_ARGS(ControlFile->checkPointCopy.redo))));
}
/*
--
2.27.0
^ permalink raw reply [nested|flat] 17+ messages in thread
* Re: Add checkpoint and redo LSN to LogCheckpointEnd log message
@ 2022-07-06 16:11 ` Fujii Masao <[email protected]>
2022-07-07 07:26 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Kyotaro Horiguchi <[email protected]>
1 sibling, 1 reply; 17+ messages in thread
From: Fujii Masao @ 2022-07-06 16:11 UTC (permalink / raw)
To: Kyotaro Horiguchi <[email protected]>; [email protected]; +Cc: [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]
On 2022/03/16 10:29, Kyotaro Horiguchi wrote:
> At Wed, 16 Mar 2022 09:19:13 +0900 (JST), Kyotaro Horiguchi <[email protected]> wrote in
>> In short, I split out the two topics other than checkpoint log to
>> other threads.
>
> So, this is about the main topic of this thread, adding LSNs to
> checkpint log. Other topics have moved to other treads [1], [2] ,
> [3].
>
> I think this is no longer controversial alone. So this patch is now
> really Read-for-Commiter and is waiting to be picked up.
+1
+ * ControlFileLock is not required as we are the only
+ * updator of these variables.
Isn't it better to add "at this time" or something at the end of the comment because only we're not always updator of them? No?
Barring any objection, I'm thinking to apply the above small change and commit the patch.
Regards,
--
Fujii Masao
Advanced Computing Technology Center
Research and Development Headquarters
NTT DATA CORPORATION
^ permalink raw reply [nested|flat] 17+ messages in thread
* Re: Add checkpoint and redo LSN to LogCheckpointEnd log message
2022-07-06 16:11 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Fujii Masao <[email protected]>
@ 2022-07-07 07:26 ` Kyotaro Horiguchi <[email protected]>
2022-07-07 13:45 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Fujii Masao <[email protected]>
0 siblings, 1 reply; 17+ messages in thread
From: Kyotaro Horiguchi @ 2022-07-07 07:26 UTC (permalink / raw)
To: [email protected]; +Cc: [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]
At Thu, 7 Jul 2022 01:11:33 +0900, Fujii Masao <[email protected]> wrote in
>
>
> On 2022/03/16 10:29, Kyotaro Horiguchi wrote:
> > At Wed, 16 Mar 2022 09:19:13 +0900 (JST), Kyotaro Horiguchi
> > <[email protected]> wrote in
> >> In short, I split out the two topics other than checkpoint log to
> >> other threads.
> > So, this is about the main topic of this thread, adding LSNs to
> > checkpint log. Other topics have moved to other treads [1], [2] ,
> > [3].
> > I think this is no longer controversial alone. So this patch is now
> > really Read-for-Commiter and is waiting to be picked up.
>
> +1
>
> + * ControlFileLock is not required as we are the only
> + * updator of these variables.
>
> Isn't it better to add "at this time" or something at the end of the
> comment because only we're not always updator of them? No?
Excluding initialization, (I believe) checkpointer is really the only
updator of the variables/members. But I'm fine with the addition.
> Barring any objection, I'm thinking to apply the above small change
> and commit the patch.
regards.
--
Kyotaro Horiguchi
NTT Open Source Software Center
^ permalink raw reply [nested|flat] 17+ messages in thread
* Re: Add checkpoint and redo LSN to LogCheckpointEnd log message
2022-07-06 16:11 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Fujii Masao <[email protected]>
2022-07-07 07:26 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Kyotaro Horiguchi <[email protected]>
@ 2022-07-07 13:45 ` Fujii Masao <[email protected]>
0 siblings, 0 replies; 17+ messages in thread
From: Fujii Masao @ 2022-07-07 13:45 UTC (permalink / raw)
To: Kyotaro Horiguchi <[email protected]>; +Cc: [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]
On 2022/07/07 16:26, Kyotaro Horiguchi wrote:
>> + * ControlFileLock is not required as we are the only
>> + * updator of these variables.
>>
>> Isn't it better to add "at this time" or something at the end of the
>> comment because only we're not always updator of them? No?
>
> Excluding initialization, (I believe) checkpointer is really the only
> updator of the variables/members. But I'm fine with the addition.
Ok, so I modified the patch slightly and pushed it. Thanks!
Regards,
--
Fujii Masao
Advanced Computing Technology Center
Research and Development Headquarters
NTT DATA CORPORATION
^ permalink raw reply [nested|flat] 17+ messages in thread
end of thread, other threads:[~2022-07-07 13:45 UTC | newest]
Thread overview: 17+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2019-08-25 18:45 [PATCH] Fix handling of ? option Quentin Rameau <[email protected]>
2019-08-25 18:45 [PATCH] Fix handling of ? option Quentin Rameau <[email protected]>
2021-12-23 15:05 Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
2021-12-24 05:51 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Kyotaro Horiguchi <[email protected]>
2021-12-24 12:07 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
2021-12-24 12:11 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Michael Paquier <[email protected]>
2021-12-24 12:24 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
2021-12-28 02:56 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
2022-02-01 04:34 [PATCH v10 2/5] Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
2022-02-01 04:34 [PATCH v9 2/4] Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
2022-03-04 04:22 [PATCH v12 2/5] Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
2022-03-04 04:22 [PATCH v13] Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
2022-03-04 04:22 [PATCH v11 2/5] Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]>
2022-03-28 19:31 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Greg Stark <[email protected]>
2022-07-06 16:11 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Fujii Masao <[email protected]>
2022-07-07 07:26 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Kyotaro Horiguchi <[email protected]>
2022-07-07 13:45 ` Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Fujii Masao <[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