8000 Add more traces · postgrespro/postgres_cluster@ac0afb1 · GitHub
[go: up one dir, main page]
Skip to content

Navigation Menu

Sign in
Appearance settings

Search code, repositories, users, issues, pull requests...

Provide feedback

We read every piece of feedback, and take your input very seriously.

Saved searches

Use saved searches to filter your results more quickly
Appearance settings

Commit ac0afb1

Browse files
knizhnikknizhnik
committed
Add more traces
1 parent 0b9c386 commit ac0afb1

File tree

3 files changed

+34
-25
lines changed

3 files changed

+34
-25
lines changed

‎contrib/mmts/multimaster.c

Lines changed: 29 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -695,20 +695,18 @@ MtmCreateTransState(MtmCurrentTrans* x)
695695
{
696696
bool found;
697697
MtmTransState* ts = hash_search(MtmXid2State, &x->xid, HASH_ENTER, &found);
698-
if (!found) {
699-
ts->status = TRANSACTION_STATUS_IN_PROGRESS;
700-
ts->snapshot = x->snapshot;
701-
ts->isLocal = true;
702-
if (TransactionIdIsValid(x->gtid.xid)) {
703-
Assert(x->gtid.node != MtmNodeId);
704-
ts->gtid = x->gtid;
705-
strcpy(ts->gid, x->gid);
706-
} else {
707-
/* I am coordinator of transaction */
708-
ts->gtid.xid = x->xid;
709-
ts->gtid.node = MtmNodeId;
710-
ts->gid[0] = '\0';
711-
}
698+
ts->status = TRANSACTION_STATUS_IN_PROGRESS;
699+
ts->snapshot = x->snapshot;
700+
ts->isLocal = true;
701+
if (TransactionIdIsValid(x->gtid.xid)) {
702+
Assert(x->gtid.node != MtmNodeId);
703+
ts->gtid = x->gtid;
704+
strcpy(ts->gid, x->gid);
705+
} else {
706+
/* I am coordinator of transaction */
707+
ts->gtid.xid = x->xid;
708+
ts->gtid.node = MtmNodeId;
709+
ts->gid[0] = '\0';
712710
}
713711
return ts;
714712
}
@@ -854,11 +852,11 @@ MtmPostPrepareTransaction(MtmCurrentTrans* x)
854852
if (!ts->votingCompleted) {
855853
if (ts->status != TRANSACTION_STATUS_ABORTED) {
856854
MtmAbortTransaction(ts);
857-
elog(WARNING, "Transaction is aborted because of %d msec timeout expiration, prepare time %d msec", (int)transTimeout, (int)USEC_TO_MSEC(ts->csn - x->snapshot));
855+
elog(WARNING, "Transaction %d is aborted because of %d msec timeout expiration, prepare time %d msec", x->xid, (int)transTimeout, (int)USEC_TO_MSEC(ts->csn - x->snapshot));
858856
}
859857
} else if (nConfigChanges != Mtm->nConfigChanges) {
860858
MtmAbortTransaction(ts);
861-
elog(WARNING, "Transaction is aborted because cluster configuration is changed during commit");
859+
elog(WARNING, "Transaction %d is aborted because cluster configuration is changed during commit", x->xid);
862860
}
863861
x->status = ts->status;
864862
MTM_LOG3("%d: Result of vote: %d", MyProcPid, ts->status);
@@ -880,9 +878,12 @@ MtmAbortPreparedTransaction(MtmCurrentTrans* x)
880878
MtmLock(LW_EXCLUSIVE);
881879
tm = (MtmTransMap*)hash_search(MtmGid2State, x->gid, HASH_REMOVE, NULL);
882880
Assert(tm != NULL);
881+
MTM_LOG1("Abort prepared transaction %d with gid='%s' is already aborted", x->xid, x->gid);
883882
MtmAbortTransaction(tm->state);
884883
MtmUnlock();
885884
x->status = TRANSACTION_STATUS_ABORTED;
885+
} else {
886+
MTM_LOG1("Transaction %d with gid='%s' is already aborted", x->xid, x->gid);
886887
}
887888
}
888889

@@ -918,6 +919,7 @@ MtmEndTransaction(MtmCurrentTrans* x, bool commit)
918919
Assert(Mtm->nActiveTransactions != 0);
919920
Mtm->nActiveTransactions -= 1;
920921
} else {
922+
MTM_LOG1("%d: abort transaction %d gid='%s' is called from MtmEndTransaction", MyProcPid, x->xid, x->gid);
921923
MtmAbortTransaction(ts);
922924
}
923925
}
@@ -998,7 +1000,7 @@ void MtmJoinTransaction(GlobalTransactionId* gtid, csn_t globalSnapshot)
9981000

