Message-ID: <53D62059.6060304@vmware.com>
Date: Mon, 28 Jul 2014 13:05:13 +0300
From: Heikki Linnakangas <hlinnakangas@vmware.com>
Organization: VMware
User-Agent: Mozilla/5.0 (X11; Linux x86_64;
 rv:24.0) Gecko/20100101 Icedove/24.5.0
MIME-Version: 1.0
To: Tom Lane <tgl@sss.pgh.pa.us>, Andres Freund <andres@2ndquadrant.com>
CC: <s.zuban@gmail.com>, <pgsql-bugs@postgresql.org>
Subject: Re: BUG #11032: Prepared transactions do not update
 pg_last_xact_replay_timestamp() anymore
References: <20140724191127.32089.82261@wrigleys.postgresql.org>
 <20429.1406238373@sss.pgh.pa.us> <20140724215743.GG16857@alap3.anarazel.de>
 <21266.1406241129@sss.pgh.pa.us> <20140724223459.GI16857@alap3.anarazel.de>
 <21620.1406242232@sss.pgh.pa.us>
In-Reply-To: <21620.1406242232@sss.pgh.pa.us>
Content-Type: multipart/mixed; boundary="------------050505010807020007030400"
Precedence: bulk
Sender: pgsql-bugs-owner@postgresql.org

--------------050505010807020007030400
Content-Type: text/plain; charset="ISO-8859-1"; format=flowed
Content-Transfer-Encoding: 7bit

On 07/25/2014 01:50 AM, Tom Lane wrote:
> Andres Freund <andres@2ndquadrant.com> writes:
>> Afaics before the commit a LockGXact() did a GetTopTransactionId(),
>> afterwards it doesn't anymore. That'd fit, right?
>
> Ah, I think you've got it.

Yep. The extra commit record masked the issue that getRecordTimestamp() 
ignores commit/abort prepared records.

>  Now I'm worried.  I have a very vague
> recollection that that behavior (forcing our own COMMIT to be written
> after a COMMIT PREPARED) was intentional.  I don't recall exactly
> why though.

Hmm. I've always considered it just a quirk that we didn't bother to fix 
when two-phase commit was implemented, because it would've required more 
invasive code changes. But the code has since moved on - not all 
transactions are assigned an XID anymore - and now it was 
straightforward to fix that quirk.

It wouldn't surprise me much though, if we find more little things like 
this that were previously masked by the extra commit record:

At a quick glance, the recovery_min_apply_delay code in xlog.c seems to 
be oblivious of prepared transactions. Now that we no longer write the 
normal COMMIT record after a COMMIT_PREPARED record, that's become 
worse, but it was always wrong. The COMMIT_PREPARED record would always 
be applied immediately, regardless of recovery_min_apply_delay, although 
we would then pause at the commit record that follows. The 
recovery_target_xid handling also ignores prepared transactions.

> xact.h points out
>
> /*
>   * COMMIT_PREPARED and ABORT_PREPARED are identical to COMMIT/ABORT records
>   * except that we have to store the XID of the prepared transaction explicitly
>   * --- the XID in the record header will be for the transaction doing the
>   * COMMIT PREPARED or ABORT PREPARED command.
>   */
>
> and what this change means is that there isn't actually any valid XID in
> the record header, which at least means that comment needs an update.
> But I'm concerned about the knock-on aspects of that.  In particular
> I wonder if we were expecting commit of the surrounding transaction to
> result in a WAL flush or anything like that.  The proposal you made
> recently to not sync non-XID-assigning WAL records would affect this.

RecordTransactionCommitPrepared calls XLogFlush() and 
SyncRepWaitForLSN(), so those particular things are covered.

We probably should set XLogRecord->xl_xid in COMMIT_/ABORT_PREPARED 
records though. It seems weird not to, and it would simplify code that 
interprets those records. But I don't think we should back-patch that.

> As far as the timestamp aspects go, I wonder if we were thinking that
> commit/abort prepared might contain stale timestamps by design.  They
> don't --- in the current coding, the timestamp is the time of creating the
> WAL record, not of the prepare --- but it's not that hard to imagine that
> time-of-prepare might have been the original intent.

Time-of-commit makes much more sense to me. The transaction doesn't 
appear as committed to other transactions until it's committed, 
regardless of when it prepared.

