From 3d143d49106e8a6634c1b04adb456f0526a01e3b Mon Sep 17 00:00:00 2001 From: Heikki Linnakangas Date: Tue, 26 Apr 2022 12:17:45 +0300 Subject: [PATCH 1/4] Add error context, if replaying a WAL record fails in WAL redo process. --- src/backend/access/transam/xlog.c | 3 +-- src/backend/tcop/zenith_wal_redo.c | 37 +++++++++++++++++++++++++++++- src/include/access/xlog.h | 1 + 3 files changed, 38 insertions(+), 3 deletions(-) diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c index 55f14ec032f..f10dcd95bdc 100644 --- a/src/backend/access/transam/xlog.c +++ b/src/backend/access/transam/xlog.c @@ -976,7 +976,6 @@ static bool CheckForStandbyTrigger(void); static void xlog_outrec(StringInfo buf, XLogReaderState *record); #endif static void xlog_block_info(StringInfo buf, XLogReaderState *record); -static void xlog_outdesc(StringInfo buf, XLogReaderState *record); static void pg_start_backup_callback(int code, Datum arg); static void pg_stop_backup_callback(int code, Datum arg); static bool read_backup_label(XLogRecPtr *checkPointLoc, @@ -10882,7 +10881,7 @@ xlog_block_info(StringInfo buf, XLogReaderState *record) * Returns a string describing an XLogRecord, consisting of its identity * optionally followed by a colon, a space, and a further description. */ -static void +void xlog_outdesc(StringInfo buf, XLogReaderState *record) { RmgrId rmid = XLogRecGetRmid(record); diff --git a/src/backend/tcop/zenith_wal_redo.c b/src/backend/tcop/zenith_wal_redo.c index f09ae5273b2..ac55c7cefc6 100644 --- a/src/backend/tcop/zenith_wal_redo.c +++ b/src/backend/tcop/zenith_wal_redo.c @@ -93,6 +93,7 @@ static int ReadRedoCommand(StringInfo inBuf); static void BeginRedoForBlock(StringInfo input_message); static void PushPage(StringInfo input_message); static void ApplyRecord(StringInfo input_message); +static void apply_error_callback(void *arg); static bool redo_block_filter(XLogReaderState *record, uint8 block_id); static void GetPage(StringInfo input_message); static ssize_t buffered_read(void *buf, size_t count); @@ -579,11 +580,11 @@ PushPage(StringInfo input_message) static void ApplyRecord(StringInfo input_message) { - /* recovery here */ char *errormsg; XLogRecPtr lsn; XLogRecord *record; int nleft; + ErrorContextCallback errcallback; /* * message format: @@ -601,7 +602,18 @@ ApplyRecord(StringInfo input_message) elog(ERROR, "mismatch between record (%d) and message size (%d)", record->xl_tot_len, (int) sizeof(XLogRecord) + nleft); + /* Setup error traceback support for ereport() */ + errcallback.callback = apply_error_callback; + errcallback.arg = (void *) reader_state; + errcallback.previous = error_context_stack; + error_context_stack = &errcallback; + XLogBeginRead(reader_state, lsn); + /* + * In lieu of calling XLogReadRecord, store the record 'decoded_record' + * buffer directly. + */ + reader_state->ReadRecPtr = lsn; reader_state->decoded_record = record; if (!DecodeXLogRecord(reader_state, record, &errormsg)) elog(ERROR, "failed to decode WAL record: %s", errormsg); @@ -613,10 +625,33 @@ ApplyRecord(StringInfo input_message) redo_read_buffer_filter = NULL; + /* Pop the error context stack */ + error_context_stack = errcallback.previous; + elog(TRACE, "applied WAL record with LSN %X/%X", (uint32) (lsn >> 32), (uint32) lsn); } +/* + * Error context callback for errors occurring during ApplyRecord + */ +static void +apply_error_callback(void *arg) +{ + XLogReaderState *record = (XLogReaderState *) arg; + StringInfoData buf; + + initStringInfo(&buf); + xlog_outdesc(&buf, record); + + /* translator: %s is a WAL record description */ + errcontext("WAL redo at %X/%X for %s", + LSN_FORMAT_ARGS(record->ReadRecPtr), + buf.data); + + pfree(buf.data); +} + static bool redo_block_filter(XLogReaderState *record, uint8 block_id) { diff --git a/src/include/access/xlog.h b/src/include/access/xlog.h index e34f1deaf6e..f35e3686cf8 100644 --- a/src/include/access/xlog.h +++ b/src/include/access/xlog.h @@ -307,6 +307,7 @@ extern void XLogSetReplicationSlotMinimumLSN(XLogRecPtr lsn); extern void xlog_redo(XLogReaderState *record); extern void xlog_desc(StringInfo buf, XLogReaderState *record); extern const char *xlog_identify(uint8 info); +extern void xlog_outdesc(StringInfo buf, XLogReaderState *record); extern void issue_xlog_fsync(int fd, XLogSegNo segno); From 352e286ec76d16169ba425ebd56f9185fa9b76a7 Mon Sep 17 00:00:00 2001 From: Heikki Linnakangas Date: Tue, 26 Apr 2022 13:19:01 +0300 Subject: [PATCH 2/4] Add WARNING for debugging purposes. --- contrib/zenith/inmem_smgr.c | 4 ++++ src/backend/tcop/zenith_wal_redo.c | 8 ++++++++ 2 files changed, 12 insertions(+) diff --git a/contrib/zenith/inmem_smgr.c b/contrib/zenith/inmem_smgr.c index 95e7d062f61..dbc780624a8 100644 --- a/contrib/zenith/inmem_smgr.c +++ b/contrib/zenith/inmem_smgr.c @@ -195,6 +195,10 @@ inmem_nblocks(SMgrRelation reln, ForkNumber forknum) { int nblocks = 0; + /* + * Find the hightest-numbered page, and report that as the relation size. + * XXX: Why does this get called during WAL replay at all? + */ for (int i = 0; i < used_pages; i++) { if (RelFileNodeEquals(reln->smgr_rnode.node, page_tag[i].rnode) diff --git a/src/backend/tcop/zenith_wal_redo.c b/src/backend/tcop/zenith_wal_redo.c index ac55c7cefc6..aa423a0e2dc 100644 --- a/src/backend/tcop/zenith_wal_redo.c +++ b/src/backend/tcop/zenith_wal_redo.c @@ -664,6 +664,14 @@ redo_block_filter(XLogReaderState *record, uint8 block_id) elog(PANIC, "failed to locate backup block with ID %d", block_id); } + /* + * Can a WAL redo function ever access a relation other than the one that + * it modifies? I don't see why it would. + */ + if (!RelFileNodeEquals(target_tag.rnode, target_redo_tag.rnode)) + elog(WARNING, "REDO accessing unexpected page: %u/%u/%u.%u blk %u", + target_tag.rnode.spcNode, target_tag.rnode.dbNode, target_tag.rnode.relNode, target_tag.forkNum, target_tag.blockNum); + /* * If this block isn't one we are currently restoring, then return 'true' * so that this gets ignored From d2afbf7f1ca407a5dbb8599336c1b5d7254dafa9 Mon Sep 17 00:00:00 2001 From: Heikki Linnakangas Date: Tue, 26 Apr 2022 14:20:49 +0300 Subject: [PATCH 3/4] Turn Assertion into elog(ERROR), to help with debugging. This error is happening in the 'pg_regress' test in the CI, but not on my laptop. Turn it into an ERROR, so that we get the error context and backtrace of it. --- src/backend/storage/smgr/smgr.c | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/src/backend/storage/smgr/smgr.c b/src/backend/storage/smgr/smgr.c index 10a6f65c118..f1e676bcc3e 100644 --- a/src/backend/storage/smgr/smgr.c +++ b/src/backend/storage/smgr/smgr.c @@ -194,7 +194,11 @@ smgropen(RelFileNode rnode, BackendId backend, char relpersistence) if (reln->smgr_relpersistence == 0) reln->smgr_relpersistence = relpersistence; else - Assert(relpersistence == 0 || reln->smgr_relpersistence == relpersistence); + { + if (!(relpersistence == 0 || reln->smgr_relpersistence == relpersistence)) + elog(ERROR, "relpersistence mismatch: smgropen %c vs SmgrRelation %c", + relpersistence, reln->smgr_relpersistence); + } } return reln; From 20c37c0565b86e07f2d22576767770cb1d159a2c Mon Sep 17 00:00:00 2001 From: Heikki Linnakangas Date: Tue, 26 Apr 2022 15:05:50 +0300 Subject: [PATCH 4/4] Fix errors in WAL redo about relpersistence mismatch. In the WAL redo process, even "permanent" buffers are stored in the local buffer cache. Need to pass RELPERSISTENCE_PERMANENT to smgropen() in that case. --- src/backend/storage/buffer/localbuf.c | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/src/backend/storage/buffer/localbuf.c b/src/backend/storage/buffer/localbuf.c index b9811cc7327..3184b1e5686 100644 --- a/src/backend/storage/buffer/localbuf.c +++ b/src/backend/storage/buffer/localbuf.c @@ -18,6 +18,7 @@ #include "access/parallel.h" #include "catalog/catalog.h" #include "executor/instrument.h" +#include "miscadmin.h" #include "storage/buf_internals.h" #include "storage/bufmgr.h" #include "utils/guc.h" @@ -215,7 +216,10 @@ LocalBufferAlloc(SMgrRelation smgr, ForkNumber forkNum, BlockNumber blockNum, Page localpage = (char *) LocalBufHdrGetBlock(bufHdr); /* Find smgr relation for buffer */ - oreln = smgropen(bufHdr->tag.rnode, MyBackendId, RELPERSISTENCE_TEMP); + if (am_wal_redo_postgres && MyBackendId == InvalidBackendId) + oreln = smgropen(bufHdr->tag.rnode, MyBackendId, RELPERSISTENCE_PERMANENT); + else + oreln = smgropen(bufHdr->tag.rnode, MyBackendId, RELPERSISTENCE_TEMP); PageSetChecksumInplace(localpage, bufHdr->tag.blockNum);