SERVER-37553 Log sending and receiving every message in the transaction two phase commit protocol

1 files changed, 29 insertions, 1 deletions

diff --git a/src/mongo/db/s/txn_two_phase_commit_cmds.cpp b/src/mongo/db/s/txn_two_phase_commit_cmds.cpp
index 0cc017ac341..118108f81c1 100644
--- a/src/mongo/db/s/txn_two_phase_commit_cmds.cpp
+++ b/src/mongo/db/s/txn_two_phase_commit_cmds.cpp
@@ -69,6 +69,11 @@ public:
         using InvocationBase::InvocationBase;
 
         Response typedRun(OperationContext* opCtx) {
+            LOG(3)
+                << "Participant shard received prepareTransaction for transaction with txnNumber "
+                << opCtx->getTxnNumber() << " on session "
+                << opCtx->getLogicalSessionId()->toBSON();
+
             // In production, only config servers or initialized shard servers can participate in a
             // sharded transaction. However, many test suites test the replication and storage parts
             // of prepareTransaction against a standalone replica set, so allow skipping the check.
@@ -174,6 +179,8 @@ public:
                 // TODO (SERVER-37328): Participant should wait for writeConcern before sending its
                 // vote.
 
+                LOG(3) << "Participant shard sending " << voteObj << " to " << coordinatorId;
+
                 const auto coordinatorPrimaryHost = [&] {
                     auto coordinatorShard = uassertStatusOK(
                         Grid::get(opCtx)->shardRegistry()->getShard(opCtx, coordinatorId));
@@ -194,7 +201,7 @@ public:
                     Grid::get(opCtx)->getExecutorPool()->getFixedExecutor()->scheduleRemoteCommand(
                         request, noOp));
             } catch (const DBException& ex) {
-                LOG(0) << "Failed to send vote " << voteObj << " to " << coordinatorId
+                LOG(3) << "Participant shard failed to send " << voteObj << " to " << coordinatorId
                        << causedBy(ex.toStatus());
             }
         }
@@ -245,6 +252,11 @@ public:
 
             const auto& cmd = request();
 
+            LOG(3) << "Coordinator shard received voteCommit from " << cmd.getShardId()
+                   << " with prepare timestamp " << cmd.getPrepareTimestamp() << " for transaction "
+                   << opCtx->getTxnNumber() << " on session "
+                   << opCtx->getLogicalSessionId()->toBSON();
+
             TransactionCoordinatorService::get(opCtx)->voteCommit(
                 opCtx,
                 opCtx->getLogicalSessionId().get(),
@@ -299,6 +311,10 @@ public:
 
             const auto& cmd = request();
 
+            LOG(3) << "Coordinator shard received voteAbort from " << cmd.getShardId()
+                   << " for transaction " << opCtx->getTxnNumber() << " on session "
+                   << opCtx->getLogicalSessionId()->toBSON();
+
             TransactionCoordinatorService::get(opCtx)->voteAbort(opCtx,
                                                                  opCtx->getLogicalSessionId().get(),
                                                                  opCtx->getTxnNumber().get(),
@@ -357,6 +373,8 @@ public:
             // the list are unique.
             // TODO (PM-564): Propagate the 'readOnly' flag down into the TransactionCoordinator.
             std::set<ShardId> participantList;
+            StringBuilder ss;
+            ss << "[";
             for (const auto& participant : cmd.getParticipants()) {
                 const auto shardId = participant.getShardId();
                 uassert(ErrorCodes::InvalidOptions,
@@ -364,7 +382,12 @@ public:
                         std::find(participantList.begin(), participantList.end(), shardId) ==
                             participantList.end());
                 participantList.insert(shardId);
+                ss << shardId << " ";
             }
+            ss << "]";
+            LOG(3) << "Coordinator shard received participant list with shards " << ss.str()
+                   << " for transaction " << opCtx->getTxnNumber() << " on session "
+                   << opCtx->getLogicalSessionId()->toBSON();
 
             auto commitDecisionFuture = TransactionCoordinatorService::get(opCtx)->coordinateCommit(
                 opCtx,
@@ -411,6 +434,11 @@ public:
                 return prepareTimestamp;
             }();
 
+            LOG(3) << "Participant shard delivering voteCommit with prepareTimestamp "
+                   << localParticipantPrepareTimestamp << " to local coordinator for transaction "
+                   << opCtx->getTxnNumber() << " on session "
+                   << opCtx->getLogicalSessionId()->toBSON();
+
             // Deliver the local participant's vote to the coordinator.
             TransactionCoordinatorService::get(opCtx)->voteCommit(
                 opCtx,