summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorLingzhi Deng <lingzhi.deng@mongodb.com>2019-04-09 18:31:51 -0400
committerLingzhi Deng <lingzhi.deng@mongodb.com>2019-04-09 18:31:51 -0400
commit408888993045ebf65e05f3fe6070d58580b774f8 (patch)
tree36f5d06311a7346905bd5b119c4bf348d23469a3
parentdc87a07c682d5a0f143c924bd12e771a6453c507 (diff)
downloadmongo-408888993045ebf65e05f3fe6070d58580b774f8.tar.gz
SERVER-40329: Log all transactions at TXN verbosity levels >= 1
-rw-r--r--src/mongo/db/transaction_participant.cpp6
-rw-r--r--src/mongo/db/transaction_participant_test.cpp49
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();