9991001
void MtmSetCurrentTransactionGID(char const* gid)
10001002
{
1001-
MTM_LOG3("Set current transaction GID %s", gid);
1003+
MTM_LOG3("Set current transaction xid=%d GID %s", MtmTx.xid, gid);
10021004
strcpy(MtmTx.gid, gid);
10031005
MtmTx.isDistributed = true;
10041006
MtmTx.isReplicated = true;
@@ -1383,15 +1385,21 @@ bool MtmRefreshClusterStatus(bool nowait)
13831385
MtmCheckQuorum();
13841386
/* Interrupt voting for active transaction and abort them */
13851387
for (ts = Mtm->transListHead; ts != NULL; ts = ts->next) {
1388+
MTM_LOG3("Active transaction gid='%s', coordinator=%d, xid=%d, status=%d, gtid.xid=%d",
1389+
ts->gid, ts->gtid.node, ts->xid, ts->status, ts->gtid.xid);
13861390
if (MtmIsCoordinator(ts)) {
13871391
if (!ts->votingCompleted && ts->status != TRANSACTION_STATUS_ABORTED) {
13881392
MtmAbortTransaction(ts);
13891393
MtmWakeUpBackend(ts);
13901394
}
13911395
} else if (TransactionIdIsValid(ts->gtid.xid) && BIT_CHECK(disabled, ts->gtid.node-1)) { // coordinator of transaction is on disabled node
1392-
if (ts->gid[0] && ts->status != TRANSACTION_STATUS_ABORTED) {
1393-
MtmAbortTransaction(ts);
1394-
FinishPreparedTransaction(ts->gid, false);
1396+
if (ts->gid[0]) {
1397+
if (ts->status == TRANSACTION_STATUS_UNKNOWN || ts->status == TRANSACTION_STATUS_IN_PROGRESS) {
1398+
MTM_LOG1("%d: Abort trasaction %s because its coordinator is at disabled node %d", MyProcPid, ts->gid, ts->gtid.node);
1399+
MtmAbortTransaction(ts);
1400+
MtmTx.status = TRANSACTION_STATUS_ABORTED; /* prevent recursive invocation of MtmAbortPreparedTransaction */
1401+
FinishPreparedTransaction(ts->gid, false);
1402+
}
13951403
}
13961404
}
13971405
}
@@ -1461,6 +1469,7 @@ void MtmOnNodeDisconnect(int nodeId)
14611469
} else if (TransactionIdIsValid(ts->gtid.xid) && ts->gtid.node == nodeId) { //coordinator of transaction is on disabled node
14621470
if (ts->gid[0] && ts->status != TRANSACTION_STATUS_ABORTED) {
14631471
MtmAbortTransaction(ts);
1472+
MtmTx.status = TRANSACTION_STATUS_ABORTED; /* prevent recursive invocation of MtmAbortPreparedTransaction */
14641473
FinishPreparedTransaction(ts->gid, false);
14651474
}
14661475
}

‎contrib/mmts/pglogical_apply.c

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -524,7 +524,7 @@ process_remote_commit(StringInfo in)
524524
{
525525
case PGLOGICAL_COMMIT:
526526
{
527-
MTM_LOG3("%d: PGLOGICAL_COMMIT commit", MyProcPid);
527+
MTM_LOG1("%d: PGLOGICAL_COMMIT commit", MyProcPid);
528528
if (IsTransactionState()) {
529529
Assert(TransactionIdIsValid(MtmGetCurrentTransactionId()));
530530
MtmBeginSession();
@@ -537,7 +537,7 @@ process_remote_commit(StringInfo in)
537537
Assert(IsTransactionState() && TransactionIdIsValid(MtmGetCurrentTransactionId()));
538538
gid = pq_getmsgstring(in);
539539
/* prepare TBLOCK_INPROGRESS state for PrepareTransactionBlock() */
540-
MTM_LOG3("%d: PGLOGICAL_PREPARE commit: gid=%s", MyProcPid, gid);
540+
MTM_LOG1("%d: PGLOGICAL_PREPARE commit: gid=%s", MyProcPid, gid);
541541
BeginTransactionBlock();
542542
CommitTransactionCommand();
543543
StartTransactionCommand();
@@ -554,7 +554,7 @@ process_remote_commit(StringInfo in)
554554
Assert(!TransactionIdIsValid(MtmGetCurrentTransactionId()));
555555
csn = pq_getmsgint64(in);
556556
gid = pq_getmsgstring(in);
557-
MTM_LOG3("%d: PGLOGICAL_COMMIT_PREPARED commit: csn=%ld, gid=%s", MyProcPid, csn, gid);
557+
MTM_LOG1("%d: PGLOGICAL_COMMIT_PREPARED commit: csn=%ld, gid=%s", MyProcPid, csn, gid);
558558
StartTransactionCommand();
559559
MtmBeginSession();
560560
MtmSetCurrentTransactionCSN(csn);
@@ -567,7 +567,7 @@ process_remote_commit(StringInfo in)
567567
{
568568
Assert(!TransactionIdIsValid(MtmGetCurrentTransactionId()));
569569
gid = pq_getmsgstring(in);
570-
MTM_LOG2("%d: PGLOGICAL_ABORT_PREPARED commit: gid=%s", MyProcPid, gid);
570+
MTM_LOG1("%d: PGLOGICAL_ABORT_PREPARED commit: gid=%s", MyProcPid, gid);
571571
if (MtmGetGlobalTransactionStatus(gid) != TRANSACTION_STATUS_ABORTED) {
572572
MTM_LOG2("%d: PGLOGICAL_ABORT_PREPARED commit: gid=%s #2", MyProcPid, gid);
573573
StartTransactionCommand();

‎contrib/mmts/pglogical_proto.c

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -160,7 +160,7 @@ pglogical_write_commit(StringInfo out, PGLogicalOutputData *data,
160160
}
161161
pq_sendbyte(out, 'C'); /* sending COMMIT */
162162

163-
MTM_LOG2("PGLOGICAL_SEND commit: event=%d, gid=%s, commit_lsn=%lx, txn->end_lsn=%lx, xlog=%lx", flags, txn->gid, commit_lsn, txn->end_lsn, GetXLogInsertRecPtr());
163+
MTM_LOG1("%ld: PGLOGICAL_SEND commit: event=%d, gid=%s, commit_lsn=%lx, txn->end_lsn=%lx, xlog=%lx", MtmGetSystemTime(), flags, txn->gid, commit_lsn, txn->end_lsn, GetXLogInsertRecPtr());
164164

165165
/* send the flags field */
166166
pq_sendbyte(out, flags);

0 commit comments

Comments
 (0)
0