SERVER-41376 Track time transactions on mongos are active and inactive and include in slow txn logging

5 files changed, 448 insertions, 20 deletions

diff --git a/src/mongo/s/session_catalog_router.cpp b/src/mongo/s/session_catalog_router.cpp
index aa4f770bec7..5c35434fe25 100644
--- a/src/mongo/s/session_catalog_router.cpp
+++ b/src/mongo/s/session_catalog_router.cpp
@@ -34,6 +34,7 @@
 #include "mongo/s/session_catalog_router.h"
 
 #include "mongo/db/sessions_collection.h"
+#include "mongo/s/transaction_router.h"
 
 namespace mongo {
 
@@ -68,8 +69,10 @@ int RouterSessionCatalog::reapSessionsOlderThan(OperationContext* opCtx,
 }
 
 RouterOperationContextSession::RouterOperationContextSession(OperationContext* opCtx)
-    : _operationContextSession(opCtx) {}
+    : _opCtx(opCtx), _operationContextSession(opCtx) {}
 
-RouterOperationContextSession::~RouterOperationContextSession() = default;
+RouterOperationContextSession::~RouterOperationContextSession() {
+    TransactionRouter::get(_opCtx).stash(_opCtx);
+};
 
 }  // namespace mongo
diff --git a/src/mongo/s/session_catalog_router.h b/src/mongo/s/session_catalog_router.h
index 057f9632593..ff54747aeed 100644
--- a/src/mongo/s/session_catalog_router.h
+++ b/src/mongo/s/session_catalog_router.h
@@ -62,6 +62,7 @@ public:
     ~RouterOperationContextSession();
 
 private:
+    OperationContext* _opCtx;
     OperationContextSession _operationContextSession;
 };
 
diff --git a/src/mongo/s/transaction_router.cpp b/src/mongo/s/transaction_router.cpp
index 9de327e0d45..4df0158d3dd 100644
--- a/src/mongo/s/transaction_router.cpp
+++ b/src/mongo/s/transaction_router.cpp
@@ -851,10 +851,12 @@ void TransactionRouter::Router::beginOrContinueTxn(OperationContext* opCtx,
                 repl::ReadConcernArgs::get(opCtx) = o().readConcernArgs;
 
                 ++p().latestStmtId;
+                _onContinue(opCtx);
                 break;
             }
             case TransactionActions::kCommit:
                 ++p().latestStmtId;