It surprises me that there is no timestamp at all in the prepare-record 
though. That could be very useful information, if you wanted to monitor 
the delay between prepare and commit, for example. But that's another issue.

I propose the attached (untested) patch that fixes the issues mentioned 
this far. I'll set up streaming replication and test 
recovery_target_xid, recovery_min_apply_delay, and 
pg_last_xact_replay_timestamp() with the patch, and barring 
objections/bugs, commit and backpatch. For master branch, I'll 
investigate how hacky it would be to set XLogRecord->xl_xid to the XID 
of the prepared transaction.

- Heikki


--------------050505010807020007030400
Content-Type: text/x-diff; name="fix-commit-abort-prepared-oversights-1.patch"
Content-Transfer-Encoding: 7bit
Content-Disposition: attachment;
 filename="fix-commit-abort-prepared-oversights-1.patch"

diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index 93f3ca2..2bf49a8 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -5457,11 +5457,21 @@ getRecordTimestamp(XLogRecord *record, TimestampTz *recordXtime)
 		*recordXtime = ((xl_xact_commit *) XLogRecGetData(record))->xact_time;
 		return true;
 	}
+	if (record->xl_rmid == RM_XACT_ID && record_info == XLOG_XACT_COMMIT_PREPARED)
+	{
+		*recordXtime = ((xl_xact_commit_prepared *) XLogRecGetData(record))->crec.xact_time;
+		return true;
+	}
 	if (record->xl_rmid == RM_XACT_ID && record_info == XLOG_XACT_ABORT)
 	{
 		*recordXtime = ((xl_xact_abort *) XLogRecGetData(record))->xact_time;
 		return true;
 	}
+	if (record->xl_rmid == RM_XACT_ID && record_info == XLOG_XACT_ABORT_PREPARED)
+	{
+		*recordXtime = ((xl_xact_abort_prepared *) XLogRecGetData(record))->arec.xact_time;
+		return true;
+	}
 	return false;
 }
 
@@ -5480,6 +5490,7 @@ recoveryStopsBefore(XLogRecord *record)
 	uint8		record_info;
 	bool		isCommit;
 	TimestampTz recordXtime = 0;
+	TransactionId recordXid;
 
 	/* Check if we should stop as soon as reaching consistency */
 	if (recoveryTarget == RECOVERY_TARGET_IMMEDIATE && reachedConsistency)
@@ -5498,10 +5509,27 @@ recoveryStopsBefore(XLogRecord *record)
 	if (record->xl_rmid != RM_XACT_ID)
 		return false;
 	record_info = record->xl_info & ~XLR_INFO_MASK;
+
 	if (record_info == XLOG_XACT_COMMIT_COMPACT || record_info == XLOG_XACT_COMMIT)
+	{
+		isCommit = true;
+		recordXid = record->xl_xid;
+	}
+	if (record_info == XLOG_XACT_COMMIT_PREPARED)
+	{
 		isCommit = true;
+		recordXid = ((xl_xact_commit_prepared *) XLogRecGetData(record))->xid;
+	}
 	else if (record_info == XLOG_XACT_ABORT)
+	{
+		isCommit = false;
+		recordXid = record->xl_xid;
+	}
+	else if (record_info == XLOG_XACT_ABORT_PREPARED)
+	{
 		isCommit = false;
+		recordXid = ((xl_xact_abort_prepared *) XLogRecGetData(record))->xid;
+	}
 	else
 		return false;
 
@@ -5516,7 +5544,7 @@ recoveryStopsBefore(XLogRecord *record)
 		 * they complete. A higher numbered xid will complete before you about
 		 * 50% of the time...
 		 */
