From 7b8a899bdeb638f46e102d1714c079a0874e9fa0 Mon Sep 17 00:00:00 2001 From: Fujii Masao Date: Wed, 13 Nov 2019 16:59:17 +0900 Subject: [PATCH] Make pg_waldump report more detail information about PREPARE TRANSACTION record. This commit changes xact_desc() so that it reports the detail information about PREPARE TRANSACTION record, like GID (global transaction identifier), timestamp at prepare transaction, delete-on-abort/commit relations, XID of subtransactions, and invalidation messages. These are helpful when diagnosing 2PC-related troubles. Author: Fujii Masao Reviewed-by: Michael Paquier, Andrey Lepikhov, Kyotaro Horiguchi, Julien Rouhaud, Alvaro Herrera Discussion: https://postgr.es/m/CAHGQGwEvhASad4JJnCv=0dW2TJypZgW_Vpb-oZik2a3utCqcrA@mail.gmail.com --- src/backend/access/rmgrdesc/standbydesc.c | 4 + src/backend/access/rmgrdesc/xactdesc.c | 140 ++++++++++++++++------ src/backend/access/transam/twophase.c | 56 +-------- src/include/access/twophase.h | 2 - src/include/access/xact.h | 19 +++ 5 files changed, 125 insertions(+), 96 deletions(-) diff --git a/src/backend/access/rmgrdesc/standbydesc.c b/src/backend/access/rmgrdesc/standbydesc.c index c295358f364..aaff652aebc 100644 --- a/src/backend/access/rmgrdesc/standbydesc.c +++ b/src/backend/access/rmgrdesc/standbydesc.c @@ -102,6 +102,10 @@ standby_desc_invalidations(StringInfo buf, { int i; + /* Do nothing if there are no invalidation messages */ + if (nmsgs <= 0) + return; + if (relcacheInitFileInval) appendStringInfo(buf, "; relcache init file inval dbid %u tsid %u", dbId, tsId); diff --git a/src/backend/access/rmgrdesc/xactdesc.c b/src/backend/access/rmgrdesc/xactdesc.c index a61f38dd19b..4c411c5322e 100644 --- a/src/backend/access/rmgrdesc/xactdesc.c +++ b/src/backend/access/rmgrdesc/xactdesc.c @@ -209,43 +209,95 @@ ParseAbortRecord(uint8 info, xl_xact_abort *xlrec, xl_xact_parsed_abort *parsed) } } -static void -xact_desc_commit(StringInfo buf, uint8 info, xl_xact_commit *xlrec, RepOriginId origin_id) +/* + * ParsePrepareRecord + */ +void +ParsePrepareRecord(uint8 info, xl_xact_prepare *xlrec, xl_xact_parsed_prepare *parsed) { - xl_xact_parsed_commit parsed; - int i; + char *bufptr; - ParseCommitRecord(info, xlrec, &parsed); + bufptr = ((char *) xlrec) + MAXALIGN(sizeof(xl_xact_prepare)); - /* If this is a prepared xact, show the xid of the original xact */ - if (TransactionIdIsValid(parsed.twophase_xid)) - appendStringInfo(buf, "%u: ", parsed.twophase_xid); + memset(parsed, 0, sizeof(*parsed)); - appendStringInfoString(buf, timestamptz_to_str(xlrec->xact_time)); + parsed->xact_time = xlrec->prepared_at; + parsed->origin_lsn = xlrec->origin_lsn; + parsed->origin_timestamp = xlrec->origin_timestamp; + parsed->twophase_xid = xlrec->xid; + parsed->dbId = xlrec->database; + parsed->nsubxacts = xlrec->nsubxacts; + parsed->nrels = xlrec->ncommitrels; + parsed->nabortrels = xlrec->nabortrels; + parsed->nmsgs = xlrec->ninvalmsgs; + + strncpy(parsed->twophase_gid, bufptr, xlrec->gidlen); + bufptr += MAXALIGN(xlrec->gidlen); + + parsed->subxacts = (TransactionId *) bufptr; + bufptr += MAXALIGN(xlrec->nsubxacts * sizeof(TransactionId)); + + parsed->xnodes = (RelFileNode *) bufptr; + bufptr += MAXALIGN(xlrec->ncommitrels * sizeof(RelFileNode)); + + parsed->abortnodes = (RelFileNode *) bufptr; + bufptr += MAXALIGN(xlrec->nabortrels * sizeof(RelFileNode)); - if (parsed.nrels > 0) + parsed->msgs = (SharedInvalidationMessage *) bufptr; + bufptr += MAXALIGN(xlrec->ninvalmsgs * sizeof(SharedInvalidationMessage)); +} + +static void +xact_desc_relations(StringInfo buf, char *label, int nrels, + RelFileNode *xnodes) +{ + int i; + + if (nrels > 0) { - appendStringInfoString(buf, "; rels:"); - for (i = 0; i < parsed.nrels; i++) + appendStringInfo(buf, "; %s:", label); + for (i = 0; i < nrels; i++) { - char *path = relpathperm(parsed.xnodes[i], MAIN_FORKNUM); + char *path = relpathperm(xnodes[i], MAIN_FORKNUM); appendStringInfo(buf, " %s", path); pfree(path); } } - if (parsed.nsubxacts > 0) +} + +static void +xact_desc_subxacts(StringInfo buf, int nsubxacts, TransactionId *subxacts) +{ + int i; + + if (nsubxacts > 0) { appendStringInfoString(buf, "; subxacts:"); - for (i = 0; i < parsed.nsubxacts; i++) - appendStringInfo(buf, " %u", parsed.subxacts[i]); - } - if (parsed.nmsgs > 0) - { - standby_desc_invalidations( - buf, parsed.nmsgs, parsed.msgs, parsed.dbId, parsed.tsId, - XactCompletionRelcacheInitFileInval(parsed.xinfo)); + for (i = 0; i < nsubxacts; i++) + appendStringInfo(buf, " %u", subxacts[i]); } +} + +static void +xact_desc_commit(StringInfo buf, uint8 info, xl_xact_commit *xlrec, RepOriginId origin_id) +{ + xl_xact_parsed_commit parsed; + + ParseCommitRecord(info, xlrec, &parsed); + + /* If this is a prepared xact, show the xid of the original xact */ + if (TransactionIdIsValid(parsed.twophase_xid)) + appendStringInfo(buf, "%u: ", parsed.twophase_xid); + + appendStringInfoString(buf, timestamptz_to_str(xlrec->xact_time)); + + xact_desc_relations(buf, "rels", parsed.nrels, parsed.xnodes); + xact_desc_subxacts(buf, parsed.nsubxacts, parsed.subxacts); + + standby_desc_invalidations( + buf, parsed.nmsgs, parsed.msgs, parsed.dbId, parsed.tsId, + XactCompletionRelcacheInitFileInval(parsed.xinfo)); if (XactCompletionForceSyncCommit(parsed.xinfo)) appendStringInfoString(buf, "; sync"); @@ -264,7 +316,6 @@ static void xact_desc_abort(StringInfo buf, uint8 info, xl_xact_abort *xlrec) { xl_xact_parsed_abort parsed; - int i; ParseAbortRecord(info, xlrec, &parsed); @@ -273,24 +324,29 @@ xact_desc_abort(StringInfo buf, uint8 info, xl_xact_abort *xlrec) appendStringInfo(buf, "%u: ", parsed.twophase_xid); appendStringInfoString(buf, timestamptz_to_str(xlrec->xact_time)); - if (parsed.nrels > 0) - { - appendStringInfoString(buf, "; rels:"); - for (i = 0; i < parsed.nrels; i++) - { - char *path = relpathperm(parsed.xnodes[i], MAIN_FORKNUM); - appendStringInfo(buf, " %s", path); - pfree(path); - } - } + xact_desc_relations(buf, "rels", parsed.nrels, parsed.xnodes); + xact_desc_subxacts(buf, parsed.nsubxacts, parsed.subxacts); +} - if (parsed.nsubxacts > 0) - { - appendStringInfoString(buf, "; subxacts:"); - for (i = 0; i < parsed.nsubxacts; i++) - appendStringInfo(buf, " %u", parsed.subxacts[i]); - } +static void +xact_desc_prepare(StringInfo buf, uint8 info, xl_xact_prepare *xlrec) +{ + xl_xact_parsed_prepare parsed; + + ParsePrepareRecord(info, xlrec, &parsed); + + appendStringInfo(buf, "gid %s: ", parsed.twophase_gid); + appendStringInfoString(buf, timestamptz_to_str(parsed.xact_time)); + + xact_desc_relations(buf, "rels(commit)", parsed.nrels, parsed.xnodes); + xact_desc_relations(buf, "rels(abort)", parsed.nabortrels, + parsed.abortnodes); + xact_desc_subxacts(buf, parsed.nsubxacts, parsed.subxacts); + + standby_desc_invalidations( + buf, parsed.nmsgs, parsed.msgs, parsed.dbId, parsed.tsId, + xlrec->initfileinval); } static void @@ -323,6 +379,12 @@ xact_desc(StringInfo buf, XLogReaderState *record) xact_desc_abort(buf, XLogRecGetInfo(record), xlrec); } + else if (info == XLOG_XACT_PREPARE) + { + xl_xact_prepare *xlrec = (xl_xact_prepare *) rec; + + xact_desc_prepare(buf, XLogRecGetInfo(record), xlrec); + } else if (info == XLOG_XACT_ASSIGNMENT) { xl_xact_assignment *xlrec = (xl_xact_assignment *) rec; diff --git a/src/backend/access/transam/twophase.c b/src/backend/access/transam/twophase.c index 712e842b904..b3ad0d08e30 100644 --- a/src/backend/access/transam/twophase.c +++ b/src/backend/access/transam/twophase.c @@ -910,23 +910,7 @@ TwoPhaseGetDummyProc(TransactionId xid, bool lock_held) */ #define TWOPHASE_MAGIC 0x57F94534 /* format identifier */ -typedef struct TwoPhaseFileHeader -{ - uint32 magic; /* format identifier */ - uint32 total_len; /* actual file length */ - TransactionId xid; /* original transaction XID */ - Oid database; /* OID of database it was in */ - TimestampTz prepared_at; /* time of preparation */ - Oid owner; /* user running the transaction */ - int32 nsubxacts; /* number of following subxact XIDs */ - int32 ncommitrels; /* number of delete-on-commit rels */ - int32 nabortrels; /* number of delete-on-abort rels */ - int32 ninvalmsgs; /* number of cache invalidation messages */ - bool initfileinval; /* does relcache init file need invalidation? */ - uint16 gidlen; /* length of the GID - GID follows the header */ - XLogRecPtr origin_lsn; /* lsn of this record at origin node */ - TimestampTz origin_timestamp; /* time of prepare at origin node */ -} TwoPhaseFileHeader; +typedef xl_xact_prepare TwoPhaseFileHeader; /* * Header for each record in a state file @@ -1331,44 +1315,6 @@ ReadTwoPhaseFile(TransactionId xid, bool missing_ok) return buf; } -/* - * ParsePrepareRecord - */ -void -ParsePrepareRecord(uint8 info, char *xlrec, xl_xact_parsed_prepare *parsed) -{ - TwoPhaseFileHeader *hdr; - char *bufptr; - - hdr = (TwoPhaseFileHeader *) xlrec; - bufptr = xlrec + MAXALIGN(sizeof(TwoPhaseFileHeader)); - - parsed->origin_lsn = hdr->origin_lsn; - parsed->origin_timestamp = hdr->origin_timestamp; - parsed->twophase_xid = hdr->xid; - parsed->dbId = hdr->database; - parsed->nsubxacts = hdr->nsubxacts; - parsed->nrels = hdr->ncommitrels; - parsed->nabortrels = hdr->nabortrels; - parsed->nmsgs = hdr->ninvalmsgs; - - strncpy(parsed->twophase_gid, bufptr, hdr->gidlen); - bufptr += MAXALIGN(hdr->gidlen); - - parsed->subxacts = (TransactionId *) bufptr; - bufptr += MAXALIGN(hdr->nsubxacts * sizeof(TransactionId)); - - parsed->xnodes = (RelFileNode *) bufptr; - bufptr += MAXALIGN(hdr->ncommitrels * sizeof(RelFileNode)); - - parsed->abortnodes = (RelFileNode *) bufptr; - bufptr += MAXALIGN(hdr->nabortrels * sizeof(RelFileNode)); - - parsed->msgs = (SharedInvalidationMessage *) bufptr; - bufptr += MAXALIGN(hdr->ninvalmsgs * sizeof(SharedInvalidationMessage)); -} - - /* * Reads 2PC data from xlog. During checkpoint this data will be moved to diff --git a/src/include/access/twophase.h b/src/include/access/twophase.h index b9a531c96e3..1093085a242 100644 --- a/src/include/access/twophase.h +++ b/src/include/access/twophase.h @@ -47,8 +47,6 @@ extern bool StandbyTransactionIdIsPrepared(TransactionId xid); extern TransactionId PrescanPreparedTransactions(TransactionId **xids_p, int *nxids_p); -extern void ParsePrepareRecord(uint8 info, char *xlrec, - xl_xact_parsed_prepare *parsed); extern void StandbyRecoverPreparedTransactions(void); extern void RecoverPreparedTransactions(void); diff --git a/src/include/access/xact.h b/src/include/access/xact.h index d7145517047..42b76cb4dd3 100644 --- a/src/include/access/xact.h +++ b/src/include/access/xact.h @@ -292,6 +292,24 @@ typedef struct xl_xact_abort } xl_xact_abort; #define MinSizeOfXactAbort sizeof(xl_xact_abort) +typedef struct xl_xact_prepare +{ + uint32 magic; /* format identifier */ + uint32 total_len; /* actual file length */ + TransactionId xid; /* original transaction XID */ + Oid database; /* OID of database it was in */ + TimestampTz prepared_at; /* time of preparation */ + Oid owner; /* user running the transaction */ + int32 nsubxacts; /* number of following subxact XIDs */ + int32 ncommitrels; /* number of delete-on-commit rels */ + int32 nabortrels; /* number of delete-on-abort rels */ + int32 ninvalmsgs; /* number of cache invalidation messages */ + bool initfileinval; /* does relcache init file need invalidation? */ + uint16 gidlen; /* length of the GID - GID follows the header */ + XLogRecPtr origin_lsn; /* lsn of this record at origin node */ + TimestampTz origin_timestamp; /* time of prepare at origin node */ +} xl_xact_prepare; + /* * Commit/Abort records in the above form are a bit verbose to parse, so * there's a deconstructed versions generated by ParseCommit/AbortRecord() for @@ -435,6 +453,7 @@ extern const char *xact_identify(uint8 info); /* also in xactdesc.c, so they can be shared between front/backend code */ extern void ParseCommitRecord(uint8 info, xl_xact_commit *xlrec, xl_xact_parsed_commit *parsed); extern void ParseAbortRecord(uint8 info, xl_xact_abort *xlrec, xl_xact_parsed_abort *parsed); +extern void ParsePrepareRecord(uint8 info, xl_xact_prepare *xlrec, xl_xact_parsed_prepare *parsed); extern void EnterParallelMode(void); extern void ExitParallelMode(void); -- 2.39.5