Add TXFINISH optional logs

kelvich · kelvich · commit ca707816ddea · 2017-10-15T03:23:47.000+03:00
diff --git a/contrib/mmts/arbiter.c b/contrib/mmts/arbiter.c
@@ -987,6 +987,7 @@ static void MtmReceiver(Datum arg)
 										 msg->gid, MtmTxnStatusMnem[msg->status], node);
 
 									replorigin_session_origin = DoNotReplicateId;
+									TXFINISH("%s ABORT, MSG_POLL_STATUS", msg->gid);
 									MtmFinishPreparedTransaction(ts, false);
 									replorigin_session_origin = InvalidRepOriginId;
 								} 
@@ -1000,6 +1001,7 @@ static void MtmReceiver(Datum arg)
 										MTM_ELOG(LOG, "Commit transaction %s because it is prepared at all live nodes", msg->gid);		
 
 										replorigin_session_origin = DoNotReplicateId;
+										TXFINISH("%s COMMIT, MSG_POLL_STATUS", msg->gid);
 										MtmFinishPreparedTransaction(ts, true);
 										replorigin_session_origin = InvalidRepOriginId;
 									} else { 
diff --git a/contrib/mmts/multimaster.c b/contrib/mmts/multimaster.c
@@ -1973,10 +1973,12 @@ void MtmPollStatusOfPreparedTransactionsForDisabledNode(int disabledNodeId, bool
 			Assert(ts->gid[0]);
 			if (ts->status == TRANSACTION_STATUS_IN_PROGRESS) {
 				MTM_ELOG(LOG, "Abort transaction %s because its coordinator is disabled and it is not prepared at node %d", ts->gid, MtmNodeId);
+				TXFINISH("%s ABORT, PollStatusOfPrepared", ts->gid);
 				MtmFinishPreparedTransaction(ts, false);
 			} else {
 				if (commitPrecommited)
 				{
+					TXFINISH("%s COMMIT, PollStatusOfPrepared", ts->gid);
 					MtmFinishPreparedTransaction(ts, true);
 				}
 				else
@@ -3309,6 +3311,7 @@ void MtmRollbackPreparedTransaction(int nodeId, char const* gid)
 		StartTransactionCommand();
 		MtmBeginSession(nodeId);
 		MtmSetCurrentTransactionGID(gid);
+		TXFINISH("%s ABORT, MtmRollbackPrepared", gid);
 		FinishPreparedTransaction(gid, false);
 		MtmTx.isActive = true;
 		CommitTransactionCommand();
@@ -4592,9 +4595,11 @@ static bool MtmTwoPhaseCommit(MtmCurrentTrans* x)
 					ts = (MtmTransState*) hash_search(MtmXid2State, &(x->xid), HASH_FIND, NULL);
 					Assert(ts);
 
+					TXFINISH("%s ABORT, MtmTwoPhase", x->gid);
 					FinishPreparedTransaction(x->gid, false);
 					MTM_ELOG(ERROR, "Transaction %s (%llu) is aborted on node %d. Check its log to see error details.", x->gid, (long64)x->xid, ts->abortedByNode);
 				} else {
+					TXFINISH("%s COMMIT, MtmTwoPhase", x->gid);
 					FinishPreparedTransaction(x->gid, true);
 					MTM_TXTRACE(x, "MtmTwoPhaseCommit Committed");
 					MTM_LOG2("Distributed transaction %s (%lld) is committed at %lld with LSN=%lld", x->gid, (long64)x->xid, MtmGetCurrentTime(), (long64)GetXLogInsertRecPtr());
diff --git a/contrib/mmts/multimaster.h b/contrib/mmts/multimaster.h
@@ -41,6 +41,14 @@
 #define MTM_LOG4(fmt, ...) fprintf(stderr, fmt "\n", ## __VA_ARGS__)
 #endif
 
+// #define MTM_TXFINISH 1
+
+#ifndef MTM_TXFINISH
+#define TXFINISH(fmt, ...)
+#else
+#define TXFINISH(fmt, ...) elog(LOG, MTM_TAG "[TXFINISH] " fmt, ## __VA_ARGS__)
+#endif
+
 // #define MTM_TRACE 1
 
 #ifndef MTM_TRACE
diff --git a/contrib/mmts/pglogical_apply.c b/contrib/mmts/pglogical_apply.c
@@ -726,6 +726,7 @@ process_remote_commit(StringInfo in)
 					MTM_LOG1("Perform delayed rollback of prepared global transaction %s", gid);	
 					StartTransactionCommand();
 					MtmSetCurrentTransactionGID(gid);
+					TXFINISH("%s ABORT, PGLOGICAL_PREPARE", gid);
 					FinishPreparedTransaction(gid, false);
 					CommitTransactionCommand();					
 					Assert(!MtmTransIsActive());
@@ -755,6 +756,7 @@ process_remote_commit(StringInfo in)
 			else
 				MtmSetCurrentTransactionCSN(csn);
 			MtmSetCurrentTransactionGID(gid);
+			TXFINISH("%s COMMIT, PGLOGICAL_COMMIT_PREPARED csn=%lld", gid, csn);
 			FinishPreparedTransaction(gid, true);
 			MTM_LOG2("Distributed transaction %s is committed", gid);
 			CommitTransactionCommand();
