public inbox for [email protected]help / color / mirror / Atom feed
Re: Add checkpoint and redo LSN to LogCheckpointEnd log message 6+ messages / 4 participants [nested] [flat]
* Re: Add checkpoint and redo LSN to LogCheckpointEnd log message @ 2022-02-01 13:03 Bharath Rupireddy <[email protected]> 0 siblings, 1 reply; 6+ messages in thread From: Bharath Rupireddy @ 2022-02-01 13:03 UTC (permalink / raw) To: Kyotaro Horiguchi <[email protected]>; +Cc: Fujii Masao <[email protected]>; Nathan Bossart <[email protected]>; Stephen Frost <[email protected]>; Bossart, Nathan <[email protected]>; Julien Rouhaud <[email protected]>; Michael Paquier <[email protected]>; PostgreSQL Hackers <[email protected]> On Tue, Feb 1, 2022 at 11:58 AM Kyotaro Horiguchi <[email protected]> wrote: > > Modified in v8. > > 0001 looks good to me. > > I tend to agree to 0002. Thanks. > FWIW, I collected other user-facing usage of "location" as LSN. > > 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) I tried to change the "location" to "lsn" in most of the user-facing messages/text. I refrained from changing the bakup_label file content (above) as it might break many applications/service layer code and it's not good for backward compatibility. Attaching the above changes 0003 (0001 and 0002 remain the same). If the committer doesn't agree on the text or wording in 0003, I would like the 0001 and 0002 to be taken here and I can start a new thread for discussing 0003 separately. Regards, Bharath Rupireddy. Attachments: [application/octet-stream] v8-0001-Add-checkpoint-and-redo-LSN-to-LogCheckpointEnd-l.patch (2.8K, ../../CALj2ACUtZhTb=2ENkF3BQ3wi137uaGi__qzvXC-qFYC0XwjALw@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, ../../CALj2ACUtZhTb=2ENkF3BQ3wi137uaGi__qzvXC-qFYC0XwjALw@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 [application/octet-stream] v8-0003-Change-location-to-lsn-in-user-facing-text.patch (15.1K, ../../CALj2ACUtZhTb=2ENkF3BQ3wi137uaGi__qzvXC-qFYC0XwjALw@mail.gmail.com/4-v8-0003-Change-location-to-lsn-in-user-facing-text.patch) download | inline diff: From 79907e02d6ff7119d6c5522391330aa36a1c4597 Mon Sep 17 00:00:00 2001 From: Bharath Rupireddy <[email protected]> Date: Tue, 1 Feb 2022 12:36:34 +0000 Subject: [PATCH v8] Change "location" to "lsn" in user facing text --- src/backend/access/rmgrdesc/xlogdesc.c | 2 +- src/backend/access/transam/xlog.c | 12 ++++++------ src/backend/replication/repl_scanner.l | 2 +- src/backend/replication/walsender.c | 2 +- src/bin/pg_basebackup/pg_basebackup.c | 6 +++--- src/bin/pg_basebackup/pg_receivewal.c | 2 +- src/bin/pg_basebackup/pg_recvlogical.c | 4 ++-- src/bin/pg_basebackup/streamutil.c | 2 +- src/bin/pg_rewind/pg_rewind.c | 2 +- src/bin/pg_rewind/timeline.c | 2 +- src/bin/pg_waldump/pg_waldump.c | 14 +++++++------- src/include/catalog/pg_proc.dat | 16 ++++++++-------- 12 files changed, 33 insertions(+), 33 deletions(-) diff --git a/src/backend/access/rmgrdesc/xlogdesc.c b/src/backend/access/rmgrdesc/xlogdesc.c index e7452af679..a7ffbd7590 100644 --- a/src/backend/access/rmgrdesc/xlogdesc.c +++ b/src/backend/access/rmgrdesc/xlogdesc.c @@ -44,7 +44,7 @@ xlog_desc(StringInfo buf, XLogReaderState *record) { CheckPoint *checkpoint = (CheckPoint *) rec; - appendStringInfo(buf, "redo %X/%X; " + appendStringInfo(buf, "redo lsn %X/%X; " "tli %u; prev tli %u; fpw %s; xid %u:%u; oid %u; multi %u; offset %u; " "oldest xid %u in DB %u; oldest multi %u in DB %u; " "oldest/newest commit timestamp xid: %u/%u; " diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c index dfe2a0bcce..ed137dc899 100644 --- a/src/backend/access/transam/xlog.c +++ b/src/backend/access/transam/xlog.c @@ -1858,7 +1858,7 @@ WaitXLogInsertionsToFinish(XLogRecPtr upto) if (upto > reservedUpto) { ereport(LOG, - (errmsg("request to flush past end of generated WAL; request %X/%X, current position %X/%X", + (errmsg("request to flush past end of generated WAL; request lsn %X/%X, current lsn %X/%X", LSN_FORMAT_ARGS(upto), LSN_FORMAT_ARGS(reservedUpto)))); upto = reservedUpto; } @@ -5962,7 +5962,7 @@ recoveryStopsBefore(XLogReaderState *record) recoveryStopTime = 0; recoveryStopName[0] = '\0'; ereport(LOG, - (errmsg("recovery stopping before WAL location (LSN) \"%X/%X\"", + (errmsg("recovery stopping before WAL LSN \"%X/%X\"", LSN_FORMAT_ARGS(recoveryStopLSN)))); return true; } @@ -6125,7 +6125,7 @@ recoveryStopsAfter(XLogReaderState *record) recoveryStopTime = 0; recoveryStopName[0] = '\0'; ereport(LOG, - (errmsg("recovery stopping after WAL location (LSN) \"%X/%X\"", + (errmsg("recovery stopping after WAL LSN \"%X/%X\"", LSN_FORMAT_ARGS(recoveryStopLSN)))); return true; } @@ -6715,7 +6715,7 @@ StartupXLOG(void) */ if (!XRecOffIsValid(ControlFile->checkPoint)) ereport(FATAL, - (errmsg("control file contains invalid checkpoint location"))); + (errmsg("control file contains invalid checkpoint LSN"))); switch (ControlFile->state) { @@ -6843,7 +6843,7 @@ StartupXLOG(void) recoveryTargetName))); else if (recoveryTarget == RECOVERY_TARGET_LSN) ereport(LOG, - (errmsg("starting point-in-time recovery to WAL location (LSN) \"%X/%X\"", + (errmsg("starting point-in-time recovery to WAL LSN \"%X/%X\"", LSN_FORMAT_ARGS(recoveryTargetLSN)))); else if (recoveryTarget == RECOVERY_TARGET_IMMEDIATE) ereport(LOG, @@ -6926,7 +6926,7 @@ StartupXLOG(void) if (!ReadRecord(xlogreader, LOG, false, checkPoint.ThisTimeLineID)) ereport(FATAL, - (errmsg("could not find redo location referenced by checkpoint record"), + (errmsg("could not find redo LSN referenced by checkpoint record"), errhint("If you are restoring from a backup, touch \"%s/recovery.signal\" and add required recovery options.\n" "If you are not restoring from a backup, try removing the file \"%s/backup_label\".\n" "Be careful: removing \"%s/backup_label\" will result in a corrupt cluster if restoring from a backup.", diff --git a/src/backend/replication/repl_scanner.l b/src/backend/replication/repl_scanner.l index d992bcc2e3..f1a435bc22 100644 --- a/src/backend/replication/repl_scanner.l +++ b/src/backend/replication/repl_scanner.l @@ -148,7 +148,7 @@ MANIFEST_CHECKSUMS { return K_MANIFEST_CHECKSUMS; } uint32 hi, lo; if (sscanf(yytext, "%X/%X", &hi, &lo) != 2) - yyerror("invalid streaming start location"); + yyerror("invalid streaming start LSN"); yylval.recptr = ((uint64) hi) << 32 | lo; return RECPTR; } diff --git a/src/backend/replication/walsender.c b/src/backend/replication/walsender.c index 655760fee3..0c9d86b72c 100644 --- a/src/backend/replication/walsender.c +++ b/src/backend/replication/walsender.c @@ -812,7 +812,7 @@ StartReplication(StartReplicationCmd *cmd) if (FlushPtr < cmd->startpoint) { ereport(ERROR, - (errmsg("requested starting point %X/%X is ahead of the WAL flush position of this server %X/%X", + (errmsg("requested starting point %X/%X is ahead of the WAL flush LSN of this server %X/%X", LSN_FORMAT_ARGS(cmd->startpoint), LSN_FORMAT_ARGS(FlushPtr)))); } diff --git a/src/bin/pg_basebackup/pg_basebackup.c b/src/bin/pg_basebackup/pg_basebackup.c index c40925c1f0..99b41fc2a6 100644 --- a/src/bin/pg_basebackup/pg_basebackup.c +++ b/src/bin/pg_basebackup/pg_basebackup.c @@ -473,7 +473,7 @@ reached_end_position(XLogRecPtr segendpos, uint32 timeline, if (sscanf(xlogend, "%X/%X", &hi, &lo) != 2) { - pg_log_error("could not parse write-ahead log location \"%s\"", + pg_log_error("could not parse WAL LSN \"%s\"", xlogend); exit(1); } @@ -612,7 +612,7 @@ StartLogStreamer(char *startpos, uint32 timeline, char *sysidentifier) /* Convert the starting position */ if (sscanf(startpos, "%X/%X", &hi, &lo) != 2) { - pg_log_error("could not parse write-ahead log location \"%s\"", + pg_log_error("could not parse WAL LSN \"%s\"", startpos); exit(1); } @@ -2220,7 +2220,7 @@ BaseBackup(void) */ if (sscanf(xlogend, "%X/%X", &hi, &lo) != 2) { - pg_log_error("could not parse write-ahead log location \"%s\"", + pg_log_error("could not parse WAL LSN \"%s\"", xlogend); exit(1); } diff --git a/src/bin/pg_basebackup/pg_receivewal.c b/src/bin/pg_basebackup/pg_receivewal.c index ccb215c398..e8c1631745 100644 --- a/src/bin/pg_basebackup/pg_receivewal.c +++ b/src/bin/pg_basebackup/pg_receivewal.c @@ -753,7 +753,7 @@ main(int argc, char **argv) case 'E': if (sscanf(optarg, "%X/%X", &hi, &lo) != 2) { - pg_log_error("could not parse end position \"%s\"", optarg); + pg_log_error("could not parse end LSN \"%s\"", optarg); exit(1); } endpos = ((uint64) hi) << 32 | lo; diff --git a/src/bin/pg_basebackup/pg_recvlogical.c b/src/bin/pg_basebackup/pg_recvlogical.c index cc35d16f32..0bfb9edb94 100644 --- a/src/bin/pg_basebackup/pg_recvlogical.c +++ b/src/bin/pg_basebackup/pg_recvlogical.c @@ -781,7 +781,7 @@ main(int argc, char **argv) case 'I': if (sscanf(optarg, "%X/%X", &hi, &lo) != 2) { - pg_log_error("could not parse start position \"%s\"", optarg); + pg_log_error("could not parse start LSN \"%s\"", optarg); exit(1); } startpos = ((uint64) hi) << 32 | lo; @@ -789,7 +789,7 @@ main(int argc, char **argv) case 'E': if (sscanf(optarg, "%X/%X", &hi, &lo) != 2) { - pg_log_error("could not parse end position \"%s\"", optarg); + pg_log_error("could not parse end LSN \"%s\"", optarg); exit(1); } endpos = ((uint64) hi) << 32 | lo; diff --git a/src/bin/pg_basebackup/streamutil.c b/src/bin/pg_basebackup/streamutil.c index 4a6afd1a06..41d0473138 100644 --- a/src/bin/pg_basebackup/streamutil.c +++ b/src/bin/pg_basebackup/streamutil.c @@ -447,7 +447,7 @@ RunIdentifySystem(PGconn *conn, char **sysid, TimeLineID *starttli, { if (sscanf(PQgetvalue(res, 0, 2), "%X/%X", &hi, &lo) != 2) { - pg_log_error("could not parse write-ahead log location \"%s\"", + pg_log_error("could not parse WAL LSN \"%s\"", PQgetvalue(res, 0, 2)); PQclear(res); diff --git a/src/bin/pg_rewind/pg_rewind.c b/src/bin/pg_rewind/pg_rewind.c index efb82a4034..7e4a1c2c30 100644 --- a/src/bin/pg_rewind/pg_rewind.c +++ b/src/bin/pg_rewind/pg_rewind.c @@ -343,7 +343,7 @@ main(int argc, char **argv) XLogRecPtr chkptendrec; findCommonAncestorTimeline(&divergerec, &lastcommontliIndex); - pg_log_info("servers diverged at WAL location %X/%X on timeline %u", + pg_log_info("servers diverged at WAL LSN %X/%X on timeline %u", LSN_FORMAT_ARGS(divergerec), targetHistory[lastcommontliIndex].tli); diff --git a/src/bin/pg_rewind/timeline.c b/src/bin/pg_rewind/timeline.c index df8f82a50c..0b3c524f16 100644 --- a/src/bin/pg_rewind/timeline.c +++ b/src/bin/pg_rewind/timeline.c @@ -79,7 +79,7 @@ rewind_parseTimeLineHistory(char *buffer, TimeLineID targetTLI, int *nentries) if (nfields != 3) { pg_log_error("syntax error in history file: %s", fline); - pg_log_error("Expected a write-ahead log switchpoint location."); + pg_log_error("Expected a WAL switchpoint LSN."); exit(1); } if (entries && tli <= lasttli) diff --git a/src/bin/pg_waldump/pg_waldump.c b/src/bin/pg_waldump/pg_waldump.c index a6251e1a96..f792e6351d 100644 --- a/src/bin/pg_waldump/pg_waldump.c +++ b/src/bin/pg_waldump/pg_waldump.c @@ -765,7 +765,7 @@ usage(void) printf(_(" %s [OPTION]... [STARTSEG [ENDSEG]]\n"), progname); printf(_("\nOptions:\n")); printf(_(" -b, --bkp-details output detailed information about backup blocks\n")); - printf(_(" -e, --end=RECPTR stop reading at WAL location RECPTR\n")); + printf(_(" -e, --end=RECPTR stop reading at WAL LSN RECPTR\n")); printf(_(" -f, --follow keep retrying after reaching end of WAL\n")); printf(_(" -n, --limit=N number of records to display\n")); printf(_(" -p, --path=PATH directory in which to find log segment files or a\n" @@ -774,7 +774,7 @@ usage(void) printf(_(" -q, --quiet do not print any output, except for errors\n")); printf(_(" -r, --rmgr=RMGR only show records generated by resource manager RMGR;\n" " use --rmgr=list to list valid resource manager names\n")); - printf(_(" -s, --start=RECPTR start reading at WAL location RECPTR\n")); + printf(_(" -s, --start=RECPTR start reading at WAL LSN RECPTR\n")); printf(_(" -t, --timeline=TLI timeline from which to read log records\n" " (default: 1 or the value used in STARTSEG)\n")); printf(_(" -V, --version output version information, then exit\n")); @@ -883,7 +883,7 @@ main(int argc, char **argv) case 'e': if (sscanf(optarg, "%X/%X", &xlogid, &xrecoff) != 2) { - pg_log_error("could not parse end WAL location \"%s\"", + pg_log_error("could not parse end WAL LSN \"%s\"", optarg); goto bad_argument; } @@ -935,7 +935,7 @@ main(int argc, char **argv) case 's': if (sscanf(optarg, "%X/%X", &xlogid, &xrecoff) != 2) { - pg_log_error("could not parse start WAL location \"%s\"", + pg_log_error("could not parse start WAL LSN \"%s\"", optarg); goto bad_argument; } @@ -1026,7 +1026,7 @@ main(int argc, char **argv) XLogSegNoOffsetToRecPtr(segno, 0, WalSegSz, private.startptr); else if (!XLByteInSeg(private.startptr, segno, WalSegSz)) { - pg_log_error("start WAL location %X/%X is not inside file \"%s\"", + pg_log_error("start WAL LSN %X/%X is not inside file \"%s\"", LSN_FORMAT_ARGS(private.startptr), fname); goto bad_argument; @@ -1068,7 +1068,7 @@ main(int argc, char **argv) if (!XLByteInSeg(private.endptr, segno, WalSegSz) && private.endptr != (segno + 1) * WalSegSz) { - pg_log_error("end WAL location %X/%X is not inside file \"%s\"", + pg_log_error("end WAL LSN %X/%X is not inside file \"%s\"", LSN_FORMAT_ARGS(private.endptr), argv[argc - 1]); goto bad_argument; @@ -1080,7 +1080,7 @@ main(int argc, char **argv) /* we don't know what to print */ if (XLogRecPtrIsInvalid(private.startptr)) { - pg_log_error("no start WAL location given"); + pg_log_error("no start WAL LSN given"); goto bad_argument; } diff --git a/src/include/catalog/pg_proc.dat b/src/include/catalog/pg_proc.dat index 7024dbe10a..c302544486 100644 --- a/src/include/catalog/pg_proc.dat +++ b/src/include/catalog/pg_proc.dat @@ -6299,24 +6299,24 @@ proname => 'pg_create_restore_point', provolatile => 'v', prorettype => 'pg_lsn', proargtypes => 'text', prosrc => 'pg_create_restore_point' }, -{ oid => '2849', descr => 'current wal write location', +{ oid => '2849', descr => 'current wal write lsn', proname => 'pg_current_wal_lsn', provolatile => 'v', prorettype => 'pg_lsn', proargtypes => '', prosrc => 'pg_current_wal_lsn' }, -{ oid => '2852', descr => 'current wal insert location', +{ oid => '2852', descr => 'current wal insert lsn', proname => 'pg_current_wal_insert_lsn', provolatile => 'v', prorettype => 'pg_lsn', proargtypes => '', prosrc => 'pg_current_wal_insert_lsn' }, -{ oid => '3330', descr => 'current wal flush location', +{ oid => '3330', descr => 'current wal flush lsn', proname => 'pg_current_wal_flush_lsn', provolatile => 'v', prorettype => 'pg_lsn', proargtypes => '', prosrc => 'pg_current_wal_flush_lsn' }, { oid => '2850', - descr => 'wal filename and byte offset, given a wal location', + descr => 'wal filename and byte offset, given a wal lsn', proname => 'pg_walfile_name_offset', prorettype => 'record', proargtypes => 'pg_lsn', proallargtypes => '{pg_lsn,text,int4}', proargmodes => '{i,o,o}', proargnames => '{lsn,file_name,file_offset}', prosrc => 'pg_walfile_name_offset' }, -{ oid => '2851', descr => 'wal filename, given a wal location', +{ oid => '2851', descr => 'wal filename, given a wal lsn', proname => 'pg_walfile_name', prorettype => 'text', proargtypes => 'pg_lsn', prosrc => 'pg_walfile_name' }, @@ -6332,11 +6332,11 @@ proname => 'pg_is_in_recovery', provolatile => 'v', prorettype => 'bool', proargtypes => '', prosrc => 'pg_is_in_recovery' }, -{ oid => '3820', descr => 'current wal flush location', +{ oid => '3820', descr => 'current wal flush lsn', proname => 'pg_last_wal_receive_lsn', provolatile => 'v', prorettype => 'pg_lsn', proargtypes => '', prosrc => 'pg_last_wal_receive_lsn' }, -{ oid => '3821', descr => 'last wal replay location', +{ oid => '3821', descr => 'last wal replay lsn', proname => 'pg_last_wal_replay_lsn', provolatile => 'v', prorettype => 'pg_lsn', proargtypes => '', prosrc => 'pg_last_wal_replay_lsn' }, @@ -11509,7 +11509,7 @@ proparallel => 'r', prorettype => 'void', proargtypes => '', prosrc => 'pg_replication_origin_xact_reset' }, -{ oid => '6012', descr => 'advance replication origin to specific location', +{ oid => '6012', descr => 'advance replication origin to specific lsn', proname => 'pg_replication_origin_advance', provolatile => 'v', proparallel => 'u', prorettype => 'void', proargtypes => 'text pg_lsn', prosrc => 'pg_replication_origin_advance' }, -- 2.25.1 ^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: Add checkpoint and redo LSN to LogCheckpointEnd log message @ 2022-02-01 16:09 Fujii Masao <[email protected]> parent: Bharath Rupireddy <[email protected]> 0 siblings, 2 replies; 6+ messages in thread From: Fujii Masao @ 2022-02-01 16:09 UTC (permalink / raw) To: Bharath Rupireddy <[email protected]>; Kyotaro Horiguchi <[email protected]>; +Cc: Nathan Bossart <[email protected]>; Stephen Frost <[email protected]>; Bossart, Nathan <[email protected]>; Julien Rouhaud <[email protected]>; Michael Paquier <[email protected]>; PostgreSQL Hackers <[email protected]> On 2022/02/01 22:03, Bharath Rupireddy wrote: > On Tue, Feb 1, 2022 at 11:58 AM Kyotaro Horiguchi > <[email protected]> wrote: >>> Modified in v8. >> >> 0001 looks good to me. I found that CreateRestartPoint() already reported the redo lsn as follows after emitting the restartpoint log message. To avoid duplicated logging of the same information, we should update this code? ereport((log_checkpoints ? LOG : DEBUG2), (errmsg("recovery restart point at %X/%X", LSN_FORMAT_ARGS(lastCheckPoint.redo)), xtime ? errdetail("Last completed transaction was at log time %s.", timestamptz_to_str(xtime)) : 0)); This code reports lastCheckPoint.redo as redo lsn. OTOH, with the patch, LogCheckpointEnd() reports ControlFile->checkPointCopy.redo. They may be different, for example, when the current DB state is not DB_IN_ARCHIVE_RECOVERY. In this case, which lsn should we report as redo lsn? + "lsn=%X/%X, redo lsn=%X/%X", Originally you proposed to use upper cases for "lsn". But the latest patch uses the lower cases. Why? It seems better to use upper cases, i.e., LSN and REDO LSN because LSN is basically used in other errmsg(). > Attaching the above changes 0003 (0001 and 0002 remain the same). If > the committer doesn't agree on the text or wording in 0003, I would > like the 0001 and 0002 to be taken here and I can start a new thread > for discussing 0003 separately. Personally I'm ok with 001, but regarding 0002 and 0003 patches, I'm not sure if it's really worth replacing "location" with "lsn" there. BTW, the similar idea was proposed at [1] before, but seems "location" was left as it was. [1] https://postgr.es/m/[email protected] Regards, -- Fujii Masao Advanced Computing Technology Center Research and Development Headquarters NTT DATA CORPORATION ^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: Add checkpoint and redo LSN to LogCheckpointEnd log message @ 2022-02-01 21:05 Stephen Frost <[email protected]> parent: Fujii Masao <[email protected]> 1 sibling, 0 replies; 6+ messages in thread From: Stephen Frost @ 2022-02-01 21:05 UTC (permalink / raw) To: Fujii Masao <[email protected]>; +Cc: Bharath Rupireddy <[email protected]>; Kyotaro Horiguchi <[email protected]>; Nathan Bossart <[email protected]>; Bossart, Nathan <[email protected]>; Julien Rouhaud <[email protected]>; Michael Paquier <[email protected]>; PostgreSQL Hackers <[email protected]> Greetings, * Fujii Masao ([email protected]) wrote: > On 2022/02/01 22:03, Bharath Rupireddy wrote: > >On Tue, Feb 1, 2022 at 11:58 AM Kyotaro Horiguchi > ><[email protected]> wrote: > >>>Modified in v8. > >> > >>0001 looks good to me. > > I found that CreateRestartPoint() already reported the redo lsn as follows after emitting the restartpoint log message. To avoid duplicated logging of the same information, we should update this code? > > ereport((log_checkpoints ? LOG : DEBUG2), > (errmsg("recovery restart point at %X/%X", > LSN_FORMAT_ARGS(lastCheckPoint.redo)), > xtime ? errdetail("Last completed transaction was at log time %s.", > timestamptz_to_str(xtime)) : 0)); > > This code reports lastCheckPoint.redo as redo lsn. OTOH, with the patch, LogCheckpointEnd() reports ControlFile->checkPointCopy.redo. They may be different, for example, when the current DB state is not DB_IN_ARCHIVE_RECOVERY. In this case, which lsn should we report as redo lsn? > > + "lsn=%X/%X, redo lsn=%X/%X", > > Originally you proposed to use upper cases for "lsn". But the latest patch uses the lower cases. Why? It seems better to use upper cases, i.e., LSN and REDO LSN because LSN is basically used in other errmsg(). We do use 'lsn=' quite a bit in verify_nbtree.c already and lowercase is also what's in the various functions and views in the catalog in the database, of course. I don't see even one usage of "LSN=" in the tree today. We also use 'lsn %X/%X' in replorigindesc.c, xactdesc.c, xactdesc.c, tablesync.c, standby.c, parsexlog.c, then 'redo %X/%X' in xactdesc.c. xlog.c does have a number of "WAL location (LSN)", along with a bunch of other usages. logical.c uses both "LSN" and "lsn". worker.c uses "LSN". slot.c uses "restart_lsn". pg_rewind.c uses "WAL location" while pg_waldump.c uses, "lsn:", "WAL location", and "WAL record". Overall, we don't seem to be super consistent, but I'd say that 'lsn=' looks the best, to my eyes anyway, and isn't out of place in the code base. Lowercase seems to generally be more common overall. > >Attaching the above changes 0003 (0001 and 0002 remain the same). If > >the committer doesn't agree on the text or wording in 0003, I would > >like the 0001 and 0002 to be taken here and I can start a new thread > >for discussing 0003 separately. > > Personally I'm ok with 001, but regarding 0002 and 0003 patches, I'm not sure if it's really worth replacing "location" with "lsn" there. BTW, the similar idea was proposed at [1] before, but seems "location" was left as it was. > > [1] > https://postgr.es/m/[email protected] This discussion strikes me as sufficient reason to make the change, with the prior comment not really having all that much weight. When we're actually pretty consistent with one term, having random places where we are inconsistent leads people to be unsure about which way to go and then we end up having to have this discussion. Would be great to avoid having to have it again in the future. Thanks, Stephen Attachments: [application/pgp-signature] signature.asc (819B, ../../[email protected]/2-signature.asc) download ^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: Add checkpoint and redo LSN to LogCheckpointEnd log message @ 2022-02-02 14:46 Bharath Rupireddy <[email protected]> parent: Fujii Masao <[email protected]> 1 sibling, 1 reply; 6+ messages in thread From: Bharath Rupireddy @ 2022-02-02 14:46 UTC (permalink / raw) To: Fujii Masao <[email protected]>; +Cc: Kyotaro Horiguchi <[email protected]>; Nathan Bossart <[email protected]>; Stephen Frost <[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:39 PM Fujii Masao <[email protected]> wrote: > I found that CreateRestartPoint() already reported the redo lsn as follows after emitting the restartpoint log message. To avoid duplicated logging of the same information, we should update this code? > > ereport((log_checkpoints ? LOG : DEBUG2), > (errmsg("recovery restart point at %X/%X", > LSN_FORMAT_ARGS(lastCheckPoint.redo)), > xtime ? errdetail("Last completed transaction was at log time %s.", > timestamptz_to_str(xtime)) : 0)); > > This code reports lastCheckPoint.redo as redo lsn. OTOH, with the patch, LogCheckpointEnd() reports ControlFile->checkPointCopy.redo. They may be different, for example, when the current DB state is not DB_IN_ARCHIVE_RECOVERY. In this case, which lsn should we report as redo lsn? Do we ever reach CreateRestartPoint when ControlFile->stat != DB_IN_ARCHIVE_RECOVERY? Assert(ControlFile->state == DB_IN_ARCHIVE_RECOVERY); in CreateRestartPoint doesn't fail any regression tests. Here's what can happen: lastCheckPoint.redo is 100 and ControlFile->checkPointCopy.redo is 105, so, "skipping restartpoint, already performed at %X/%X" LogCheckpointEnd isn't reached lastCheckPoint.redo is 105 and ControlFile->checkPointCopy.redo is 100 and ControlFile->state == DB_IN_ARCHIVE_RECOVERY, then the control file gets updated and LogCheckpointEnd prints the right redo lsn. lastCheckPoint.redo is 105 and ControlFile->checkPointCopy.redo is 100 and ControlFile->state != DB_IN_ARCHIVE_RECOVERY, the the control file doesn't get updated and LogCheckpointEnd just prints the control redo lsn. Looks like this case is rare given Assert(ControlFile->state == DB_IN_ARCHIVE_RECOVERY); doesn't fail any tests. I think we should just let LogCheckpointEnd print the redo lsn from the control file. We can just remove the above errmsg("recovery restart point at %X/%X" message altogether or just print it only in the rare scenario, something like below: if (ControlFile->state != DB_IN_ARCHIVE_RECOVERY) { ereport((log_checkpoints ? LOG : DEBUG2), (errmsg("performed recovery restart point at %X/%X while the database state is %s", LSN_FORMAT_ARGS(lastCheckPoint.redo)), getDBState(ControlFile->state))); } And the last commit/abort records's timestamp will always get logged even before we reach here in the main redo loop (errmsg("last completed transaction was at log time %s"). Or another way is to just pass the redo lsn to LogCheckpointEnd and pass the lastCheckPoint.redo in if (ControlFile->state != DB_IN_ARCHIVE_RECOVERY) cases or when control file isn't updated but restart point happened. Thoughts? Regards, Bharath Rupireddy. ^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: Add checkpoint and redo LSN to LogCheckpointEnd log message @ 2022-02-03 04:59 Fujii Masao <[email protected]> parent: Bharath Rupireddy <[email protected]> 0 siblings, 0 replies; 6+ messages in thread From: Fujii Masao @ 2022-02-03 04:59 UTC (permalink / raw) To: Bharath Rupireddy <[email protected]>; +Cc: Kyotaro Horiguchi <[email protected]>; Nathan Bossart <[email protected]>; Stephen Frost <[email protected]>; Bossart, Nathan <[email protected]>; Julien Rouhaud <[email protected]>; Michael Paquier <[email protected]>; PostgreSQL Hackers <[email protected]> On 2022/02/02 23:46, Bharath Rupireddy wrote: > On Tue, Feb 1, 2022 at 9:39 PM Fujii Masao <[email protected]> wrote: >> I found that CreateRestartPoint() already reported the redo lsn as follows after emitting the restartpoint log message. To avoid duplicated logging of the same information, we should update this code? >> >> ereport((log_checkpoints ? LOG : DEBUG2), >> (errmsg("recovery restart point at %X/%X", >> LSN_FORMAT_ARGS(lastCheckPoint.redo)), >> xtime ? errdetail("Last completed transaction was at log time %s.", >> timestamptz_to_str(xtime)) : 0)); >> >> This code reports lastCheckPoint.redo as redo lsn. OTOH, with the patch, LogCheckpointEnd() reports ControlFile->checkPointCopy.redo. They may be different, for example, when the current DB state is not DB_IN_ARCHIVE_RECOVERY. In this case, which lsn should we report as redo lsn? > > Do we ever reach CreateRestartPoint when ControlFile->stat != > DB_IN_ARCHIVE_RECOVERY? Assert(ControlFile->state == > DB_IN_ARCHIVE_RECOVERY); in CreateRestartPoint doesn't fail any > regression tests. ISTM that CreateRestartPoint() can reach the condition ControlFile->state != DB_IN_ARCHIVE_RECOVERY. Please imagine the case where CreateRestartPoint() has already started and calls CheckPointGuts(). If the standby server is promoted while CreateRestartPoint() is flushing the data to disk at CheckPointGuts(), the state would be updated to DB_IN_PRODUCTION and CreateRestartPoint() can see the state != DB_IN_ARCHIVE_RECOVERY later. As far as I read the code, this case seems to be able to make the server unrecoverable. If this case happens, since pg_control is not updated, pg_control still indicates the REDO LSN of last valid restartpoint. But CreateRestartPoint() seems to delete old WAL files based on its "current" REDO LSN not pg_control's REDO LSN. That is, WAL files required for the crash recovery starting from pg_control's REDO LSN would be removed. If this understanding is right, to address this issue, probably we need to make CreateRestartPoint() do nothing (return immediately) when the state != DB_IN_ARCHIVE_RECOVERY? Regards, -- Fujii Masao Advanced Computing Technology Center Research and Development Headquarters NTT DATA CORPORATION ^ permalink raw reply [nested|flat] 6+ messages in thread
* [PATCH 11/25] vcregress: add alltaptests @ 2022-02-25 23:00 Justin Pryzby <[email protected]> 0 siblings, 0 replies; 6+ messages in thread From: Justin Pryzby @ 2022-02-25 23:00 UTC (permalink / raw) https://www.postgresql.org/message-id/[email protected] https://www.postgresql.org/message-id/flat/[email protected] In passing, document taptest PROVE_FLAGS ci-os-only: windows See also: d835dd6685246f0737ca42ab68242210681bb220 13d856e177e69083f543d6383eeda9e12ce3c55c fed6df486dca1b9e53d3f560031b9a236c99f4bb --- .cirrus.yml | 10 ++------- src/tools/msvc/vcregress.pl | 43 +++++++++++++++++++++++++++++++++---- 2 files changed, 41 insertions(+), 12 deletions(-) diff --git a/.cirrus.yml b/.cirrus.yml index 54124d0fe34..f19558e67e0 100644 --- a/.cirrus.yml +++ b/.cirrus.yml @@ -455,14 +455,8 @@ task: test_ssl_script: | set with_ssl=openssl %T_C% perl src/tools/msvc/vcregress.pl taptest ./src/test/ssl/ - test_subscription_script: | - %T_C% perl src/tools/msvc/vcregress.pl taptest ./src/test/subscription/ - test_authentication_script: | - %T_C% perl src/tools/msvc/vcregress.pl taptest ./src/test/authentication/ - test_recovery_script: | - %T_C% perl src/tools/msvc/vcregress.pl recoverycheck - test_bin_script: | - %T_C% perl src/tools/msvc/vcregress.pl bincheck + test_tap_script: | + %T_C% perl src/tools/msvc/vcregress.pl alltaptests test_ecpg_script: | rem tries to build additional stuff vcvarsall x64 diff --git a/src/tools/msvc/vcregress.pl b/src/tools/msvc/vcregress.pl index 2d6ccd45419..6495f33e593 100644 --- a/src/tools/msvc/vcregress.pl +++ b/src/tools/msvc/vcregress.pl @@ -51,7 +51,7 @@ if (-e "src/tools/msvc/buildenv.pl") my $what = shift || ""; if ($what =~ - /^(check|installcheck|plcheck|contribcheck|modulescheck|ecpgcheck|isolationcheck|upgradecheck|bincheck|recoverycheck|taptest)$/i + /^(check|installcheck|plcheck|contribcheck|modulescheck|ecpgcheck|isolationcheck|upgradecheck|bincheck|recoverycheck|taptest|alltaptests)$/i ) { $what = uc $what; @@ -109,6 +109,7 @@ my %command = ( BINCHECK => \&bincheck, RECOVERYCHECK => \&recoverycheck, UPGRADECHECK => \&upgradecheck, # no-op + ALLTAPTESTS => \&alltaptests, TAPTEST => \&taptest,); my $proc = $command{$what}; @@ -296,6 +297,9 @@ sub tap_check # add the module build dir as the second element in the PATH $ENV{PATH} =~ s!;!;$topdir/$Config/$module;!; + print "============================================================\n"; + print "Checking $dir: @args\n"; + rmtree('tmp_check'); system(@args); my $status = $? >> 8; @@ -310,8 +314,7 @@ sub bincheck my $mstat = 0; - # Find out all the existing TAP tests by looking for t/ directories - # in the tree. + # Find the TAP tests by looking for t/ directories my @bin_dirs = glob("$topdir/src/bin/*"); # Process each test @@ -326,6 +329,36 @@ sub bincheck return; } +sub alltaptests +{ + InstallTemp(); + + my $mstat = 0; + + # Find out all the existing TAP tests by looking for t/ directories + # in the tree. + my @tap_dirs = (); + my @top_dir = ($topdir); + File::Find::find( + { wanted => sub { + /^t\z/s + && $File::Find::name !~ /\/(kerberos|ldap|ssl|ssl_passphrase_callback)\// # opt-in: warn about these? + && push(@tap_dirs, $File::Find::name); + } + }, + @top_dir); + + # Process each test + foreach my $test_path (@tap_dirs) + { + my $dir = dirname($test_path); + my $status = tap_check($dir); + $mstat ||= $status; + } + exit $mstat if $mstat; + return; +} + sub taptest { my $dir = shift; @@ -676,6 +709,7 @@ sub usage print STDERR "Usage: vcregress.pl <mode> [<arg>]\n\n", "Options for <mode>:\n", + " alltaptests run all tap tests (except kerberos, ldap, ssl, ssl_passphrase_callback)\n", " bincheck run tests of utilities in src/bin/\n", " check deploy instance and run regression tests on it\n", " contribcheck run tests of modules in contrib/\n", @@ -693,6 +727,7 @@ sub usage "\nOptions for <arg>: (used by contribcheck and modulescheck)\n", " install also run tests which require a new instance\n", "\nOption for <arg>: for taptest\n", - " TEST_DIR (required) directory where tests reside\n"; + " TEST_DIR (required) directory where tests reside\n", + " PROVE_FLAGS flags to pass to prove\n"; exit(1); } -- 2.17.1 --IS0zKkzwUGydFO0o Content-Type: text/x-diff; charset=us-ascii Content-Disposition: attachment; filename="0012-tmp-run-tap-tests-first.patch" ^ permalink raw reply [nested|flat] 6+ messages in thread
end of thread, other threads:[~2022-02-25 23:00 UTC | newest] Thread overview: 6+ messages (download: mbox mbox.gz follow: Atom feed) -- links below jump to the message on this page -- 2022-02-01 13:03 Re: Add checkpoint and redo LSN to LogCheckpointEnd log message Bharath Rupireddy <[email protected]> 2022-02-01 16:09 ` Fujii Masao <[email protected]> 2022-02-01 21:05 ` Stephen Frost <[email protected]> 2022-02-02 14:46 ` Bharath Rupireddy <[email protected]> 2022-02-03 04:59 ` Fujii Masao <[email protected]> 2022-02-25 23:00 [PATCH 11/25] vcregress: add alltaptests Justin Pryzby <[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