SERVER-35302 Added startWallClockTime to CurrentOp's transaction sub-document

4 files changed, 62 insertions, 20 deletions

diff --git a/jstests/noPassthrough/currentop_active_transaction.js b/jstests/noPassthrough/currentop_active_transaction.js
index c254ff63cbc..ed711acb6cc 100644
--- a/jstests/noPassthrough/currentop_active_transaction.js
+++ b/jstests/noPassthrough/currentop_active_transaction.js
@@ -32,20 +32,35 @@
         sessionDB[collName].update({}, {x: 2});
         session.commitTransaction();
     };
+
+    const timeBeforeTransactionStarts = new ISODate();
     const transactionProcess = startParallelShell(transactionFn, rst.ports[0]);
 
+    const transactionFilter = {
+        active: true,
+        'lsid': {$exists: true},
+        'transaction.parameters.txnNumber': {$eq: 0},
+        'transaction.parameters.autocommit': {$eq: false}
+    };
+
     // Keep running currentOp() until we see the transaction subdocument.
     assert.soon(function() {
-        const transactionFilter = {
-            active: true,
-            'lsid': {$exists: true},
-            'transaction.parameters.txnNumber': {$eq: 0},
-            'transaction.parameters.autocommit': {$eq: false},
-            'transaction.parameters.timeOpenMicros': {$gt: 0}
-        };
         return 1 === adminDB.aggregate([{$currentOp: {}}, {$match: transactionFilter}]).itcount();
     });
 
+    const timeAfterTransactionStarts = new ISODate();
+    // Sleep here to allow some time between timeAfterTransactionStarts and timeBeforeCurrentOp to
+    // elapse.
+    sleep(100);
+    const timeBeforeCurrentOp = new ISODate();
+    // Check that the currentOp's transaction subdocument's fields align with our expectations.
+    let currentOp = adminDB.aggregate([{$currentOp: {}}, {$match: transactionFilter}]).toArray();
+    let transactionDocument = currentOp[0].transaction;
+    assert.eq(transactionDocument.parameters.autocommit, false);
+    assert.gt(transactionDocument.timeOpenMicros,
+              (timeBeforeCurrentOp - timeAfterTransactionStarts) * 1000);
+    assert.gte(ISODate(transactionDocument.startWallClockTime), timeBeforeTransactionStarts);
+
     // Now the transaction can proceed.
     assert.commandWorked(testDB.adminCommand(
         {configureFailPoint: 'setInterruptOnlyPlansCheckForInterruptHang', mode: 'off'}));
diff --git a/jstests/sharding/aggregation_currentop.js b/jstests/sharding/aggregation_currentop.js
index a7634c5afb3..67e26766f59 100644
--- a/jstests/sharding/aggregation_currentop.js
+++ b/jstests/sharding/aggregation_currentop.js
@@ -626,8 +626,6 @@ TestData.skipAwaitingReplicationOnShardsBeforeCheckingUUIDs = true;
             desc: "inactive transaction",
             "lsid.id": {$in: sessions.map((session) => session.getSessionId().id)},
             "transaction.parameters.txnNumber": {$gte: 0, $lt: sessions.length},
-            "transaction.parameters.autocommit": false,
-            'transaction.parameters.timeOpenMicros': {$gt: 0}
         };
     }
 
@@ -722,6 +720,8 @@ TestData.skipAwaitingReplicationOnShardsBeforeCheckingUUIDs = true;
     // disabled, even with 'allUsers:false'.
     const session = shardAdminDB.getMongo().startSession();
 