+                _onContinue(opCtx);
                 break;
         }
     } else if (txnNumber > o().txnNumber) {
@@ -908,6 +910,12 @@ void TransactionRouter::Router::beginOrContinueTxn(OperationContext* opCtx,
     _updateLastClientInfo(opCtx->getClient());
 }
 
+void TransactionRouter::Router::stash(OperationContext* opCtx) {
+    auto tickSource = opCtx->getServiceContext()->getTickSource();
+    stdx::lock_guard<Client> lk(*opCtx->getClient());
+    o(lk).timingStats.trySetInactive(tickSource, tickSource->getTicks());
+}
+
 BSONObj TransactionRouter::Router::_handOffCommitToCoordinator(OperationContext* opCtx) {
     invariant(o().coordinatorId);
     auto coordinatorIter = o().participants.find(*o().coordinatorId);
@@ -1080,7 +1088,9 @@ BSONObj TransactionRouter::Router::_commitTransaction(
 }
 
 BSONObj TransactionRouter::Router::abortTransaction(OperationContext* opCtx) {
-    _onExplicitAbort(opCtx);
+    // Update stats on scope exit so the transaction is considered "active" while waiting on abort
+    // responses.
+    auto updateStatsGuard = makeGuard([&] { _onExplicitAbort(opCtx); });
 
     // The router has yet to send any commands to a remote shard for this transaction.
     // Return the same error that would have been returned by a shard.
@@ -1140,7 +1150,9 @@ void TransactionRouter::Router::implicitlyAbortTransaction(OperationContext* opC
         return;
     }
 
-    _onImplicitAbort(opCtx, errorStatus);
+    // Update stats on scope exit so the transaction is considered "active" while waiting on abort
+    // responses.
+    auto updateStatsGuard = makeGuard([&] { _onImplicitAbort(opCtx, errorStatus); });
 
     if (o().participants.empty()) {
         return;
@@ -1208,9 +1220,8 @@ void TransactionRouter::Router::_resetRouterState(OperationContext* opCtx,
     p().terminationInitiated = false;
 
     auto tickSource = opCtx->getServiceContext()->getTickSource();
-    o(lk).timingStats.startTime = tickSource->getTicks();
-    o(lk).timingStats.startWallClockTime =
-        opCtx->getServiceContext()->getPreciseClockSource()->now();
+    auto curTicks = tickSource->getTicks();
+    o(lk).timingStats.trySetActive(opCtx, curTicks);
 
     // TODO SERVER-37115: Parse statement ids from the client and remember the statement id
     // of the command that started the transaction, if one was included.
@@ -1300,8 +1311,6 @@ std::string TransactionRouter::Router::_transactionInfoForLog(
 
         invariant(!o().abortCause.empty());
         sb << " abortCause:" << o().abortCause << ",";
-
-        // TODO SERVER-40985: Log abortSource
     }
 
     if (o().commitType != CommitType::kNotInitiated) {
@@ -1312,9 +1321,13 @@ std::string TransactionRouter::Router::_transactionInfoForLog(
            << ",";
     }
 
-    // TODO SERVER-41376: Log timeActiveMicros
+    sb << " timeActiveMicros:"
+       << durationCount<Microseconds>(o().timingStats.getTimeActiveMicros(tickSource, curTicks))
+       << ",";
 
-    // TODO SERVER-41376: Log timeInactiveMicros
+    sb << " timeInactiveMicros:"
+       << durationCount<Microseconds>(o().timingStats.getTimeInactiveMicros(tickSource, curTicks))
+       << ",";
 
     // Total duration of the transaction. Logged at the end of the line for consistency with slow
     // command logging.
@@ -1398,6 +1411,13 @@ void TransactionRouter::Router::_onNonRetryableCommitError(OperationContext* opC
     _endTransactionTrackingIfNecessary(opCtx, TerminationCause::kAborted);
 }
 
+void TransactionRouter::Router::_onContinue(OperationContext* opCtx) {
+    auto tickSource = opCtx->getServiceContext()->getTickSource();
+
+    stdx::lock_guard<Client> lk(*opCtx->getClient());
+    o(lk).timingStats.trySetActive(opCtx, tickSource->getTicks());
+}
+
 void TransactionRouter::Router::_onSuccessfulCommit(OperationContext* opCtx) {
     _endTransactionTrackingIfNecessary(opCtx, TerminationCause::kCommitted);
 }
@@ -1414,13 +1434,14 @@ void TransactionRouter::Router::_endTransactionTrackingIfNecessary(
 
     {
         stdx::lock_guard<Client> lk(*opCtx->getClient());
-        o(lk).timingStats.endTime = curTicks;
 
-        // If startTime hasn't been set yet, that probably means it run into an error and is
-        // getting aborted.
-        if (o().timingStats.startTime == 0) {
-            o(lk).timingStats.startTime = curTicks;
-        }
+        // In some error contexts, the transaction may not have been started yet, so try setting the
+        // transaction's timing stats to active before ending it below. This is a no-op for already
+        // active transactions.
+        o(lk).timingStats.trySetActive(opCtx, curTicks);
+
+        o(lk).timingStats.trySetInactive(tickSource, curTicks);
+        o(lk).timingStats.endTime = curTicks;
     }
 
     if (shouldLog(logger::LogComponent::kTransaction, logger::LogSeverity::Debug(1)) ||
@@ -1467,4 +1488,55 @@ Microseconds TransactionRouter::TimingStats::getCommitDuration(TickSource* tickS
     return tickSource->ticksTo<Microseconds>(endTime - commitStartTime);
 }
 
+Microseconds TransactionRouter::TimingStats::getTimeActiveMicros(TickSource* tickSource,
+                                                                 TickSource::Tick curTicks) const {
+    invariant(startTime > 0);
+
+    if (lastTimeActiveStart != 0) {
+        // The transaction is currently active, so return the active time so far plus the time since
+        // the transaction became active.
+        return timeActiveMicros + tickSource->ticksTo<Microseconds>(curTicks - lastTimeActiveStart);
+    }
+    return timeActiveMicros;
+}
+
+Microseconds TransactionRouter::TimingStats::getTimeInactiveMicros(
+    TickSource* tickSource, TickSource::Tick curTicks) const {
+    invariant(startTime > 0);
+
+    auto micros = getDuration(tickSource, curTicks) - getTimeActiveMicros(tickSource, curTicks);
+    dassert(micros >= Microseconds(0),
+            str::stream() << "timeInactiveMicros should never be negative, was: " << micros);
+    return micros;
+}
+
+void TransactionRouter::TimingStats::trySetActive(OperationContext* opCtx,
+                                                  TickSource::Tick curTicks) {
+    if (endTime != 0 || lastTimeActiveStart != 0) {
+        // A transaction can't become active if it has already ended or is already active.
+        return;
+    }
+
+    if (startTime == 0) {
+        // If the transaction is becoming active for the first time, also set the transaction's
+        // start time.
+        startTime = curTicks;
+        startWallClockTime = opCtx->getServiceContext()->getPreciseClockSource()->now();
+    }
+    lastTimeActiveStart = curTicks;
+}
+
+void TransactionRouter::TimingStats::trySetInactive(TickSource* tickSource,
+                                                    TickSource::Tick curTicks) {
+    if (endTime != 0 || lastTimeActiveStart == 0) {
+        // If the transaction is already over or the router has already been stashed, the relevant
+        // stats should have been updated earlier. In certain error scenarios, it's possible for a
+        // transaction to be stashed twice in a row.
+        return;
+    }
+
+    timeActiveMicros += tickSource->ticksTo<Microseconds>(curTicks - lastTimeActiveStart);
+    lastTimeActiveStart = 0;
+}
+
 }  // namespace mongo
diff --git a/src/mongo/s/transaction_router.h b/src/mongo/s/transaction_router.h
index 3f1e45d5fa3..10879068894 100644
--- a/src/mongo/s/transaction_router.h
+++ b/src/mongo/s/transaction_router.h
@@ -134,23 +134,59 @@ public:
          */
         Microseconds getCommitDuration(TickSource* tickSource, TickSource::Tick curTicks) const;
 
+        /**
+         * Returns the total active time of the transaction, given the current time value. A
+         * transaction is active when there is a running operation that is part of the transaction.
+         */
+        Microseconds getTimeActiveMicros(TickSource* tickSource, TickSource::Tick curTicks) const;
+
+        /**
+         * Returns the total inactive time of the transaction, given the current time value. A
+         * transaction is inactive when it is idly waiting for a new operation to occur.
+         */
+        Microseconds getTimeInactiveMicros(TickSource* tickSource, TickSource::Tick curTicks) const;
+
+        /**
+         * Marks the transaction as active and sets the start of the transaction's active time and
+         * overall start time the first time it is called.
+         *
+         * This method is a no-op if the transaction is currently active or has already ended.
+         */
+        void trySetActive(OperationContext* opCtx, TickSource::Tick curTicks);
+
+        /**
+         * Marks the transaction as inactive and sets the total active time of the transaction. The
+         * total active time will only be set if the transaction was active prior to this call.
+         *
+         * This method is a no-op if the transaction is not currently active or has already ended.
+         */
+        void trySetInactive(TickSource* tickSource, TickSource::Tick curTicks);
+
         // The start time of the transaction in millisecond resolution. Used only for diagnostics
         // reporting.
         Date_t startWallClockTime;
 
         // The start time of the transaction. Note that tick values should only ever be used to
-        // measure distance from other tick values, not for reporting absolute wall clock time.
+        // measure distance from other tick values, not for reporting absolute wall clock time. A
+        // value of zero means the transaction hasn't started yet.
         TickSource::Tick startTime{0};
 
         // The start time of the transaction commit in millisecond resolution. Used only for
         // diagnostics reporting.
         Date_t commitStartWallClockTime;
 
-        // When commit was started.
+        // When commit was started. A value of zero means the commit hasn't started yet.
         TickSource::Tick commitStartTime{0};
 
-        // The end time of the transaction.
+        // The end time of the transaction. A value of zero means the transaction hasn't ended yet.
         TickSource::Tick endTime{0};
+
+        // The total amount of active time spent by the transaction.
+        Microseconds timeActiveMicros = Microseconds{0};
+
+        // The time at which the transaction was last marked as active. The transaction is
+        // considered active if this value is not equal to 0.
+        TickSource::Tick lastTimeActiveStart{0};
     };
 
     enum class TransactionActions { kStart, kContinue, kCommit };
@@ -260,6 +296,11 @@ public:
                                 TransactionActions action);
 
         /**
+         * Updates transaction diagnostics when the transaction's session is checked in.
+         */
+        void stash(OperationContext* opCtx);
+
+        /**
          * Attaches the required transaction related fields for a request to be sent to the given
          * shard.
          *
@@ -517,6 +558,11 @@ public:
         void _onNonRetryableCommitError(OperationContext* opCtx, Status commitStatus);
 
         /**
+         * Updates relevent metrics when a transaction is continued.
+         */
+        void _onContinue(OperationContext* opCtx);
+
+        /**
          * The first time this method is called it marks the transaction as over in the router's
          * diagnostics and will log transaction information if its duration is over the global
          * slowMS threshold or the transaction log componenet verbosity >= 1. Only meant to be
diff --git a/src/mongo/s/transaction_router_test.cpp b/src/mongo/s/transaction_router_test.cpp
index db099d84789..e95252553e5 100644
--- a/src/mongo/s/transaction_router_test.cpp
+++ b/src/mongo/s/transaction_router_test.cpp
@@ -2794,6 +2794,9 @@ protected:
     const TxnNumber kTxnNumber = 10;
     const TxnRecoveryToken kDummyRecoveryToken;
 
+    static constexpr auto kDefaultTimeActive = Microseconds(50);
+    static constexpr auto kDefaultTimeInactive = Microseconds(100);
+
     void setUp() override {
         TransactionRouterTestWithDefaultSession::setUp();
         repl::ReadConcernArgs::get(operationContext()) = repl::ReadConcernArgs();
@@ -2856,6 +2859,16 @@ protected:
         return guard->hasReadyRequests();
     }
 
+    void assertTimeActiveIs(Microseconds micros) {
+        auto stats = txnRouter().getTimingStats();
+        ASSERT_EQ(stats.getTimeActiveMicros(tickSource(), tickSource()->getTicks()), micros);
+    }
+
+    void assertTimeInactiveIs(Microseconds micros) {
+        auto stats = txnRouter().getTimingStats();
+        ASSERT_EQ(stats.getTimeInactiveMicros(tickSource(), tickSource()->getTicks()), micros);
+    }
+
     //
     // Helpers for each way a router's transaction may terminate. Meant to be used where the
     // particular commit type is not being tested.
@@ -3051,6 +3064,31 @@ protected:
     auto routerTxnMetrics() {
         return RouterTransactionsMetrics::get(operationContext());
     }
+
+    void assertTimeActiveAndInactiveCannotAdvance(Microseconds timeActive,
+                                                  Microseconds timeInactive) {
+        tickSource()->advance(Microseconds(150));
+        assertTimeActiveIs(Microseconds(timeActive));
+        assertTimeInactiveIs(Microseconds(timeInactive));
+
+        txnRouter().stash(operationContext());
+
+        tickSource()->advance(Microseconds(150));
+        assertTimeActiveIs(Microseconds(timeActive));
+        assertTimeInactiveIs(Microseconds(timeInactive));
+    }
+
+    void setUpDefaultTimeActiveAndInactive() {
+        tickSource()->advance(kDefaultTimeActive);
+        assertTimeActiveIs(kDefaultTimeActive);
+        assertTimeInactiveIs(Microseconds(0));
+
+        txnRouter().stash(operationContext());
+
+        tickSource()->advance(kDefaultTimeInactive);
+        assertTimeActiveIs(kDefaultTimeActive);
+        assertTimeInactiveIs(kDefaultTimeInactive);
+    }
 };
 
 //
@@ -3132,6 +3170,23 @@ TEST_F(TransactionRouterMetricsTest, SlowLoggingPrintsDurationAtEnd) {
     ASSERT_EQUALS(1, countLogLinesContaining(" 111ms\n") + countLogLinesContaining(" 111ms\r\n"));
 }
 
+TEST_F(TransactionRouterMetricsTest, SlowLoggingPrintsTimeActiveAndInactive) {
+    beginTxnWithDefaultTxnNumber();
+    tickSource()->advance(Microseconds(111));
+    assertTimeActiveIs(Microseconds(111));
+
+    txnRouter().stash(operationContext());
+    tickSource()->advance(Microseconds(222));
+    assertTimeInactiveIs(Microseconds(222));
+
+    txnRouter().beginOrContinueTxn(
+        operationContext(), kTxnNumber, TransactionRouter::TransactionActions::kCommit);
+    runCommit(kDummyOkRes);
+
+    ASSERT_EQUALS(1, countLogLinesContaining("timeActiveMicros:111,"));
+    ASSERT_EQUALS(1, countLogLinesContaining("timeInactiveMicros:222,"));
+}
+
 //
 // Slow transaction logging tests for the parameters that depend on the read concern level.
 //
@@ -3511,6 +3566,14 @@ TEST_F(TransactionRouterMetricsTest, DurationDoesNotAdvanceAfterImplicitAbort) {
     assertDurationIs(Microseconds(100));
 }
 
+TEST_F(TransactionRouterMetricsTest, DurationIsZeroForAbortedUnstartedTxn) {
+    // It's possible a transaction that has not been started can be implicitly aborted at server
+    // shutdown. The duration for such a transaction should be 0.
+    txnRouter().implicitlyAbortTransaction(operationContext(), kDummyStatus);
+
+    assertDurationIs(Microseconds(0));
+}
+
 TEST_F(TransactionRouterMetricsTest, CommitDurationAdvancesDuringCommit) {
     beginTxnWithDefaultTxnNumber();
 
@@ -3615,6 +3678,249 @@ TEST_F(TransactionRouterMetricsTest, DurationsAdvanceAfterUnknownCommitResult) {
     assertCommitDurationIs(Microseconds(200));
 }
 
+TEST_F(TransactionRouterMetricsTest, TimeActiveAndInactiveAdvanceSeparatelyAndSumToDuration) {
+    beginTxnWithDefaultTxnNumber();
+
+    // Both timeActive and timeInactive start at 0.
+    assertTimeActiveIs(Microseconds(0));
+    assertTimeInactiveIs(Microseconds(0));
+    assertDurationIs(Microseconds(0));
+
+    // Only timeActive will advance while a txn is active.
+    tickSource()->advance(Microseconds(50));
+    assertTimeActiveIs(Microseconds(50));
+    assertTimeInactiveIs(Microseconds(0));
+    assertDurationIs(Microseconds(50));
+
+    // Only timeInactive will advance while a txn is stashed.
+    txnRouter().stash(operationContext());
+    tickSource()->advance(Microseconds(100));
+    assertTimeActiveIs(Microseconds(50));
+    assertTimeInactiveIs(Microseconds(100));
+    assertDurationIs(Microseconds(150));
+
+    // Will not advance after commit.
+    // Neither can advance after a successful commit.
+    txnRouter().beginOrContinueTxn(
+        operationContext(), kTxnNumber, TransactionRouter::TransactionActions::kCommit);
+    runCommit(kDummyOkRes);
+
+    tickSource()->advance(Microseconds(150));
+    assertTimeActiveIs(Microseconds(50));
+    assertTimeInactiveIs(Microseconds(100));
+    assertDurationIs(Microseconds(150));
+}
+
+TEST_F(TransactionRouterMetricsTest, StashIsIdempotent) {
+    // An error after checking out a session and before continuing a transaction can lead to
+    // back-to-back calls to TransactionRouter::stash(), so a repeated call to stash() shouldn't
+    // toggle the transaction back to the active state.
+
+    beginTxnWithDefaultTxnNumber();
+
+    setUpDefaultTimeActiveAndInactive();
+
+    assertTimeActiveIs(kDefaultTimeActive);
+    assertTimeInactiveIs(kDefaultTimeInactive);
+
+    txnRouter().stash(operationContext());
+
+    // Only timeInactive can advance.
+    tickSource()->advance(Microseconds(100));
+    assertTimeActiveIs(kDefaultTimeActive);
+    assertTimeInactiveIs(kDefaultTimeInactive + Microseconds(100));
+
+    txnRouter().stash(operationContext());
+
+    // Still only timeInactive can advance.
+    tickSource()->advance(Microseconds(100));
+    assertTimeActiveIs(kDefaultTimeActive);
+    assertTimeInactiveIs(kDefaultTimeInactive + Microseconds(200));
+}
+
+TEST_F(TransactionRouterMetricsTest, TimeActiveAndInactiveAreZeroForAbortedUnstartedTxn) {
+    // It's possible a transaction that has not been started can be implicitly aborted at server
+    // shutdown. The time active and inactive for such a transaction should be 0.
+    txnRouter().implicitlyAbortTransaction(operationContext(), kDummyStatus);
+
+    assertTimeActiveIs(Microseconds(0));
+    assertTimeInactiveIs(Microseconds(0));
+}
+
+TEST_F(TransactionRouterMetricsTest, DurationsForImplicitlyAbortedStashedTxn) {
+    beginTxnWithDefaultTxnNumber();
+
+    setUpDefaultTimeActiveAndInactive();
+
+    assertTimeActiveIs(kDefaultTimeActive);
+    assertTimeInactiveIs(kDefaultTimeInactive);
+    assertDurationIs(kDefaultTimeActive + kDefaultTimeInactive);
+
+    txnRouter().stash(operationContext());
+
+    // At shutdown transactions are implicitly aborted without being continued so a transaction may
+    // be stashed when aborting, which should still lead to durations in a consistent state.
+    txnRouter().implicitlyAbortTransaction(operationContext(), kDummyStatus);
+
+    assertTimeActiveIs(kDefaultTimeActive);
+    assertTimeInactiveIs(kDefaultTimeInactive);
+    assertDurationIs(kDefaultTimeActive + kDefaultTimeInactive);
+}
+
+TEST_F(TransactionRouterMetricsTest, DurationsForImplicitlyAbortedActiveTxn) {
+    beginTxnWithDefaultTxnNumber();
+
+    setUpDefaultTimeActiveAndInactive();
+
+    assertTimeActiveIs(kDefaultTimeActive);
+    assertTimeInactiveIs(kDefaultTimeInactive);
+    assertDurationIs(kDefaultTimeActive + kDefaultTimeInactive);
+
+    txnRouter().beginOrContinueTxn(
+        operationContext(), kTxnNumber, TransactionRouter::TransactionActions::kContinue);
+    tickSource()->advance(Microseconds(100));
+
+    assertTimeActiveIs(kDefaultTimeActive + Microseconds(100));
+    assertTimeInactiveIs(kDefaultTimeInactive);
+    assertDurationIs(kDefaultTimeActive + kDefaultTimeInactive + Microseconds(100));
+
+    txnRouter().implicitlyAbortTransaction(operationContext(), kDummyStatus);
+
+    assertTimeActiveIs(kDefaultTimeActive + Microseconds(100));
+    assertTimeInactiveIs(kDefaultTimeInactive);
+    assertDurationIs(kDefaultTimeActive + kDefaultTimeInactive + Microseconds(100));
+}
+
+TEST_F(TransactionRouterMetricsTest, DurationsForImplicitlyAbortedEndedTxn) {
+    beginTxnWithDefaultTxnNumber();
+
+    setUpDefaultTimeActiveAndInactive();
+
+    assertTimeActiveIs(kDefaultTimeActive);
+    assertTimeInactiveIs(kDefaultTimeInactive);
+    assertDurationIs(kDefaultTimeActive + kDefaultTimeInactive);
+
+    txnRouter().beginOrContinueTxn(
+        operationContext(), kTxnNumber, TransactionRouter::TransactionActions::kCommit);
+    runCommit(kDummyOkRes);
+    txnRouter().stash(operationContext());
+
+    // At shutdown transactions are implicitly aborted without being continued, so an "ended"
+    // transaction (i.e. committed or aborted) may be implicitly aborted again. This shouldn't
+    // affect any transaction durations.
+    auto future = launchAsync(
+        [&] { return txnRouter().implicitlyAbortTransaction(operationContext(), kDummyStatus); });
+    expectAbortTransactions({hostAndPort1}, getSessionId(), kTxnNumber);
+    future.default_timed_get();
+
+    assertTimeActiveIs(kDefaultTimeActive);
+    assertTimeInactiveIs(kDefaultTimeInactive);
+    assertDurationIs(kDefaultTimeActive + kDefaultTimeInactive);
+}
+
+TEST_F(TransactionRouterMetricsTest, NeitherTimeActiveNorInactiveAdvanceAfterSuccessfulCommit) {
+    beginTxnWithDefaultTxnNumber();
+
+    setUpDefaultTimeActiveAndInactive();
+
+    txnRouter().beginOrContinueTxn(
+        operationContext(), kTxnNumber, TransactionRouter::TransactionActions::kCommit);
+    runCommit(kDummyOkRes);
+
+    // Neither can advance.
+    assertTimeActiveAndInactiveCannotAdvance(kDefaultTimeActive /*timeActive*/,
+                                             kDefaultTimeInactive /*timeInactive*/);
+}
+
+TEST_F(TransactionRouterMetricsTest, NeitherTimeActiveNorInactiveAdvanceAfterFailedCommit) {
+    beginTxnWithDefaultTxnNumber();
+
+    setUpDefaultTimeActiveAndInactive();
+
+    txnRouter().beginOrContinueTxn(
+        operationContext(), kTxnNumber, TransactionRouter::TransactionActions::kContinue);
+    runCommit(kDummyErrorRes);
+
+    // Neither can advance.
+    assertTimeActiveAndInactiveCannotAdvance(kDefaultTimeActive /*timeActive*/,
+                                             kDefaultTimeInactive /*timeInactive*/);
+}
+
+TEST_F(TransactionRouterMetricsTest, TimeActiveAndInactiveAdvanceAfterUnknownCommitResult) {
+    beginTxnWithDefaultTxnNumber();
+
+    setUpDefaultTimeActiveAndInactive();
+
+    txnRouter().beginOrContinueTxn(
+        operationContext(), kTxnNumber, TransactionRouter::TransactionActions::kCommit);
+    runCommit(Status(ErrorCodes::HostUnreachable, "dummy"), true /* expectRetries */);
+
+    // timeActive can advance.
+    tickSource()->advance(Microseconds(100));
+    assertTimeActiveIs(kDefaultTimeActive + Microseconds(100));
+    assertTimeInactiveIs(kDefaultTimeInactive);
+
+    // timeInactive can advance.
+    txnRouter().stash(operationContext());
+    tickSource()->advance(Microseconds(100));
+    assertTimeActiveIs(kDefaultTimeActive + Microseconds(100));
+    assertTimeInactiveIs(kDefaultTimeInactive + Microseconds(100));
+
+    txnRouter().beginOrContinueTxn(
+        operationContext(), kTxnNumber, TransactionRouter::TransactionActions::kCommit);
+    runCommit(kDummyRetryableErrorRes, true /* expectRetries */);
+
+    // timeActive can advance.
+    tickSource()->advance(Microseconds(100));
+    assertTimeActiveIs(kDefaultTimeActive + Microseconds(200));
+    assertTimeInactiveIs(kDefaultTimeInactive + Microseconds(100));
+
+    // timeInactive can advance.
+    txnRouter().stash(operationContext());
+    tickSource()->advance(Microseconds(100));
+    assertTimeActiveIs(kDefaultTimeActive + Microseconds(200));
+    assertTimeInactiveIs(kDefaultTimeInactive + Microseconds(200));
+
+    txnRouter().beginOrContinueTxn(
+        operationContext(), kTxnNumber, TransactionRouter::TransactionActions::kCommit);
+    runCommit(kDummyOkRes);
+
+    // The result is known, so neither can advance.
+    assertTimeActiveAndInactiveCannotAdvance(kDefaultTimeActive + Microseconds(200) /*timeActive*/,
+                                             kDefaultTimeInactive +
+                                                 Microseconds(200) /*timeInactive*/);
+}
+
+TEST_F(TransactionRouterMetricsTest, NeitherTimeActiveNorInactiveAdvanceAfterAbort) {
+    beginTxnWithDefaultTxnNumber();
+
+    setUpDefaultTimeActiveAndInactive();
+
+    txnRouter().beginOrContinueTxn(
+        operationContext(), kTxnNumber, TransactionRouter::TransactionActions::kContinue);
+    ASSERT_THROWS_CODE(txnRouter().abortTransaction(operationContext()),
+                       AssertionException,
+                       ErrorCodes::NoSuchTransaction);
+
+    // Neither can advance.
+    assertTimeActiveAndInactiveCannotAdvance(kDefaultTimeActive /*timeActive*/,
+                                             kDefaultTimeInactive /*timeInactive*/);
+}
+
+TEST_F(TransactionRouterMetricsTest, NeitherTimeActiveNorInactiveAdvanceAfterImplicitAbort) {
+    beginTxnWithDefaultTxnNumber();
+
+    setUpDefaultTimeActiveAndInactive();
+
+    txnRouter().beginOrContinueTxn(
+        operationContext(), kTxnNumber, TransactionRouter::TransactionActions::kContinue);
+    txnRouter().implicitlyAbortTransaction(operationContext(), kDummyStatus);
+
+    // Neither can advance.
+    assertTimeActiveAndInactiveCannotAdvance(kDefaultTimeActive /*timeActive*/,
+                                             kDefaultTimeInactive /*timeInactive*/);
+}
+
 TEST_F(TransactionRouterMetricsTest, RouterMetricsTotalStarted_DefaultsTo0) {
     ASSERT_EQUALS(0L, routerTxnMetrics()->getTotalStarted());
 }