diff options
author | Lingzhi Deng <lingzhi.deng@mongodb.com> | 2019-04-09 18:31:51 -0400 |
---|---|---|
committer | Lingzhi Deng <lingzhi.deng@mongodb.com> | 2019-04-09 18:31:51 -0400 |
commit | 408888993045ebf65e05f3fe6070d58580b774f8 (patch) | |
tree | 36f5d06311a7346905bd5b119c4bf348d23469a3 | |
parent | dc87a07c682d5a0f143c924bd12e771a6453c507 (diff) | |
download | mongo-408888993045ebf65e05f3fe6070d58580b774f8.tar.gz |
SERVER-40329: Log all transactions at TXN verbosity levels >= 1
-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(); |