+    const timeBeforeTransactionStarts = new ISODate();
+
     // Start but do not complete a transaction.
     const sessionDB = session.getDatabase(shardTestDB.getName());
     assert.commandWorked(sessionDB.runCommand({
@@ -735,6 +735,8 @@ TestData.skipAwaitingReplicationOnShardsBeforeCheckingUUIDs = true;
     sessionDBs = [sessionDB];
     sessions = [session];
 
+    const timeAfterTransactionStarts = new ISODate();
+
     // Use $currentOp to confirm that the incomplete transaction has stashed its locks.
     assert.eq(shardAdminDB.aggregate([{$currentOp: {allUsers: false}}, {$match: sessionFilter()}])
                   .itcount(),
@@ -748,6 +750,18 @@ TestData.skipAwaitingReplicationOnShardsBeforeCheckingUUIDs = true;
             .itcount(),
         0);
 
+    const timeBeforeCurrentOp = new ISODate();
+
+    // Check that the currentOp's transaction subdocument's fields align with our expectations.
+    let currentOp =
+        shardAdminDB.aggregate([{$currentOp: {allUsers: false}}, {$match: sessionFilter()}])
+            .toArray();
+    let transactionDocument = currentOp[0].transaction;
+    assert.eq(transactionDocument.parameters.autocommit, false);
+    assert.gt(transactionDocument.timeOpenMicros,
+              (timeBeforeCurrentOp - timeAfterTransactionStarts) * 1000);
+    assert.gte(ISODate(transactionDocument.startWallClockTime), timeBeforeTransactionStarts);
+
     // Allow the transactions to complete and close the session.
     assert.commandWorked(sessionDB.adminCommand({
         commitTransaction: 1,
diff --git a/src/mongo/db/session.cpp b/src/mongo/db/session.cpp
index 5ddcdff9acf..bf92dc2d65c 100644
--- a/src/mongo/db/session.cpp
+++ b/src/mongo/db/session.cpp
@@ -1149,10 +1149,13 @@ void Session::_reportTransactionStats(WithLock wl, BSONObjBuilder* builder) cons
         return;
     }
     parametersBuilder.append("autocommit", _autocommit);
-    parametersBuilder.append("timeOpenMicros",
-                             static_cast<long long>(_singleTransactionStats->getDuration()));
-
     parametersBuilder.done();
+
+    builder->append("timeOpenMicros",
+                    static_cast<long long>(_singleTransactionStats->getDuration()));
+    builder->append("startWallClockTime",
+                    dateToISOStringLocal(Date_t::fromMillisSinceEpoch(
+                        _singleTransactionStats->getStartTime() / 1000)));
 }
 
 void Session::_checkValid(WithLock) const {
diff --git a/src/mongo/db/session_test.cpp b/src/mongo/db/session_test.cpp
index 574fa429079..ba4fe6d6c0e 100644
--- a/src/mongo/db/session_test.cpp
+++ b/src/mongo/db/session_test.cpp
@@ -726,6 +726,7 @@ TEST_F(SessionTest, StashAndUnstashResources) {
 }
 
 TEST_F(SessionTest, ReportStashedResources) {
+    Date_t startTime = Date_t::now();
     const auto sessionId = makeLogicalSessionIdForTest();
     const TxnNumber txnNum = 20;
     const bool autocommit = false;
@@ -759,16 +760,20 @@ TEST_F(SessionTest, ReportStashedResources) {
 
     // Verify that the Session's report of its own stashed state aligns with our expectations.
     auto stashedState = session.reportStashedState();
-    auto transactionDocument =
-        stashedState.getObjectField("transaction").getObjectField("parameters");
+    auto transactionDocument = stashedState.getObjectField("transaction");
+    auto parametersDocument = transactionDocument.getObjectField("parameters");
 
     ASSERT_EQ(stashedState.getField("host").valueStringData().toString(),
               getHostNameCachedAndPort());
     ASSERT_EQ(stashedState.getField("desc").valueStringData().toString(), "inactive transaction");
     ASSERT_BSONOBJ_EQ(stashedState.getField("lsid").Obj(), sessionId.toBSON());
-    ASSERT_EQ(transactionDocument.getField("txnNumber").numberLong(), txnNum);
-    ASSERT_EQ(transactionDocument.getField("autocommit").boolean(), autocommit);
+    ASSERT_EQ(parametersDocument.getField("txnNumber").numberLong(), txnNum);
+    ASSERT_EQ(parametersDocument.getField("autocommit").boolean(), autocommit);
     ASSERT_GTE(transactionDocument.getField("timeOpenMicros").numberLong(), 0);
+    ASSERT_GTE(
+        dateFromISOString(transactionDocument.getField("startWallClockTime").valueStringData())
+            .getValue(),
+        startTime);
     ASSERT_EQ(stashedState.getField("waitingForLock").boolean(), false);
     ASSERT_EQ(stashedState.getField("active").boolean(), false);
 
@@ -788,6 +793,7 @@ TEST_F(SessionTest, ReportStashedResources) {
 }
 
 TEST_F(SessionTest, ReportUnstashedResources) {
+    Date_t startTime = Date_t::now();
     const auto sessionId = makeLogicalSessionIdForTest();
     const TxnNumber txnNum = 20;
     const bool autocommit = false;
@@ -819,12 +825,16 @@ TEST_F(SessionTest, ReportUnstashedResources) {
     BSONObjBuilder unstashedStateBuilder;
     session.reportUnstashedState(&unstashedStateBuilder);
     auto unstashedState = unstashedStateBuilder.obj();
-    auto transactionDocument =
-        unstashedState.getObjectField("transaction").getObjectField("parameters");
+    auto transactionDocument = unstashedState.getObjectField("transaction");
+    auto parametersDocument = transactionDocument.getObjectField("parameters");
 
-    ASSERT_EQ(transactionDocument.getField("txnNumber").numberLong(), txnNum);
-    ASSERT_EQ(transactionDocument.getField("autocommit").boolean(), autocommit);
+    ASSERT_EQ(parametersDocument.getField("txnNumber").numberLong(), txnNum);
+    ASSERT_EQ(parametersDocument.getField("autocommit").boolean(), autocommit);
     ASSERT_GTE(transactionDocument.getField("timeOpenMicros").numberLong(), 0);
+    ASSERT_GTE(
+        dateFromISOString(transactionDocument.getField("startWallClockTime").valueStringData())
+            .getValue(),
+        startTime);
 
     // Stash resources. The original Locker and RecoveryUnit now belong to the stash.
     session.stashTransactionResources(opCtx());