-		stopsHere = (record->xl_xid == recoveryTargetXid);
+		stopsHere = (recordXid == recoveryTargetXid);
 	}
 
 	if (recoveryTarget == RECOVERY_TARGET_TIME &&
@@ -5536,7 +5564,7 @@ recoveryStopsBefore(XLogRecord *record)
 	if (stopsHere)
 	{
 		recoveryStopAfter = false;
-		recoveryStopXid = record->xl_xid;
+		recoveryStopXid = recordXid;
 		recoveryStopTime = recordXtime;
 		recoveryStopName[0] = '\0';
 
@@ -5602,12 +5630,24 @@ recoveryStopsAfter(XLogRecord *record)
 	if (record->xl_rmid == RM_XACT_ID &&
 		(record_info == XLOG_XACT_COMMIT_COMPACT ||
 		 record_info == XLOG_XACT_COMMIT ||
-		 record_info == XLOG_XACT_ABORT))
+		 record_info == XLOG_XACT_COMMIT_PREPARED ||
+		 record_info == XLOG_XACT_ABORT ||
+		 record_info == XLOG_XACT_ABORT_PREPARED))
 	{
+		TransactionId recordXid;
+
 		/* Update the last applied transaction timestamp */
 		if (getRecordTimestamp(record, &recordXtime))
 			SetLatestXTime(recordXtime);
 
+		/* Extract the XID of the committed/aborted transaction */
+		if (record_info == XLOG_XACT_COMMIT_PREPARED)
+			recordXid = ((xl_xact_commit_prepared *) XLogRecGetData(record))->xid;
+		else if (record_info == XLOG_XACT_ABORT_PREPARED)
+			recordXid = ((xl_xact_abort_prepared *) XLogRecGetData(record))->xid;
+		else
+			recordXid = record->xl_xid;
+
 		/*
 		 * There can be only one transaction end record with this exact
 		 * transactionid
@@ -5618,21 +5658,24 @@ recoveryStopsAfter(XLogRecord *record)
 		 * 50% of the time...
 		 */
 		if (recoveryTarget == RECOVERY_TARGET_XID && recoveryTargetInclusive &&
-			record->xl_xid == recoveryTargetXid)
+			recordXid == recoveryTargetXid)
 		{
 			recoveryStopAfter = true;
-			recoveryStopXid = record->xl_xid;
+			recoveryStopXid = recordXid;
 			recoveryStopTime = recordXtime;
 			recoveryStopName[0] = '\0';
 
-			if (record_info == XLOG_XACT_COMMIT_COMPACT || record_info == XLOG_XACT_COMMIT)
+			if (record_info == XLOG_XACT_COMMIT_COMPACT ||
+				record_info == XLOG_XACT_COMMIT ||
+				record_info == XLOG_XACT_COMMIT_PREPARED)
 			{
 				ereport(LOG,
 						(errmsg("recovery stopping after commit of transaction %u, time %s",
 								recoveryStopXid,
 								timestamptz_to_str(recoveryStopTime))));
 			}
-			else if (record_info == XLOG_XACT_ABORT)
+			else if (record_info == XLOG_XACT_ABORT ||
+					 record_info == XLOG_XACT_ABORT_PREPARED)
 			{
 				ereport(LOG,
 						(errmsg("recovery stopping after abort of transaction %u, time %s",
@@ -5745,7 +5788,8 @@ recoveryApplyDelay(XLogRecord *record)
 	record_info = record->xl_info & ~XLR_INFO_MASK;
 	if (!(record->xl_rmid == RM_XACT_ID &&
 		  (record_info == XLOG_XACT_COMMIT_COMPACT ||
-		   record_info == XLOG_XACT_COMMIT)))
+		   record_info == XLOG_XACT_COMMIT ||
+		   record_info == XLOG_XACT_COMMIT_PREPARED)))
 		return false;
 
 	if (!getRecordTimestamp(record, &xtime))
diff --git a/src/include/access/xact.h b/src/include/access/xact.h
index 10ee943..2168dc3 100644
--- a/src/include/access/xact.h
+++ b/src/include/access/xact.h
@@ -180,8 +180,7 @@ typedef struct xl_xact_abort
 /*
  * COMMIT_PREPARED and ABORT_PREPARED are identical to COMMIT/ABORT records
  * except that we have to store the XID of the prepared transaction explicitly
- * --- the XID in the record header will be for the transaction doing the
- * COMMIT PREPARED or ABORT PREPARED command.
+ * --- the XID in the record header will be invalid.
  */
 
 typedef struct xl_xact_commit_prepared

--------------050505010807020007030400
Content-Type: text/plain
Content-Disposition: inline
Content-Transfer-Encoding: 8bit
MIME-Version: 1.0


-- 
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs

--------------050505010807020007030400--