diff options
| -rw-r--r-- | src/mongo/db/transaction_participant.cpp | 6 | ||||
| -rw-r--r-- | src/mongo/db/transaction_participant_test.cpp | 49 |
2 files changed, 53 insertions, 2 deletions
diff --git a/src/mongo/db/transaction_participant.cpp b/src/mongo/db/transaction_participant.cpp index 190fe6a09a7..3c8c8353ca7 100644 --- a/src/mongo/db/transaction_participant.cpp +++ b/src/mongo/db/transaction_participant.cpp @@ -1805,8 +1805,10 @@ void TransactionParticipant::Participant::_logSlowTransaction( // Only log multi-document transactions. if (!o().txnState.isInRetryableWriteMode()) { const auto tickSource = opCtx->getServiceContext()->getTickSource(); - // Log the transaction if its duration is longer than the slowMS command threshold. - if (o().transactionMetricsObserver.getSingleTransactionStats().getDuration( + // Log the transaction if log message verbosity for transaction component is >= 1 or its + // duration is longer than the slowMS command threshold. + if (shouldLog(logger::LogComponent::kTransaction, logger::LogSeverity::Debug(1)) || + o().transactionMetricsObserver.getSingleTransactionStats().getDuration( tickSource, tickSource->getTicks()) > Milliseconds(serverGlobalParams.slowMS)) { log(logger::LogComponent::kTransaction) << "transaction " diff --git a/src/mongo/db/transaction_participant_test.cpp b/src/mongo/db/transaction_participant_test.cpp index 8828b002e5b..b933e52b341 100644 --- a/src/mongo/db/transaction_participant_test.cpp +++ b/src/mongo/db/transaction_participant_test.cpp @@ -47,6 +47,7 @@ #include "mongo/db/stats/fill_locker_info.h" #include "mongo/db/transaction_participant.h" #include "mongo/db/transaction_participant_gen.h" +#include "mongo/logger/logger.h" #include "mongo/stdx/future.h" #include "mongo/stdx/memory.h" #include "mongo/unittest/barrier.h" @@ -3366,6 +3367,54 @@ TEST_F(TransactionsMetricsTest, LogTransactionInfoAfterSlowStashedAbort) { ASSERT_EQUALS(1, countLogLinesContaining(expectedTransactionInfo)); } +TEST_F(TransactionsMetricsTest, LogTransactionInfoVerbosityInfo) { + auto sessionCheckout = checkOutSession(); + + auto txnParticipant = TransactionParticipant::get(opCtx()); + + // Set a high slow operation threshold to avoid the transaction being logged as slow. + serverGlobalParams.slowMS = 10000; + + // Set verbosity level of transaction components to info. + logger::globalLogDomain()->setMinimumLoggedSeverity(logger::LogComponent::kTransaction, + logger::LogSeverity::Info()); + + txnParticipant.unstashTransactionResources(opCtx(), "commitTransaction"); + + startCapturingLogMessages(); + txnParticipant.commitUnpreparedTransaction(opCtx()); + stopCapturingLogMessages(); + + // Test that the transaction is not logged. + ASSERT_EQUALS(0, countLogLinesContaining("transaction parameters")); +} + +TEST_F(TransactionsMetricsTest, LogTransactionInfoVerbosityDebug) { + auto sessionCheckout = checkOutSession(); + + auto txnParticipant = TransactionParticipant::get(opCtx()); + + // Set a high slow operation threshold to avoid the transaction being logged as slow. + serverGlobalParams.slowMS = 10000; + + // Set verbosity level of transaction components to debug. + logger::globalLogDomain()->setMinimumLoggedSeverity(logger::LogComponent::kTransaction, + logger::LogSeverity::Debug(1)); + + txnParticipant.unstashTransactionResources(opCtx(), "commitTransaction"); + + startCapturingLogMessages(); + txnParticipant.commitUnpreparedTransaction(opCtx()); + stopCapturingLogMessages(); + + // Reset verbosity level of transaction components. + logger::globalLogDomain()->setMinimumLoggedSeverity(logger::LogComponent::kTransaction, + logger::LogSeverity::Info()); + + // Test that the transaction is still logged. + ASSERT_EQUALS(1, countLogLinesContaining("transaction parameters")); +} + TEST_F(TxnParticipantTest, RollbackResetsInMemoryStateOfPreparedTransaction) { auto sessionCheckout = checkOutSession(); |