summaryrefslogtreecommitdiff
path: root/src
diff options
context:
space:
mode:
authorHenrik Edin <henrik.edin@mongodb.com>2020-01-21 20:23:50 +0000
committerevergreen <evergreen@mongodb.com>2020-01-21 20:23:50 +0000
commitb7846ff4dceec36e344b0f87c48783dffa2c6a32 (patch)
tree73068bb126bf19901e75bb972a941f17c9759754 /src
parent41b3d7da7c763e304bc8f4056d0d31d200742e0b (diff)
downloadmongo-b7846ff4dceec36e344b0f87c48783dffa2c6a32.tar.gz
SERVER-45583 Unittests are using logv2.
Capture log system uses logv2, tests can handle converted log statements.
Diffstat (limited to 'src')
-rw-r--r--src/mongo/client/fetcher_test.cpp8
-rw-r--r--src/mongo/db/repl/apply_ops_test.cpp4
-rw-r--r--src/mongo/db/repl/drop_pending_collection_reaper_test.cpp3
-rw-r--r--src/mongo/db/repl/oplog_applier_impl_test.cpp6
-rw-r--r--src/mongo/db/repl/replication_coordinator_impl_elect_v1_test.cpp138
-rw-r--r--src/mongo/db/repl/replication_coordinator_impl_reconfig_test.cpp5
-rw-r--r--src/mongo/db/repl/replication_coordinator_impl_test.cpp39
-rw-r--r--src/mongo/db/repl/replication_recovery_test.cpp3
-rw-r--r--src/mongo/db/repl/rs_rollback_test.cpp32
-rw-r--r--src/mongo/db/repl/topology_coordinator_v1_test.cpp2
-rw-r--r--src/mongo/db/repl/vote_requester_test.cpp2
-rw-r--r--src/mongo/db/s/transaction_coordinator_test.cpp61
-rw-r--r--src/mongo/db/transaction_participant_test.cpp16
-rw-r--r--src/mongo/logger/log_function_test.cpp3
-rw-r--r--src/mongo/logger/log_manager.cpp17
-rw-r--r--src/mongo/logger/log_test.cpp14
-rw-r--r--src/mongo/logger/log_test.h32
-rw-r--r--src/mongo/logv2/domain_filter.h9
-rw-r--r--src/mongo/logv2/log_capture_backend.h60
-rw-r--r--src/mongo/logv2/log_test_v2.cpp58
-rw-r--r--src/mongo/logv2/log_test_v2.h8
-rw-r--r--src/mongo/s/transaction_router_test.cpp129
-rw-r--r--src/mongo/unittest/unittest.cpp101
-rw-r--r--src/mongo/unittest/unittest.h15
24 files changed, 472 insertions, 293 deletions
diff --git a/src/mongo/client/fetcher_test.cpp b/src/mongo/client/fetcher_test.cpp
index 557f47a5b57..b03ba051978 100644
--- a/src/mongo/client/fetcher_test.cpp
+++ b/src/mongo/client/fetcher_test.cpp
@@ -837,7 +837,7 @@ TEST_F(FetcherTest, EmptyGetMoreRequestAfterFirstBatchMakesFetcherInactiveAndKil
// killCursors command request will be canceled by executor on shutdown.
tearDown();
ASSERT_EQUALS(1,
- countLogLinesContaining(
+ countTextFormatLogLinesContaining(
"killCursors command task failed: CallbackCanceled: Callback canceled"));
}
@@ -910,7 +910,7 @@ TEST_F(FetcherTest, UpdateNextActionAfterSecondBatch) {
getNet()->runReadyNetworkOperations();
}
- ASSERT_EQUALS(1, countLogLinesContaining("killCursors command failed: UnknownError"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("killCursors command failed: UnknownError"));
}
/**
@@ -979,8 +979,8 @@ TEST_F(FetcherTest, ShutdownDuringSecondBatch) {
// Fetcher should attempt (unsuccessfully) to schedule a killCursors command.
ASSERT_EQUALS(1,
- countLogLinesContaining("failed to schedule killCursors command: "
- "ShutdownInProgress: Shutdown in progress"));
+ countTextFormatLogLinesContaining("failed to schedule killCursors command: "
+ "ShutdownInProgress: Shutdown in progress"));
ASSERT_EQUALS(ErrorCodes::ShutdownInProgress, status.code());
}
diff --git a/src/mongo/db/repl/apply_ops_test.cpp b/src/mongo/db/repl/apply_ops_test.cpp
index 9fe27a8c8a1..85c4c428361 100644
--- a/src/mongo/db/repl/apply_ops_test.cpp
+++ b/src/mongo/db/repl/apply_ops_test.cpp
@@ -315,7 +315,7 @@ TEST_F(ApplyOpsTest, ApplyOpsPropagatesOplogApplicationMode) {
cmdObj,
OplogApplication::Mode::kInitialSync,
&resultBuilder));
- ASSERT_EQUALS(1, countLogLinesContaining("oplog application mode: InitialSync"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("oplog application mode: InitialSync"));
auto docToInsert1 = BSON("_id" << 1);
cmdObj = makeApplyOpsWithInsertOperation(nss, uuid, docToInsert1);
@@ -325,7 +325,7 @@ TEST_F(ApplyOpsTest, ApplyOpsPropagatesOplogApplicationMode) {
cmdObj,
OplogApplication::Mode::kSecondary,
&resultBuilder));
- ASSERT_EQUALS(1, countLogLinesContaining("oplog application mode: Secondary"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("oplog application mode: Secondary"));
stopCapturingLogMessages();
}
diff --git a/src/mongo/db/repl/drop_pending_collection_reaper_test.cpp b/src/mongo/db/repl/drop_pending_collection_reaper_test.cpp
index 0ac9f2071e6..3d12d1acde4 100644
--- a/src/mongo/db/repl/drop_pending_collection_reaper_test.cpp
+++ b/src/mongo/db/repl/drop_pending_collection_reaper_test.cpp
@@ -238,7 +238,8 @@ TEST_F(DropPendingCollectionReaperTest, DropCollectionsOlderThanLogsDropCollecti
reaper.dropCollectionsOlderThan(opCtx.get(), optime);
stopCapturingLogMessages();
- ASSERT_EQUALS(1LL, countLogLinesContaining("Failed to remove drop-pending collection"));
+ ASSERT_EQUALS(1LL,
+ countTextFormatLogLinesContaining("Failed to remove drop-pending collection"));
}
TEST_F(DropPendingCollectionReaperTest,
diff --git a/src/mongo/db/repl/oplog_applier_impl_test.cpp b/src/mongo/db/repl/oplog_applier_impl_test.cpp
index a851ee49917..6f0c8ae14f8 100644
--- a/src/mongo/db/repl/oplog_applier_impl_test.cpp
+++ b/src/mongo/db/repl/oplog_applier_impl_test.cpp
@@ -2246,7 +2246,7 @@ TEST_F(OplogApplierImplTest, LogSlowOpApplicationWhenSuccessful) {
"wall: new Date(0), o: "
"{ _id: 0 } }, took "
<< applyDuration << "ms";
- ASSERT_EQUALS(1, countLogLinesContaining(expected.str()));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining(expected.str()));
}
TEST_F(OplogApplierImplTest, DoNotLogSlowOpApplicationWhenFailed) {
@@ -2270,7 +2270,7 @@ TEST_F(OplogApplierImplTest, DoNotLogSlowOpApplicationWhenFailed) {
expected << "applied op: CRUD { op: \"i\", ns: \"test.t\", o: { _id: 0 }, ts: Timestamp(1, 1), "
"t: 1, h: 1, v: 2 }, took "
<< applyDuration << "ms";
- ASSERT_EQUALS(0, countLogLinesContaining(expected.str()));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining(expected.str()));
}
TEST_F(OplogApplierImplTest, DoNotLogNonSlowOpApplicationWhenSuccessful) {
@@ -2294,7 +2294,7 @@ TEST_F(OplogApplierImplTest, DoNotLogNonSlowOpApplicationWhenSuccessful) {
expected << "applied op: CRUD { op: \"i\", ns: \"test.t\", o: { _id: 0 }, ts: Timestamp(1, 1), "
"t: 1, h: 1, v: 2 }, took "
<< applyDuration << "ms";
- ASSERT_EQUALS(0, countLogLinesContaining(expected.str()));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining(expected.str()));
}
class OplogApplierImplTxnTableTest : public OplogApplierImplTest {
public:
diff --git a/src/mongo/db/repl/replication_coordinator_impl_elect_v1_test.cpp b/src/mongo/db/repl/replication_coordinator_impl_elect_v1_test.cpp
index 06c6cd8b6cb..bb44ed0bcd4 100644
--- a/src/mongo/db/repl/replication_coordinator_impl_elect_v1_test.cpp
+++ b/src/mongo/db/repl/replication_coordinator_impl_elect_v1_test.cpp
@@ -268,7 +268,7 @@ TEST_F(ReplCoordTest, ElectionSucceedsWhenAllNodesVoteYea) {
ASSERT_EQ(1, lastVote.getValue().getTerm());
stopCapturingLogMessages();
- ASSERT_EQUALS(1, countLogLinesContaining("election succeeded"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("election succeeded"));
// Check that the numElectionTimeoutsCalled and the numElectionTimeoutsSuccessful election
// metrics have been incremented, and that none of the metrics that track the number of
@@ -322,7 +322,7 @@ TEST_F(ReplCoordTest, ElectionSucceedsWhenMaxSevenNodesVoteYea) {
ASSERT_EQ(1, lastVote.getValue().getTerm());
stopCapturingLogMessages();
- ASSERT_EQUALS(1, countLogLinesContaining("election succeeded"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("election succeeded"));
}
TEST_F(ReplCoordTest, ElectionFailsWhenInsufficientVotesAreReceivedDuringDryRun) {
@@ -388,8 +388,9 @@ TEST_F(ReplCoordTest, ElectionFailsWhenInsufficientVotesAreReceivedDuringDryRun)
}
net->exitNetwork();
stopCapturingLogMessages();
- ASSERT_EQUALS(
- 1, countLogLinesContaining("not running for primary, we received insufficient votes"));
+ ASSERT_EQUALS(1,
+ countTextFormatLogLinesContaining(
+ "not running for primary, we received insufficient votes"));
// Check that the node's election candidate metrics have been cleared, since it lost the dry-run
// election and will not become primary.
@@ -453,8 +454,9 @@ TEST_F(ReplCoordTest, ElectionFailsWhenDryRunResponseContainsANewerTerm) {
net->exitNetwork();
getReplCoord()->waitForElectionFinish_forTest();
stopCapturingLogMessages();
- ASSERT_EQUALS(
- 1, countLogLinesContaining("not running for primary, we have been superseded already"));
+ ASSERT_EQUALS(1,
+ countTextFormatLogLinesContaining(
+ "not running for primary, we have been superseded already"));
}
TEST_F(ReplCoordTest, NodeWillNotStandForElectionDuringHeartbeatReconfig) {
@@ -571,8 +573,8 @@ TEST_F(ReplCoordTest, NodeWillNotStandForElectionDuringHeartbeatReconfig) {
stopCapturingLogMessages();
// ensure node does not stand for election
ASSERT_EQUALS(1,
- countLogLinesContaining("Not standing for election; processing "
- "a configuration change"));
+ countTextFormatLogLinesContaining("Not standing for election; processing "
+ "a configuration change"));
globalFailPointRegistry().find("blockHeartbeatReconfigFinish")->setMode(FailPoint::off);
}
@@ -621,8 +623,9 @@ TEST_F(ReplCoordTest, ElectionFailsWhenInsufficientVotesAreReceivedDuringRequest
getReplCoord()->waitForElectionFinish_forTest();
stopCapturingLogMessages();
- ASSERT_EQUALS(1,
- countLogLinesContaining("not becoming primary, we received insufficient votes"));
+ ASSERT_EQUALS(
+ 1,
+ countTextFormatLogLinesContaining("not becoming primary, we received insufficient votes"));
}
TEST_F(ReplCoordTest, TransitionToRollbackFailsWhenElectionInProgress) {
@@ -714,8 +717,9 @@ TEST_F(ReplCoordTest, ElectionFailsWhenVoteRequestResponseContainsANewerTerm) {
getReplCoord()->waitForElectionFinish_forTest();
stopCapturingLogMessages();
- ASSERT_EQUALS(1,
- countLogLinesContaining("not becoming primary, we have been superseded already"));
+ ASSERT_EQUALS(
+ 1,
+ countTextFormatLogLinesContaining("not becoming primary, we have been superseded already"));
// Check that the node's election candidate metrics have been cleared, since it lost the actual
// election and will not become primary.
@@ -757,7 +761,7 @@ TEST_F(ReplCoordTest, ElectionFailsWhenTermChangesDuringDryRun) {
stopCapturingLogMessages();
ASSERT_EQUALS(1,
- countLogLinesContaining(
+ countTextFormatLogLinesContaining(
"not running for primary, we have been superseded already during dry run"));
}
@@ -808,8 +812,9 @@ TEST_F(ReplCoordTest, ElectionFailsWhenTermChangesDuringActualElection) {
net->exitNetwork();
getReplCoord()->waitForElectionFinish_forTest();
stopCapturingLogMessages();
- ASSERT_EQUALS(1,
- countLogLinesContaining("not becoming primary, we have been superseded already"));
+ ASSERT_EQUALS(
+ 1,
+ countTextFormatLogLinesContaining("not becoming primary, we have been superseded already"));
}
class TakeoverTest : public ReplCoordTest {
@@ -897,10 +902,11 @@ public:
ASSERT_EQ(lastVoteExpected.getTerm(), lastVote.getValue().getTerm());
if (reason == StartElectionReasonEnum::kPriorityTakeover) {
- ASSERT_EQUALS(1,
- countLogLinesContaining("Starting an election for a priority takeover"));
+ ASSERT_EQUALS(
+ 1,
+ countTextFormatLogLinesContaining("Starting an election for a priority takeover"));
}
- ASSERT_EQUALS(1, countLogLinesContaining("election succeeded"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("election succeeded"));
}
private:
@@ -1136,10 +1142,10 @@ TEST_F(TakeoverTest, PrefersPriorityToCatchupTakeoverIfNodeHasHighestPriority) {
ASSERT_FALSE(replCoord->getCatchupTakeover_forTest());
stopCapturingLogMessages();
- ASSERT_EQUALS(
- 1,
- countLogLinesContaining("I can take over the primary because I have a higher priority, "
- "the highest priority in the replica set, and fresher data."));
+ ASSERT_EQUALS(1,
+ countTextFormatLogLinesContaining(
+ "I can take over the primary because I have a higher priority, "
+ "the highest priority in the replica set, and fresher data."));
}
TEST_F(TakeoverTest, CatchupTakeoverNotScheduledTwice) {
@@ -1322,13 +1328,15 @@ TEST_F(TakeoverTest, CatchupTakeoverCallbackCanceledIfElectionTimeoutRuns) {
stopCapturingLogMessages();
- ASSERT_EQUALS(1, countLogLinesContaining("Starting an election, since we've seen no PRIMARY"));
+ ASSERT_EQUALS(
+ 1, countTextFormatLogLinesContaining("Starting an election, since we've seen no PRIMARY"));
// Make sure catchup takeover never happend and CatchupTakeover callback was canceled.
ASSERT_FALSE(replCoord->getCatchupTakeover_forTest());
ASSERT(replCoord->getMemberState().secondary());
- ASSERT_EQUALS(1, countLogLinesContaining("Canceling catchup takeover callback"));
- ASSERT_EQUALS(0, countLogLinesContaining("Starting an election for a catchup takeover"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("Canceling catchup takeover callback"));
+ ASSERT_EQUALS(0,
+ countTextFormatLogLinesContaining("Starting an election for a catchup takeover"));
}
TEST_F(TakeoverTest, CatchupTakeoverCanceledIfTransitionToRollback) {
@@ -1387,8 +1395,9 @@ TEST_F(TakeoverTest, CatchupTakeoverCanceledIfTransitionToRollback) {
// Make sure catchup takeover never happend and CatchupTakeover callback was canceled.
ASSERT_FALSE(replCoord->getCatchupTakeover_forTest());
- ASSERT_EQUALS(1, countLogLinesContaining("Canceling catchup takeover callback"));
- ASSERT_EQUALS(0, countLogLinesContaining("Starting an election for a catchup takeover"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("Canceling catchup takeover callback"));
+ ASSERT_EQUALS(0,
+ countTextFormatLogLinesContaining("Starting an election for a catchup takeover"));
}
TEST_F(TakeoverTest, SuccessfulCatchupTakeover) {
@@ -1446,7 +1455,8 @@ TEST_F(TakeoverTest, SuccessfulCatchupTakeover) {
// Since the heartbeats go through the catchupTakeoverTimeout, this log
// message happens already (otherwise it would happen in performSuccessfulTakeover).
- ASSERT_EQUALS(1, countLogLinesContaining("Starting an election for a catchup takeover"));
+ ASSERT_EQUALS(1,
+ countTextFormatLogLinesContaining("Starting an election for a catchup takeover"));
LastVote lastVoteExpected = LastVote(replCoord->getTerm() + 1, 0);
performSuccessfulTakeover(
@@ -1524,7 +1534,8 @@ TEST_F(TakeoverTest, CatchupTakeoverDryRunFailsPrimarySaysNo) {
now = respondToHeartbeatsUntil(
config, catchupTakeoverTime, HostAndPort("node2", 12345), behindOptime);
- ASSERT_EQUALS(1, countLogLinesContaining("Starting an election for a catchup takeover"));
+ ASSERT_EQUALS(1,
+ countTextFormatLogLinesContaining("Starting an election for a catchup takeover"));
// Simulate a dry run where the primary has caught up and is now ahead of the
// node trying to do the catchup takeover. All the secondary nodes respond
@@ -1570,7 +1581,7 @@ TEST_F(TakeoverTest, CatchupTakeoverDryRunFailsPrimarySaysNo) {
// Make sure an election wasn't called for and that we are still secondary.
ASSERT_EQUALS(1,
- countLogLinesContaining(
+ countTextFormatLogLinesContaining(
"not running for primary, the current primary responded no in the dry run"));
ASSERT(replCoord->getMemberState().secondary());
}
@@ -1630,7 +1641,8 @@ TEST_F(TakeoverTest, PrimaryCatchesUpBeforeCatchupTakeover) {
// Make sure we're secondary and that no catchup takeover election happened.
ASSERT(replCoord->getMemberState().secondary());
ASSERT_FALSE(replCoord->getCatchupTakeover_forTest());
- ASSERT_EQUALS(1, countLogLinesContaining("Not starting an election for a catchup takeover"));
+ ASSERT_EQUALS(
+ 1, countTextFormatLogLinesContaining("Not starting an election for a catchup takeover"));
}
TEST_F(TakeoverTest, PrimaryCatchesUpBeforeHighPriorityNodeCatchupTakeover) {
@@ -1690,7 +1702,8 @@ TEST_F(TakeoverTest, PrimaryCatchesUpBeforeHighPriorityNodeCatchupTakeover) {
// Make sure we're secondary and that no catchup takeover election happens.
ASSERT(replCoord->getMemberState().secondary());
ASSERT_FALSE(replCoord->getCatchupTakeover_forTest());
- ASSERT_EQUALS(1, countLogLinesContaining("Not starting an election for a catchup takeover"));
+ ASSERT_EQUALS(
+ 1, countTextFormatLogLinesContaining("Not starting an election for a catchup takeover"));
// Make sure that the priority takeover has now been scheduled and at the
// correct time.
@@ -1867,8 +1880,9 @@ TEST_F(TakeoverTest, DontCallForPriorityTakeoverWhenLaggedSameSecond) {
stopCapturingLogMessages();
ASSERT(replCoord->getMemberState().secondary());
- ASSERT_EQUALS(1,
- countLogLinesContaining("Not standing for election because member is not "
+ ASSERT_EQUALS(
+ 1,
+ countTextFormatLogLinesContaining("Not standing for election because member is not "
"caught up enough to the most up-to-date member to "
"call for priority takeover"));
@@ -1951,8 +1965,9 @@ TEST_F(TakeoverTest, DontCallForPriorityTakeoverWhenLaggedDifferentSecond) {
stopCapturingLogMessages();
ASSERT(replCoord->getMemberState().secondary());
- ASSERT_EQUALS(1,
- countLogLinesContaining("Not standing for election because member is not "
+ ASSERT_EQUALS(
+ 1,
+ countTextFormatLogLinesContaining("Not standing for election because member is not "
"caught up enough to the most up-to-date member to "
"call for priority takeover"));
@@ -2255,7 +2270,9 @@ TEST_F(PrimaryCatchUpTest, PrimaryDoesNotNeedToCatchUp) {
ASSERT_EQUALS(2, count);
ASSERT(getReplCoord()->getApplierState() == ApplierState::Draining);
stopCapturingLogMessages();
- ASSERT_EQ(1, countLogLinesContaining("Caught up to the latest optime known via heartbeats"));
+ ASSERT_EQ(
+ 1,
+ countTextFormatLogLinesContaining("Caught up to the latest optime known via heartbeats"));
auto opCtx = makeOperationContext();
signalDrainComplete(opCtx.get());
Lock::GlobalLock lock(opCtx.get(), MODE_IX);
@@ -2309,7 +2326,8 @@ TEST_F(PrimaryCatchUpTest, CatchupSucceeds) {
advanceMyLastAppliedOpTime(time2, Date_t() + Seconds(time2.getSecs()));
ASSERT(getReplCoord()->getApplierState() == ApplierState::Draining);
stopCapturingLogMessages();
- ASSERT_EQUALS(1, countLogLinesContaining("Caught up to the latest known optime successfully"));
+ ASSERT_EQUALS(
+ 1, countTextFormatLogLinesContaining("Caught up to the latest known optime successfully"));
auto opCtx = makeOperationContext();
signalDrainComplete(opCtx.get());
Lock::GlobalLock lock(opCtx.get(), MODE_IX);
@@ -2343,7 +2361,7 @@ TEST_F(PrimaryCatchUpTest, CatchupTimeout) {
});
ASSERT(getReplCoord()->getApplierState() == ApplierState::Draining);
stopCapturingLogMessages();
- ASSERT_EQUALS(1, countLogLinesContaining("Catchup timed out"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("Catchup timed out"));
auto opCtx = makeOperationContext();
signalDrainComplete(opCtx.get());
Lock::GlobalLock lock(opCtx.get(), MODE_IX);
@@ -2382,7 +2400,9 @@ TEST_F(PrimaryCatchUpTest, CannotSeeAllNodes) {
});
ASSERT(getReplCoord()->getApplierState() == ApplierState::Draining);
stopCapturingLogMessages();
- ASSERT_EQ(1, countLogLinesContaining("Caught up to the latest optime known via heartbeats"));
+ ASSERT_EQ(
+ 1,
+ countTextFormatLogLinesContaining("Caught up to the latest optime known via heartbeats"));
auto opCtx = makeOperationContext();
signalDrainComplete(opCtx.get());
Lock::GlobalLock lock(opCtx.get(), MODE_IX);
@@ -2422,7 +2442,9 @@ TEST_F(PrimaryCatchUpTest, HeartbeatTimeout) {
});
ASSERT(getReplCoord()->getApplierState() == ApplierState::Draining);
stopCapturingLogMessages();
- ASSERT_EQ(1, countLogLinesContaining("Caught up to the latest optime known via heartbeats"));
+ ASSERT_EQ(
+ 1,
+ countTextFormatLogLinesContaining("Caught up to the latest optime known via heartbeats"));
auto opCtx = makeOperationContext();
signalDrainComplete(opCtx.get());
Lock::GlobalLock lock(opCtx.get(), MODE_IX);
@@ -2459,9 +2481,9 @@ TEST_F(PrimaryCatchUpTest, PrimaryStepsDownBeforeHeartbeatRefreshing) {
ASSERT_TRUE(getReplCoord()->getMemberState().secondary());
ASSERT(getReplCoord()->getApplierState() == ApplierState::Running);
stopCapturingLogMessages();
- ASSERT_EQUALS(1, countLogLinesContaining("Exited primary catch-up mode"));
- ASSERT_EQUALS(0, countLogLinesContaining("Caught up to the latest"));
- ASSERT_EQUALS(0, countLogLinesContaining("Catchup timed out"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("Exited primary catch-up mode"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("Caught up to the latest"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("Catchup timed out"));
auto opCtx = makeOperationContext();
Lock::GlobalLock lock(opCtx.get(), MODE_IX);
ASSERT_FALSE(getReplCoord()->canAcceptWritesForDatabase(opCtx.get(), "test"));
@@ -2507,9 +2529,9 @@ TEST_F(PrimaryCatchUpTest, PrimaryStepsDownDuringCatchUp) {
// replyHeartbeatsAndRunUntil(getNet()->now() + config.getCatchUpTimeoutPeriod());
ASSERT(getReplCoord()->getApplierState() == ApplierState::Running);
stopCapturingLogMessages();
- ASSERT_EQUALS(1, countLogLinesContaining("Exited primary catch-up mode"));
- ASSERT_EQUALS(0, countLogLinesContaining("Caught up to the latest"));
- ASSERT_EQUALS(0, countLogLinesContaining("Catchup timed out"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("Exited primary catch-up mode"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("Caught up to the latest"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("Catchup timed out"));
auto opCtx = makeOperationContext();
Lock::GlobalLock lock(opCtx.get(), MODE_IX);
ASSERT_FALSE(getReplCoord()->canAcceptWritesForDatabase(opCtx.get(), "test"));
@@ -2551,7 +2573,7 @@ TEST_F(PrimaryCatchUpTest, PrimaryStepsDownDuringDrainMode) {
advanceMyLastAppliedOpTime(time2, Date_t() + Seconds(time2.getSecs()));
ASSERT(replCoord->getApplierState() == ApplierState::Draining);
stopCapturingLogMessages();
- ASSERT_EQUALS(1, countLogLinesContaining("Caught up to the latest"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("Caught up to the latest"));
// Check that the number of elections requiring primary catchup was incremented.
auto opCtx = makeOperationContext();
@@ -2636,7 +2658,7 @@ TEST_F(PrimaryCatchUpTest, FreshestNodeBecomesAvailableLater) {
// The node is still in catchup mode, but the target optime has been set.
ASSERT(getReplCoord()->getApplierState() == ApplierState::Running);
stopCapturingLogMessages();
- ASSERT_EQ(1, countLogLinesContaining("Heartbeats updated catchup target optime"));
+ ASSERT_EQ(1, countTextFormatLogLinesContaining("Heartbeats updated catchup target optime"));
ASSERT_EQUALS(time3,
ReplicationMetrics::get(getServiceContext()).getTargetCatchupOpTime_forTesting());
@@ -2658,7 +2680,7 @@ TEST_F(PrimaryCatchUpTest, FreshestNodeBecomesAvailableLater) {
// The node is still in catchup mode, but the target optime has been updated.
ASSERT(getReplCoord()->getApplierState() == ApplierState::Running);
stopCapturingLogMessages();
- ASSERT_EQ(1, countLogLinesContaining("Heartbeats updated catchup target optime"));
+ ASSERT_EQ(1, countTextFormatLogLinesContaining("Heartbeats updated catchup target optime"));
ASSERT_EQUALS(time4,
ReplicationMetrics::get(getServiceContext()).getTargetCatchupOpTime_forTesting());
@@ -2671,7 +2693,7 @@ TEST_F(PrimaryCatchUpTest, FreshestNodeBecomesAvailableLater) {
advanceMyLastAppliedOpTime(time4, Date_t() + Seconds(time4.getSecs()));
ASSERT(getReplCoord()->getApplierState() == ApplierState::Draining);
stopCapturingLogMessages();
- ASSERT_EQ(1, countLogLinesContaining("Caught up to the latest"));
+ ASSERT_EQ(1, countTextFormatLogLinesContaining("Caught up to the latest"));
auto opCtx = makeOperationContext();
signalDrainComplete(opCtx.get());
Lock::GlobalLock lock(opCtx.get(), MODE_IX);
@@ -2730,9 +2752,9 @@ TEST_F(PrimaryCatchUpTest, InfiniteTimeoutAndAbort) {
ASSERT(getReplCoord()->getApplierState() == ApplierState::Draining);
stopCapturingLogMessages();
- ASSERT_EQUALS(1, countLogLinesContaining("Exited primary catch-up mode"));
- ASSERT_EQUALS(0, countLogLinesContaining("Caught up to the latest"));
- ASSERT_EQUALS(0, countLogLinesContaining("Catchup timed out"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("Exited primary catch-up mode"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("Caught up to the latest"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("Catchup timed out"));
auto opCtx = makeOperationContext();
signalDrainComplete(opCtx.get());
Lock::GlobalLock lock(opCtx.get(), MODE_IX);
@@ -2761,7 +2783,7 @@ TEST_F(PrimaryCatchUpTest, ZeroTimeout) {
ReplSetConfig config = setUp3NodeReplSetAndRunForElection(time1, 0);
ASSERT(getReplCoord()->getApplierState() == ApplierState::Draining);
stopCapturingLogMessages();
- ASSERT_EQUALS(1, countLogLinesContaining("Skipping primary catchup"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("Skipping primary catchup"));
auto opCtx = makeOperationContext();
signalDrainComplete(opCtx.get());
Lock::GlobalLock lock(opCtx.get(), MODE_IX);
@@ -2802,9 +2824,9 @@ TEST_F(PrimaryCatchUpTest, CatchUpFailsDueToPrimaryStepDown) {
ASSERT(getReplCoord()->getApplierState() == ApplierState::Running);
stopCapturingLogMessages();
- ASSERT_EQUALS(1, countLogLinesContaining("Exited primary catch-up mode"));
- ASSERT_EQUALS(0, countLogLinesContaining("Caught up to the latest"));
- ASSERT_EQUALS(0, countLogLinesContaining("Catchup timed out"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("Exited primary catch-up mode"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("Caught up to the latest"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("Catchup timed out"));
// Check that the number of elections requiring primary catchup was incremented.
ASSERT_EQ(1, ReplicationMetrics::get(opCtx.get()).getNumCatchUps_forTesting());
diff --git a/src/mongo/db/repl/replication_coordinator_impl_reconfig_test.cpp b/src/mongo/db/repl/replication_coordinator_impl_reconfig_test.cpp
index 5822e6c5506..e79f7bc8866 100644
--- a/src/mongo/db/repl/replication_coordinator_impl_reconfig_test.cpp
+++ b/src/mongo/db/repl/replication_coordinator_impl_reconfig_test.cpp
@@ -605,8 +605,9 @@ TEST_F(ReplCoordTest, NodeDoesNotAcceptHeartbeatReconfigWhileInTheMidstOfReconfi
// respond to reconfig's quorum check so that we can join that thread and exit cleanly
net->exitNetwork();
stopCapturingLogMessages();
- ASSERT_EQUALS(
- 1, countLogLinesContaining("because already in the midst of a configuration process"));
+ ASSERT_EQUALS(1,
+ countTextFormatLogLinesContaining(
+ "because already in the midst of a configuration process"));
shutdown(opCtx.get());
reconfigThread.join();
setMinimumLoggedSeverity(logger::LogSeverity::Log());
diff --git a/src/mongo/db/repl/replication_coordinator_impl_test.cpp b/src/mongo/db/repl/replication_coordinator_impl_test.cpp
index d97dedf157f..a708941155d 100644
--- a/src/mongo/db/repl/replication_coordinator_impl_test.cpp
+++ b/src/mongo/db/repl/replication_coordinator_impl_test.cpp
@@ -192,7 +192,7 @@ TEST_F(ReplCoordTest, NodeEntersRemovedStateWhenStartingUpWithALocalConfigWhichL
<< "node2:54321"))),
HostAndPort("node3", 12345));
stopCapturingLogMessages();
- ASSERT_EQUALS(1, countLogLinesContaining("NodeNotFound"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("NodeNotFound"));
ASSERT_EQUALS(MemberState::RS_REMOVED, getReplCoord()->getMemberState().s);
}
@@ -207,7 +207,7 @@ TEST_F(ReplCoordTest,
<< "node1:12345"))),
HostAndPort("node1", 12345));
stopCapturingLogMessages();
- ASSERT_EQUALS(1, countLogLinesContaining("reports set name of notMySet,"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("reports set name of notMySet,"));
ASSERT_EQUALS(MemberState::RS_REMOVED, getReplCoord()->getMemberState().s);
}
@@ -215,7 +215,7 @@ TEST_F(ReplCoordTest, NodeEntersStartupStateWhenStartingUpWithNoLocalConfig) {
startCapturingLogMessages();
start();
stopCapturingLogMessages();
- ASSERT_EQUALS(3, countLogLinesContaining("Did not find local "));
+ ASSERT_EQUALS(3, countTextFormatLogLinesContaining("Did not find local "));
ASSERT_EQUALS(MemberState::RS_STARTUP, getReplCoord()->getMemberState().s);
}
@@ -3534,7 +3534,8 @@ TEST_F(ReplCoordTest, LogAMessageWhenShutDownBeforeReplicationStartUpFinished) {
getReplCoord()->shutdown(opCtx.get());
}
stopCapturingLogMessages();
- ASSERT_EQUALS(1, countLogLinesContaining("shutdown() called before startup() finished"));
+ ASSERT_EQUALS(1,
+ countTextFormatLogLinesContaining("shutdown() called before startup() finished"));
}
TEST_F(ReplCoordTest, DoNotProcessSelfWhenUpdatePositionContainsInfoAboutSelf) {
@@ -5671,15 +5672,15 @@ TEST_F(ReplCoordTest, CancelAndRescheduleElectionTimeoutLogging) {
// Setting mode to secondary should schedule the election timeout.
ReplicationCoordinatorImpl* replCoord = getReplCoord();
ASSERT_OK(replCoord->setFollowerMode(MemberState::RS_SECONDARY));
- ASSERT_EQ(1, countLogLinesContaining("Scheduling election timeout callback"));
- ASSERT_EQ(0, countLogLinesContaining("Rescheduling election timeout callback"));
- ASSERT_EQ(0, countLogLinesContaining("Canceling election timeout callback"));
+ ASSERT_EQ(1, countTextFormatLogLinesContaining("Scheduling election timeout callback"));
+ ASSERT_EQ(0, countTextFormatLogLinesContaining("Rescheduling election timeout callback"));
+ ASSERT_EQ(0, countTextFormatLogLinesContaining("Canceling election timeout callback"));
// Scheduling again should produce the "rescheduled", not the "scheduled", message .
replCoord->cancelAndRescheduleElectionTimeout();
- ASSERT_EQ(1, countLogLinesContaining("Scheduling election timeout callback"));
- ASSERT_EQ(1, countLogLinesContaining("Rescheduling election timeout callback"));
- ASSERT_EQ(1, countLogLinesContaining("Canceling election timeout callback"));
+ ASSERT_EQ(1, countTextFormatLogLinesContaining("Scheduling election timeout callback"));
+ ASSERT_EQ(1, countTextFormatLogLinesContaining("Rescheduling election timeout callback"));
+ ASSERT_EQ(1, countTextFormatLogLinesContaining("Canceling election timeout callback"));
auto net = getNet();
net->enterNetwork();
@@ -5703,9 +5704,9 @@ TEST_F(ReplCoordTest, CancelAndRescheduleElectionTimeoutLogging) {
net->exitNetwork();
// The election should have scheduled (not rescheduled) another timeout.
- ASSERT_EQ(2, countLogLinesContaining("Scheduling election timeout callback"));
- ASSERT_EQ(1, countLogLinesContaining("Rescheduling election timeout callback"));
- ASSERT_EQ(1, countLogLinesContaining("Canceling election timeout callback"));
+ ASSERT_EQ(2, countTextFormatLogLinesContaining("Scheduling election timeout callback"));
+ ASSERT_EQ(1, countTextFormatLogLinesContaining("Rescheduling election timeout callback"));
+ ASSERT_EQ(1, countTextFormatLogLinesContaining("Canceling election timeout callback"));
setMinimumLoggedSeverity(logger::LogComponent::kReplicationElection,
logger::LogSeverity::Debug(4));
@@ -5716,9 +5717,9 @@ TEST_F(ReplCoordTest, CancelAndRescheduleElectionTimeoutLogging) {
replCoord->cancelAndRescheduleElectionTimeout();
// We should not see this reschedule because it should be at log level 5.
- ASSERT_EQ(2, countLogLinesContaining("Scheduling election timeout callback"));
- ASSERT_EQ(1, countLogLinesContaining("Rescheduling election timeout callback"));
- ASSERT_EQ(1, countLogLinesContaining("Canceling election timeout callback"));
+ ASSERT_EQ(2, countTextFormatLogLinesContaining("Scheduling election timeout callback"));
+ ASSERT_EQ(1, countTextFormatLogLinesContaining("Rescheduling election timeout callback"));
+ ASSERT_EQ(1, countTextFormatLogLinesContaining("Canceling election timeout callback"));
net->enterNetwork();
until = electionTimeoutWhen + Milliseconds(1001);
@@ -5729,9 +5730,9 @@ TEST_F(ReplCoordTest, CancelAndRescheduleElectionTimeoutLogging) {
stopCapturingLogMessages();
// We should see this reschedule at level 4 because it has been over 1 sec since we logged
// at level 4.
- ASSERT_EQ(2, countLogLinesContaining("Scheduling election timeout callback"));
- ASSERT_EQ(2, countLogLinesContaining("Rescheduling election timeout callback"));
- ASSERT_EQ(2, countLogLinesContaining("Canceling election timeout callback"));
+ ASSERT_EQ(2, countTextFormatLogLinesContaining("Scheduling election timeout callback"));
+ ASSERT_EQ(2, countTextFormatLogLinesContaining("Rescheduling election timeout callback"));
+ ASSERT_EQ(2, countTextFormatLogLinesContaining("Canceling election timeout callback"));
}
TEST_F(ReplCoordTest, AdvanceCommittedSnapshotToMostRecentSnapshotPriorToOpTimeWhenOpTimeChanges) {
diff --git a/src/mongo/db/repl/replication_recovery_test.cpp b/src/mongo/db/repl/replication_recovery_test.cpp
index c633e981542..4831a612b7e 100644
--- a/src/mongo/db/repl/replication_recovery_test.cpp
+++ b/src/mongo/db/repl/replication_recovery_test.cpp
@@ -1323,7 +1323,8 @@ TEST_F(ReplicationRecoveryTest, RecoverFromOplogUpToWithEmptyOplog) {
recovery.recoverFromOplogUpTo(opCtx, Timestamp(5, 5));
stopCapturingLogMessages();
- ASSERT_EQUALS(1, countLogLinesContaining("No stored oplog entries to apply for recovery."));
+ ASSERT_EQUALS(
+ 1, countTextFormatLogLinesContaining("No stored oplog entries to apply for recovery."));
_assertDocsInTestCollection(opCtx, {});
ASSERT_EQ(getConsistencyMarkers()->getAppliedThrough(opCtx), OpTime(Timestamp(0, 0), 1));
}
diff --git a/src/mongo/db/repl/rs_rollback_test.cpp b/src/mongo/db/repl/rs_rollback_test.cpp
index 462ca0f708c..a5b89690129 100644
--- a/src/mongo/db/repl/rs_rollback_test.cpp
+++ b/src/mongo/db/repl/rs_rollback_test.cpp
@@ -497,7 +497,8 @@ TEST_F(RSRollbackTest, RollbackInsertDocumentWithNoId) {
stopCapturingLogMessages();
ASSERT_EQUALS(ErrorCodes::UnrecoverableRollbackError, status.code());
ASSERT_STRING_CONTAINS(status.reason(), "unable to determine common point");
- ASSERT_EQUALS(1, countLogLinesContaining("Cannot roll back op with no _id. ns: test.t,"));
+ ASSERT_EQUALS(
+ 1, countTextFormatLogLinesContaining("Cannot roll back op with no _id. ns: test.t,"));
ASSERT_FALSE(rollbackSource.called);
}
@@ -533,11 +534,11 @@ TEST_F(RSRollbackTest, RollbackCreateIndexCommand) {
_coordinator,
_replicationProcess.get()));
stopCapturingLogMessages();
- ASSERT_EQUALS(
- 1,
- countLogLinesContaining(str::stream()
- << "Dropped index in rollback for collection: " << nss.toString()
- << ", UUID: " << options.uuid->toString() << ", index: a_1"));
+ ASSERT_EQUALS(1,
+ countTextFormatLogLinesContaining(
+ str::stream()
+ << "Dropped index in rollback for collection: " << nss.toString()
+ << ", UUID: " << options.uuid->toString() << ", index: a_1"));
{
Lock::DBLock dbLock(_opCtx.get(), nss.db(), MODE_S);
auto indexCatalog = collection->getIndexCatalog();
@@ -576,7 +577,8 @@ TEST_F(RSRollbackTest, RollbackCreateIndexCommandIndexNotInCatalog) {
_coordinator,
_replicationProcess.get()));
stopCapturingLogMessages();
- ASSERT_EQUALS(1, countLogLinesContaining("Rollback failed to drop index a_1 in test.t"));
+ ASSERT_EQUALS(1,
+ countTextFormatLogLinesContaining("Rollback failed to drop index a_1 in test.t"));
{
Lock::DBLock dbLock(_opCtx.get(), "test", MODE_S);
auto indexCatalog = collection->getIndexCatalog();
@@ -785,12 +787,12 @@ TEST_F(RSRollbackTest, RollingBackDropAndCreateOfSameIndexNameWithDifferentSpecs
ASSERT(indexCatalog);
ASSERT_EQUALS(2, indexCatalog->numIndexesReady(_opCtx.get()));
ASSERT_EQUALS(1,
- countLogLinesContaining(
+ countTextFormatLogLinesContaining(
str::stream()
<< "Dropped index in rollback for collection: " << nss.toString()
<< ", UUID: " << options.uuid->toString() << ", index: a_1"));
ASSERT_EQUALS(1,
- countLogLinesContaining(
+ countTextFormatLogLinesContaining(
str::stream()
<< "Created index in rollback for collection: " << nss.toString()
<< ", UUID: " << options.uuid->toString() << ", index: a_1"));
@@ -840,7 +842,7 @@ TEST_F(RSRollbackTest, RollbackCreateIndexCommandMissingIndexName) {
ASSERT_EQUALS(ErrorCodes::UnrecoverableRollbackError, status.code());
ASSERT_STRING_CONTAINS(status.reason(), "unable to determine common point");
ASSERT_EQUALS(1,
- countLogLinesContaining(
+ countTextFormatLogLinesContaining(
"Missing index name in createIndexes operation on rollback, document: "));
}
@@ -1982,7 +1984,7 @@ TEST_F(RSRollbackTest, RollbackCollectionModificationCommand) {
stopCapturingLogMessages();
ASSERT_TRUE(rollbackSource.called);
- for (const auto& message : getCapturedLogMessages()) {
+ for (const auto& message : getCapturedTextFormatLogMessages()) {
ASSERT_TRUE(message.find("ignoring op with no _id during rollback. ns: test.t") ==
std::string::npos);
}
@@ -2765,7 +2767,8 @@ TEST_F(RSRollbackTest, RollbackReturnsImmediatelyOnFailureToTransitionToRollback
_replicationProcess.get());
stopCapturingLogMessages();
- ASSERT_EQUALS(1, countLogLinesContaining("Cannot transition from SECONDARY to ROLLBACK"));
+ ASSERT_EQUALS(
+ 1, countTextFormatLogLinesContaining("Cannot transition from SECONDARY to ROLLBACK"));
ASSERT_EQUALS(MemberState(MemberState::RS_SECONDARY), _coordinator->getMemberState());
}
@@ -2810,8 +2813,9 @@ TEST_F(RSRollbackTest, RollbackLogsRetryMessageAndReturnsOnNonUnrecoverableRollb
noopSleepSecsFn);
stopCapturingLogMessages();
- ASSERT_EQUALS(
- 1, countLogLinesContaining("Rollback cannot complete at this time (retrying later)"));
+ ASSERT_EQUALS(1,
+ countTextFormatLogLinesContaining(
+ "Rollback cannot complete at this time (retrying later)"));
ASSERT_EQUALS(MemberState(MemberState::RS_RECOVERING), _coordinator->getMemberState());
}
diff --git a/src/mongo/db/repl/topology_coordinator_v1_test.cpp b/src/mongo/db/repl/topology_coordinator_v1_test.cpp
index 69f04103eb1..ed99ee92be6 100644
--- a/src/mongo/db/repl/topology_coordinator_v1_test.cpp
+++ b/src/mongo/db/repl/topology_coordinator_v1_test.cpp
@@ -106,7 +106,7 @@ protected:
}
int64_t countLogLinesContaining(const std::string& needle) {
- const auto& msgs = getCapturedLogMessages();
+ const auto& msgs = getCapturedTextFormatLogMessages();
return std::count_if(
msgs.begin(), msgs.end(), [&](const auto& s) { return stringContains(s, needle); });
}
diff --git a/src/mongo/db/repl/vote_requester_test.cpp b/src/mongo/db/repl/vote_requester_test.cpp
index dd8dedb0ccb..94ba342ca11 100644
--- a/src/mongo/db/repl/vote_requester_test.cpp
+++ b/src/mongo/db/repl/vote_requester_test.cpp
@@ -95,7 +95,7 @@ public:
protected:
int64_t countLogLinesContaining(const std::string& needle) {
- const auto& msgs = getCapturedLogMessages();
+ const auto& msgs = getCapturedTextFormatLogMessages();
return std::count_if(
msgs.begin(), msgs.end(), [&](const auto& s) { return stringContains(s, needle); });
}
diff --git a/src/mongo/db/s/transaction_coordinator_test.cpp b/src/mongo/db/s/transaction_coordinator_test.cpp
index d21e4caf34b..93083cb9739 100644
--- a/src/mongo/db/s/transaction_coordinator_test.cpp
+++ b/src/mongo/db/s/transaction_coordinator_test.cpp
@@ -1676,7 +1676,7 @@ TEST_F(TransactionCoordinatorMetricsTest, SimpleTwoPhaseCommitRealCoordinator) {
stopCapturingLogMessages();
// Slow log line is logged since the coordination completed successfully.
- ASSERT_EQUALS(1, countLogLinesContaining("two-phase commit parameters:"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("two-phase commit parameters:"));
}
TEST_F(TransactionCoordinatorMetricsTest, CoordinatorIsCanceledWhileInactive) {
@@ -1721,7 +1721,7 @@ TEST_F(TransactionCoordinatorMetricsTest, CoordinatorIsCanceledWhileInactive) {
stopCapturingLogMessages();
// Slow log line is not logged since the coordination did not complete successfully.
- ASSERT_EQUALS(0, countLogLinesContaining("two-phase commit parameters:"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("two-phase commit parameters:"));
}
TEST_F(TransactionCoordinatorMetricsTest, CoordinatorsAWSIsShutDownWhileCoordinatorIsInactive) {
@@ -1764,7 +1764,7 @@ TEST_F(TransactionCoordinatorMetricsTest, CoordinatorsAWSIsShutDownWhileCoordina
stopCapturingLogMessages();
// Slow log line is not logged since the coordination did not complete successfully.
- ASSERT_EQUALS(0, countLogLinesContaining("two-phase commit parameters:"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("two-phase commit parameters:"));
}
TEST_F(TransactionCoordinatorMetricsTest,
@@ -1825,7 +1825,7 @@ TEST_F(TransactionCoordinatorMetricsTest,
stopCapturingLogMessages();
// Slow log line is not logged since the coordination did not complete successfully.
- ASSERT_EQUALS(0, countLogLinesContaining("two-phase commit parameters:"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("two-phase commit parameters:"));
}
TEST_F(TransactionCoordinatorMetricsTest,
@@ -1890,7 +1890,7 @@ TEST_F(TransactionCoordinatorMetricsTest,
stopCapturingLogMessages();
// Slow log line is not logged since the coordination did not complete successfully.
- ASSERT_EQUALS(0, countLogLinesContaining("two-phase commit parameters:"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("two-phase commit parameters:"));
}
TEST_F(TransactionCoordinatorMetricsTest,
@@ -1957,7 +1957,7 @@ TEST_F(TransactionCoordinatorMetricsTest,
stopCapturingLogMessages();
// Slow log line is not logged since the coordination did not complete successfully.
- ASSERT_EQUALS(0, countLogLinesContaining("two-phase commit parameters:"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("two-phase commit parameters:"));
}
TEST_F(TransactionCoordinatorMetricsTest,
@@ -2028,7 +2028,7 @@ TEST_F(TransactionCoordinatorMetricsTest,
stopCapturingLogMessages();
// Slow log line is not logged since the coordination did not complete successfully.
- ASSERT_EQUALS(0, countLogLinesContaining("two-phase commit parameters:"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("two-phase commit parameters:"));
}
TEST_F(TransactionCoordinatorMetricsTest, CoordinatorsAWSIsShutDownWhileCoordinatorIsDeletingDoc) {
@@ -2105,19 +2105,19 @@ TEST_F(TransactionCoordinatorMetricsTest, CoordinatorsAWSIsShutDownWhileCoordina
stopCapturingLogMessages();
// Slow log line is not logged since the coordination did not complete successfully.
- ASSERT_EQUALS(0, countLogLinesContaining("two-phase commit parameters:"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("two-phase commit parameters:"));
}
TEST_F(TransactionCoordinatorMetricsTest, LogsTransactionAtLogLevelOne) {
setMinimumLoggedSeverity(logger::LogComponent::kTransaction, logger::LogSeverity::Debug(1));
runSimpleTwoPhaseCommitWithCommitDecisionAndCaptureLogLines();
- ASSERT_EQUALS(1, countLogLinesContaining("two-phase commit parameters:"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("two-phase commit parameters:"));
}
TEST_F(TransactionCoordinatorMetricsTest, DoesNotLogTransactionAtLogLevelZero) {
setMinimumLoggedSeverity(logger::LogComponent::kTransaction, logger::LogSeverity::Log());
runSimpleTwoPhaseCommitWithCommitDecisionAndCaptureLogLines();
- ASSERT_EQUALS(0, countLogLinesContaining("two-phase commit parameters:"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("two-phase commit parameters:"));
}
TEST_F(TransactionCoordinatorMetricsTest, DoesNotLogTransactionsUnderSlowMSThreshold) {
@@ -2146,7 +2146,7 @@ TEST_F(TransactionCoordinatorMetricsTest, DoesNotLogTransactionsUnderSlowMSThres
coordinator.onCompletion().get();
stopCapturingLogMessages();
- ASSERT_EQUALS(0, countLogLinesContaining("two-phase commit parameters:"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("two-phase commit parameters:"));
}
TEST_F(
@@ -2177,7 +2177,7 @@ TEST_F(
coordinator.onCompletion().get();
stopCapturingLogMessages();
- ASSERT_EQUALS(0, countLogLinesContaining("two-phase commit parameters:"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("two-phase commit parameters:"));
}
TEST_F(TransactionCoordinatorMetricsTest, LogsTransactionsOverSlowMSThreshold) {
@@ -2206,7 +2206,7 @@ TEST_F(TransactionCoordinatorMetricsTest, LogsTransactionsOverSlowMSThreshold) {
coordinator.onCompletion().get();
stopCapturingLogMessages();
- ASSERT_EQUALS(1, countLogLinesContaining("two-phase commit parameters:"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("two-phase commit parameters:"));
}
TEST_F(TransactionCoordinatorMetricsTest, SlowLogLineIncludesTransactionParameters) {
@@ -2214,16 +2214,17 @@ TEST_F(TransactionCoordinatorMetricsTest, SlowLogLineIncludesTransactionParamete
BSONObjBuilder lsidBob;
_lsid.serialize(&lsidBob);
ASSERT_EQUALS(1,
- countLogLinesContaining(str::stream()
- << "parameters:{ lsid: " << lsidBob.done().toString()
- << ", txnNumber: " << _txnNumber));
+ countTextFormatLogLinesContaining(
+ str::stream() << "parameters:{ lsid: " << lsidBob.done().toString()
+ << ", txnNumber: " << _txnNumber));
}
TEST_F(TransactionCoordinatorMetricsTest,
SlowLogLineIncludesTerminationCauseAndCommitTimestampForCommitDecision) {
runSimpleTwoPhaseCommitWithCommitDecisionAndCaptureLogLines();
- ASSERT_EQUALS(
- 1, countLogLinesContaining("terminationCause:committed, commitTimestamp: Timestamp(1, 1)"));
+ ASSERT_EQUALS(1,
+ countTextFormatLogLinesContaining(
+ "terminationCause:committed, commitTimestamp: Timestamp(1, 1)"));
}
TEST_F(TransactionCoordinatorMetricsTest, SlowLogLineIncludesTerminationCauseForAbortDecision) {
@@ -2246,16 +2247,17 @@ TEST_F(TransactionCoordinatorMetricsTest, SlowLogLineIncludesTerminationCauseFor
coordinator.onCompletion().get();
stopCapturingLogMessages();
- ASSERT_EQUALS(1, countLogLinesContaining("terminationCause:aborted"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("terminationCause:aborted"));
ASSERT_EQUALS(
1,
- countLogLinesContaining("terminationDetails: NoSuchTransaction: from shard s1") +
- countLogLinesContaining("terminationDetails: NoSuchTransaction: from shard s2"));
+ countTextFormatLogLinesContaining("terminationDetails: NoSuchTransaction: from shard s1") +
+ countTextFormatLogLinesContaining(
+ "terminationDetails: NoSuchTransaction: from shard s2"));
}
TEST_F(TransactionCoordinatorMetricsTest, SlowLogLineIncludesNumParticipants) {
runSimpleTwoPhaseCommitWithCommitDecisionAndCaptureLogLines();
- ASSERT_EQUALS(1, countLogLinesContaining("numParticipants:2"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("numParticipants:2"));
}
TEST_F(TransactionCoordinatorMetricsTest, SlowLogLineIncludesStepDurationsAndTotalDuration) {
@@ -2331,12 +2333,15 @@ TEST_F(TransactionCoordinatorMetricsTest, SlowLogLineIncludesStepDurationsAndTot
// Note: The waiting for decision acks and deleting coordinator doc durations are not reported.
ASSERT_EQUALS(1,
- countLogLinesContaining("stepDurations:{ writingParticipantListMicros: "
- "100000, waitingForVotesMicros: 100000, "
- "writingDecisionMicros: 100000, "
- "waitingForDecisionAcksMicros: 100000, "
- "deletingCoordinatorDocMicros: 100000 }"));
- ASSERT_EQUALS(1, countLogLinesContaining(" 500ms\n") + countLogLinesContaining(" 500ms\r\n"));
+ countTextFormatLogLinesContaining("stepDurations:{ writingParticipantListMicros: "
+ "100000, waitingForVotesMicros: 100000, "
+ "writingDecisionMicros: 100000, "
+ "waitingForDecisionAcksMicros: 100000, "
+ "deletingCoordinatorDocMicros: 100000 }"));
+ const auto& logs = getCapturedTextFormatLogMessages();
+ ASSERT_EQUALS(1, std::count_if(logs.begin(), logs.end(), [](const std::string& line) {
+ return StringData(line).endsWith(" 500ms");
+ }));
}
TEST_F(TransactionCoordinatorMetricsTest, ServerStatusSectionIncludesTotalCreated) {
diff --git a/src/mongo/db/transaction_participant_test.cpp b/src/mongo/db/transaction_participant_test.cpp
index 90de929be2d..3e6c30ceb23 100644
--- a/src/mongo/db/transaction_participant_test.cpp
+++ b/src/mongo/db/transaction_participant_test.cpp
@@ -3292,7 +3292,7 @@ TEST_F(TransactionsMetricsTest, LogTransactionInfoAfterSlowCommit) {
std::string expectedTransactionInfo = "transaction " +
txnParticipant.getTransactionInfoForLogForTest(
opCtx(), &lockerInfo->stats, true, readConcernArgs);
- ASSERT_EQUALS(1, countLogLinesContaining(expectedTransactionInfo));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining(expectedTransactionInfo));
}
TEST_F(TransactionsMetricsTest, LogPreparedTransactionInfoAfterSlowCommit) {
@@ -3329,7 +3329,7 @@ TEST_F(TransactionsMetricsTest, LogPreparedTransactionInfoAfterSlowCommit) {
std::string expectedTransactionInfo = "transaction " +
txnParticipant.getTransactionInfoForLogForTest(
opCtx(), &lockerInfo->stats, true, readConcernArgs);
- ASSERT_EQUALS(1, countLogLinesContaining(expectedTransactionInfo));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining(expectedTransactionInfo));
}
TEST_F(TransactionsMetricsTest, LogTransactionInfoAfterSlowAbort) {
@@ -3372,7 +3372,7 @@ TEST_F(TransactionsMetricsTest, LogTransactionInfoAfterSlowAbort) {
metricValue,
false);
- ASSERT_EQUALS(1, countLogLinesContaining(expectedTransactionInfo));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining(expectedTransactionInfo));
}
TEST_F(TransactionsMetricsTest, LogPreparedTransactionInfoAfterSlowAbort) {
@@ -3419,7 +3419,7 @@ TEST_F(TransactionsMetricsTest, LogPreparedTransactionInfoAfterSlowAbort) {
false,
prepareOpTime);
- ASSERT_EQUALS(1, countLogLinesContaining(expectedTransactionInfo));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining(expectedTransactionInfo));
}
TEST_F(TransactionsMetricsTest, LogTransactionInfoAfterExceptionInPrepare) {
@@ -3465,7 +3465,7 @@ TEST_F(TransactionsMetricsTest, LogTransactionInfoAfterExceptionInPrepare) {
metricValue,
false);
- ASSERT_EQUALS(1, countLogLinesContaining(expectedTransactionInfo));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining(expectedTransactionInfo));
}
TEST_F(TransactionsMetricsTest, LogTransactionInfoAfterSlowStashedAbort) {
@@ -3504,7 +3504,7 @@ TEST_F(TransactionsMetricsTest, LogTransactionInfoAfterSlowStashedAbort) {
stopCapturingLogMessages();
std::string expectedTransactionInfo = "transaction parameters";
- ASSERT_EQUALS(1, countLogLinesContaining(expectedTransactionInfo));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining(expectedTransactionInfo));
}
TEST_F(TransactionsMetricsTest, LogTransactionInfoVerbosityInfo) {
@@ -3525,7 +3525,7 @@ TEST_F(TransactionsMetricsTest, LogTransactionInfoVerbosityInfo) {
stopCapturingLogMessages();
// Test that the transaction is not logged.
- ASSERT_EQUALS(0, countLogLinesContaining("transaction parameters"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("transaction parameters"));
}
TEST_F(TransactionsMetricsTest, LogTransactionInfoVerbosityDebug) {
@@ -3549,7 +3549,7 @@ TEST_F(TransactionsMetricsTest, LogTransactionInfoVerbosityDebug) {
setMinimumLoggedSeverity(logger::LogComponent::kTransaction, logger::LogSeverity::Info());
// Test that the transaction is still logged.
- ASSERT_EQUALS(1, countLogLinesContaining("transaction parameters"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("transaction parameters"));
}
TEST_F(TxnParticipantTest, RollbackResetsInMemoryStateOfPreparedTransaction) {
diff --git a/src/mongo/logger/log_function_test.cpp b/src/mongo/logger/log_function_test.cpp
index dd4242dbe55..72b3a78d3db 100644
--- a/src/mongo/logger/log_function_test.cpp
+++ b/src/mongo/logger/log_function_test.cpp
@@ -41,6 +41,7 @@
#include "mongo/logger/encoder.h"
#include "mongo/logger/log_component.h"
#include "mongo/logger/message_event_utf8_encoder.h"
+#include "mongo/logv2/text_formatter.h"
#include "mongo/util/log.h"
#include "mongo/util/str.h"
@@ -49,7 +50,7 @@ using namespace mongo::logger;
namespace mongo {
namespace {
-typedef LogTest<MessageEventDetailsEncoder> LogTestDetailsEncoder;
+typedef LogTest<MessageEventDetailsEncoder, logv2::TextFormatter> LogTestDetailsEncoder;
// Constants for log component test cases.
const LogComponent componentA = LogComponent::kCommand;
diff --git a/src/mongo/logger/log_manager.cpp b/src/mongo/logger/log_manager.cpp
index c167853353f..48eb660324f 100644
--- a/src/mongo/logger/log_manager.cpp
+++ b/src/mongo/logger/log_manager.cpp
@@ -27,12 +27,17 @@
* it in the license file.
*/
+#define MONGO_LOG_DEFAULT_COMPONENT ::mongo::logger::LogComponent::kDefault
+
#include "mongo/platform/basic.h"
#include "mongo/logger/log_manager.h"
#include "mongo/logger/console_appender.h"
+#include "mongo/logger/logv2_appender.h"
#include "mongo/logger/message_event_utf8_encoder.h"
+#include "mongo/logv2/log_domain_global.h"
+#include "mongo/util/log.h"
namespace mongo {
namespace logger {
@@ -63,9 +68,15 @@ void LogManager::detachDefaultConsoleAppender() {
void LogManager::reattachDefaultConsoleAppender() {
invariant(!_defaultAppender);
- _defaultAppender =
- _globalDomain.attachAppender(std::make_unique<ConsoleAppender<MessageEventEphemeral>>(
- std::make_unique<MessageEventDetailsEncoder>()));
+ if (logV2Enabled()) {
+ _defaultAppender = _globalDomain.attachAppender(
+ std::make_unique<logger::LogV2Appender<MessageEventEphemeral>>(
+ &logv2::LogManager::global().getGlobalDomain(), false));
+ } else {
+ _defaultAppender =
+ _globalDomain.attachAppender(std::make_unique<ConsoleAppender<MessageEventEphemeral>>(
+ std::make_unique<MessageEventDetailsEncoder>()));
+ }
}
bool LogManager::isDefaultConsoleAppenderAttached() const {
diff --git a/src/mongo/logger/log_test.cpp b/src/mongo/logger/log_test.cpp
index 3daf413bf9a..dcb4bb671cb 100644
--- a/src/mongo/logger/log_test.cpp
+++ b/src/mongo/logger/log_test.cpp
@@ -45,6 +45,8 @@
#include "mongo/logger/message_log_domain.h"
#include "mongo/logger/rotatable_file_appender.h"
#include "mongo/logger/rotatable_file_writer.h"
+#include "mongo/logv2/plain_formatter.h"
+#include "mongo/logv2/text_formatter.h"
#include "mongo/platform/compiler.h"
#include "mongo/unittest/unittest.h"
#include "mongo/util/concurrency/thread_name.h"
@@ -56,8 +58,8 @@ using namespace mongo::logger;
namespace mongo {
namespace {
-typedef LogTest<MessageEventDetailsEncoder> LogTestDetailsEncoder;
-typedef LogTest<MessageEventUnadornedEncoder> LogTestUnadornedEncoder;
+typedef LogTest<MessageEventDetailsEncoder, logv2::TextFormatter> LogTestDetailsEncoder;
+typedef LogTest<MessageEventUnadornedEncoder, logv2::PlainFormatter> LogTestUnadornedEncoder;
TEST_F(LogTestUnadornedEncoder, logContext) {
logContext("WHA!");
@@ -124,8 +126,8 @@ public:
TEST_F(LogTestUnadornedEncoder, LogstreamBuilderReentrance) {
log() << "Logging A() -- " << A() << " -- done!" << std::endl;
ASSERT_EQUALS(2U, _logLines.size());
- ASSERT_EQUALS(std::string("Golly!\n"), _logLines[0]);
- ASSERT_EQUALS(std::string("Logging A() -- Golly! -- done!\n"), _logLines[1]);
+ ASSERT(StringData(_logLines[0]).startsWith("Golly!"));
+ ASSERT(StringData(_logLines[1]).startsWith("Logging A() -- Golly! -- done!"));
}
//
@@ -155,14 +157,14 @@ TEST_F(LogTestUnadornedEncoder, MongoLogMacroNoFileScopeLogComponent) {
LOG(2) << "This is logged";
LOG(3) << "This is not logged";
ASSERT_EQUALS(1U, _logLines.size());
- ASSERT_EQUALS(std::string("This is logged\n"), _logLines[0]);
+ ASSERT(StringData(_logLines[0]).startsWith("This is logged"));
// MONGO_LOG_COMPONENT
_logLines.clear();
MONGO_LOG_COMPONENT(2, componentA) << "This is logged";
MONGO_LOG_COMPONENT(3, componentA) << "This is not logged";
ASSERT_EQUALS(1U, _logLines.size());
- ASSERT_EQUALS(std::string("This is logged\n"), _logLines[0]);
+ ASSERT(StringData(_logLines[0]).startsWith("This is logged"));
}
//
diff --git a/src/mongo/logger/log_test.h b/src/mongo/logger/log_test.h
index a5e8d914454..72c4a12b00f 100644
--- a/src/mongo/logger/log_test.h
+++ b/src/mongo/logger/log_test.h
@@ -29,6 +29,7 @@
#pragma once
+#include <boost/log/core.hpp>
#include <sstream>
#include <string>
#include <vector>
@@ -37,7 +38,13 @@
#include "mongo/logger/appender.h"
#include "mongo/logger/log_severity.h"
#include "mongo/logger/logger.h"
+#include "mongo/logger/logv2_appender.h"
#include "mongo/logger/message_log_domain.h"
+#include "mongo/logv2/component_settings_filter.h"
+#include "mongo/logv2/log_capture_backend.h"
+#include "mongo/logv2/log_domain.h"
+#include "mongo/logv2/log_domain_global.h"
+#include "mongo/logv2/log_manager.h"
#include "mongo/unittest/unittest.h"
#include "mongo/util/log_global_settings.h"
@@ -47,19 +54,37 @@ namespace logger {
// Used for testing logging framework only.
// TODO(schwerin): Have logger write to a different log from the global log, so that tests can
// redirect their global log output for examination.
-template <typename MessageEventEncoder>
+template <typename MessageEventEncoder, typename LOGV2Formatter>
class LogTest : public unittest::Test {
friend class LogTestAppender;
public:
LogTest() : _severityOld(getMinimumLogSeverity()) {
globalLogDomain()->clearAppenders();
- _appenderHandle =
- globalLogDomain()->attachAppender(std::make_unique<LogTestAppender>(this));
+ if (logV2Enabled()) {
+ _appenderHandle = globalLogDomain()->attachAppender(
+ std::make_unique<LogV2Appender<MessageEventEphemeral>>(
+ &logv2::LogManager::global().getGlobalDomain(), true));
+
+ if (!_captureSink) {
+ _captureSink = logv2::LogCaptureBackend::create(_logLines);
+ _captureSink->set_filter(logv2::ComponentSettingsFilter(
+ logv2::LogManager::global().getGlobalDomain(),
+ logv2::LogManager::global().getGlobalSettings()));
+ _captureSink->set_formatter(LOGV2Formatter());
+ }
+ boost::log::core::get()->add_sink(_captureSink);
+ } else {
+ _appenderHandle =
+ globalLogDomain()->attachAppender(std::make_unique<LogTestAppender>(this));
+ }
}
virtual ~LogTest() {
globalLogDomain()->detachAppender(_appenderHandle);
+ if (logV2Enabled()) {
+ boost::log::core::get()->remove_sink(_captureSink);
+ }
setMinimumLoggedSeverity(_severityOld);
}
@@ -86,6 +111,7 @@ private:
};
MessageLogDomain::AppenderHandle _appenderHandle;
+ boost::shared_ptr<boost::log::sinks::synchronous_sink<logv2::LogCaptureBackend>> _captureSink;
};
} // namespace logger
diff --git a/src/mongo/logv2/domain_filter.h b/src/mongo/logv2/domain_filter.h
index 2fbb8c09268..a84d9086c8d 100644
--- a/src/mongo/logv2/domain_filter.h
+++ b/src/mongo/logv2/domain_filter.h
@@ -57,5 +57,14 @@ private:
const LogDomain::Internal* _domain;
};
+class AllLogsFilter : public DomainFilter<AllLogsFilter> {
+public:
+ using DomainFilter::DomainFilter;
+
+ bool filter(boost::log::attribute_value_set const& attrs) const {
+ return true;
+ }
+};
+
} // namespace logv2
} // namespace mongo
diff --git a/src/mongo/logv2/log_capture_backend.h b/src/mongo/logv2/log_capture_backend.h
new file mode 100644
index 00000000000..640a3623321
--- /dev/null
+++ b/src/mongo/logv2/log_capture_backend.h
@@ -0,0 +1,60 @@
+/**
+ * Copyright (C) 2020-present MongoDB, Inc.
+ *
+ * This program is free software: you can redistribute it and/or modify
+ * it under the terms of the Server Side Public License, version 1,
+ * as published by MongoDB, Inc.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
+ * Server Side Public License for more details.
+ *
+ * You should have received a copy of the Server Side Public License
+ * along with this program. If not, see
+ * <http://www.mongodb.com/licensing/server-side-public-license>.
+ *
+ * As a special exception, the copyright holders give permission to link the
+ * code of portions of this program with the OpenSSL library under certain
+ * conditions as described in each individual source file and distribute
+ * linked combinations including the program with the OpenSSL library. You
+ * must comply with the Server Side Public License in all respects for
+ * all of the code used other than as permitted herein. If you modify file(s)
+ * with this exception, you may extend this exception to your version of the
+ * file(s), but you are not obligated to do so. If you do not wish to do so,
+ * delete this exception statement from your version. If you delete this
+ * exception statement from all source files in the program, then also delete
+ * it in the license file.
+ */
+
+#pragma once
+
+#include <boost/log/attributes/attribute_value_set.hpp>
+#include <boost/log/core/record_view.hpp>
+#include <boost/log/sinks.hpp>
+#include <boost/log/utility/formatting_ostream.hpp>
+#include <boost/make_shared.hpp>
+#include <string>
+#include <vector>
+
+namespace mongo::logv2 {
+class LogCaptureBackend
+ : public boost::log::sinks::
+ basic_formatted_sink_backend<char, boost::log::sinks::synchronized_feeding> {
+public:
+ LogCaptureBackend(std::vector<std::string>& lines) : _logLines(lines) {}
+
+ static boost::shared_ptr<boost::log::sinks::synchronous_sink<LogCaptureBackend>> create(
+ std::vector<std::string>& lines) {
+ return boost::make_shared<boost::log::sinks::synchronous_sink<LogCaptureBackend>>(
+ boost::make_shared<LogCaptureBackend>(lines));
+ }
+
+ void consume(boost::log::record_view const& rec, string_type const& formatted_string) {
+ _logLines.push_back(formatted_string);
+ }
+
+private:
+ std::vector<std::string>& _logLines;
+};
+} // namespace mongo::logv2
diff --git a/src/mongo/logv2/log_test_v2.cpp b/src/mongo/logv2/log_test_v2.cpp
index d333930c514..4e722964893 100644
--- a/src/mongo/logv2/log_test_v2.cpp
+++ b/src/mongo/logv2/log_test_v2.cpp
@@ -47,6 +47,7 @@
#include "mongo/logv2/constants.h"
#include "mongo/logv2/json_formatter.h"
#include "mongo/logv2/log.h"
+#include "mongo/logv2/log_capture_backend.h"
#include "mongo/logv2/log_component.h"
#include "mongo/logv2/plain_formatter.h"
#include "mongo/logv2/ramlog_sink.h"
@@ -162,32 +163,11 @@ BSONObj toBSON(const TypeWithNonMemberFormatting&) {
return builder.obj();
}
-class LogTestBackend
- : public boost::log::sinks::
- basic_formatted_sink_backend<char, boost::log::sinks::synchronized_feeding> {
-public:
- LogTestBackend(std::vector<std::string>& lines) : _logLines(lines) {}
-
- static boost::shared_ptr<boost::log::sinks::synchronous_sink<LogTestBackend>> create(
- std::vector<std::string>& lines) {
- auto backend = boost::make_shared<LogTestBackend>(lines);
- return boost::make_shared<boost::log::sinks::synchronous_sink<LogTestBackend>>(
- std::move(backend));
- }
-
- void consume(boost::log::record_view const& rec, string_type const& formatted_string) {
- _logLines.push_back(formatted_string);
- }
-
-private:
- std::vector<std::string>& _logLines;
-};
-
class LogDuringInitTester {
public:
LogDuringInitTester() {
std::vector<std::string> lines;
- auto sink = LogTestBackend::create(lines);
+ auto sink = LogCaptureBackend::create(lines);
sink->set_filter(ComponentSettingsFilter(LogManager::global().getGlobalDomain(),
LogManager::global().getGlobalSettings()));
sink->set_formatter(PlainFormatter());
@@ -204,7 +184,7 @@ LogDuringInitTester logDuringInit;
TEST_F(LogTestV2, Basic) {
std::vector<std::string> lines;
- auto sink = LogTestBackend::create(lines);
+ auto sink = LogCaptureBackend::create(lines);
sink->set_filter(ComponentSettingsFilter(LogManager::global().getGlobalDomain(),
LogManager::global().getGlobalSettings()));
sink->set_formatter(PlainFormatter());
@@ -263,21 +243,21 @@ TEST_F(LogTestV2, Types) {
using namespace constants;
std::vector<std::string> text;
- auto text_sink = LogTestBackend::create(text);
+ auto text_sink = LogCaptureBackend::create(text);
text_sink->set_filter(ComponentSettingsFilter(LogManager::global().getGlobalDomain(),
LogManager::global().getGlobalSettings()));
text_sink->set_formatter(PlainFormatter());
attach(text_sink);
std::vector<std::string> json;
- auto json_sink = LogTestBackend::create(json);
+ auto json_sink = LogCaptureBackend::create(json);
json_sink->set_filter(ComponentSettingsFilter(LogManager::global().getGlobalDomain(),
LogManager::global().getGlobalSettings()));
json_sink->set_formatter(JSONFormatter());
attach(json_sink);
std::vector<std::string> bson;
- auto bson_sink = LogTestBackend::create(bson);
+ auto bson_sink = LogCaptureBackend::create(bson);
bson_sink->set_filter(ComponentSettingsFilter(LogManager::global().getGlobalDomain(),
LogManager::global().getGlobalSettings()));
bson_sink->set_formatter(BSONFormatter());
@@ -602,7 +582,7 @@ TEST_F(LogTestV2, Types) {
TEST_F(LogTestV2, TextFormat) {
std::vector<std::string> lines;
- auto sink = LogTestBackend::create(lines);
+ auto sink = LogCaptureBackend::create(lines);
sink->set_filter(ComponentSettingsFilter(LogManager::global().getGlobalDomain(),
LogManager::global().getGlobalSettings()));
sink->set_formatter(TextFormatter());
@@ -640,14 +620,14 @@ TEST_F(LogTestV2, JsonBsonFormat) {
using namespace constants;
std::vector<std::string> lines;
- auto sink = LogTestBackend::create(lines);
+ auto sink = LogCaptureBackend::create(lines);
sink->set_filter(ComponentSettingsFilter(LogManager::global().getGlobalDomain(),
LogManager::global().getGlobalSettings()));
sink->set_formatter(JSONFormatter());
attach(sink);
std::vector<std::string> linesBson;
- auto sinkBson = LogTestBackend::create(linesBson);
+ auto sinkBson = LogCaptureBackend::create(linesBson);
sinkBson->set_filter(ComponentSettingsFilter(LogManager::global().getGlobalDomain(),
LogManager::global().getGlobalSettings()));
sinkBson->set_formatter(BSONFormatter());
@@ -815,21 +795,21 @@ TEST_F(LogTestV2, Containers) {
using namespace constants;
std::vector<std::string> text;
- auto text_sink = LogTestBackend::create(text);
+ auto text_sink = LogCaptureBackend::create(text);
text_sink->set_filter(ComponentSettingsFilter(LogManager::global().getGlobalDomain(),
LogManager::global().getGlobalSettings()));
text_sink->set_formatter(PlainFormatter());
attach(text_sink);
std::vector<std::string> json;
- auto json_sink = LogTestBackend::create(json);
+ auto json_sink = LogCaptureBackend::create(json);
json_sink->set_filter(ComponentSettingsFilter(LogManager::global().getGlobalDomain(),
LogManager::global().getGlobalSettings()));
json_sink->set_formatter(JSONFormatter());
attach(json_sink);
std::vector<std::string> bson;
- auto bson_sink = LogTestBackend::create(bson);
+ auto bson_sink = LogCaptureBackend::create(bson);
bson_sink->set_filter(ComponentSettingsFilter(LogManager::global().getGlobalDomain(),
LogManager::global().getGlobalSettings()));
bson_sink->set_formatter(BSONFormatter());
@@ -1014,7 +994,7 @@ TEST_F(LogTestV2, Containers) {
TEST_F(LogTestV2, Unicode) {
std::vector<std::string> lines;
- auto sink = LogTestBackend::create(lines);
+ auto sink = LogCaptureBackend::create(lines);
sink->set_filter(ComponentSettingsFilter(LogManager::global().getGlobalDomain(),
LogManager::global().getGlobalSettings()));
sink->set_formatter(JSONFormatter());
@@ -1085,21 +1065,21 @@ TEST_F(LogTestV2, Unicode) {
TEST_F(LogTestV2, Threads) {
std::vector<std::string> linesPlain;
- auto plainSink = LogTestBackend::create(linesPlain);
+ auto plainSink = LogCaptureBackend::create(linesPlain);
plainSink->set_filter(ComponentSettingsFilter(LogManager::global().getGlobalDomain(),
LogManager::global().getGlobalSettings()));
plainSink->set_formatter(PlainFormatter());
attach(plainSink);
std::vector<std::string> linesText;
- auto textSink = LogTestBackend::create(linesText);
+ auto textSink = LogCaptureBackend::create(linesText);
textSink->set_filter(ComponentSettingsFilter(LogManager::global().getGlobalDomain(),
LogManager::global().getGlobalSettings()));
textSink->set_formatter(TextFormatter());
attach(textSink);
std::vector<std::string> linesJson;
- auto jsonSink = LogTestBackend::create(linesJson);
+ auto jsonSink = LogCaptureBackend::create(linesJson);
jsonSink->set_filter(ComponentSettingsFilter(LogManager::global().getGlobalDomain(),
LogManager::global().getGlobalSettings()));
jsonSink->set_formatter(JSONFormatter());
@@ -1148,7 +1128,7 @@ TEST_F(LogTestV2, Ramlog) {
attach(sink);
std::vector<std::string> lines;
- auto testSink = LogTestBackend::create(lines);
+ auto testSink = LogCaptureBackend::create(lines);
testSink->set_filter(ComponentSettingsFilter(LogManager::global().getGlobalDomain(),
LogManager::global().getGlobalSettings()));
testSink->set_formatter(PlainFormatter());
@@ -1169,7 +1149,7 @@ TEST_F(LogTestV2, Ramlog) {
TEST_F(LogTestV2, MultipleDomains) {
std::vector<std::string> global_lines;
- auto sink = LogTestBackend::create(global_lines);
+ auto sink = LogCaptureBackend::create(global_lines);
sink->set_filter(ComponentSettingsFilter(LogManager::global().getGlobalDomain(),
LogManager::global().getGlobalSettings()));
sink->set_formatter(PlainFormatter());
@@ -1188,7 +1168,7 @@ TEST_F(LogTestV2, MultipleDomains) {
LogDomain other_domain(std::make_unique<OtherDomainImpl>());
std::vector<std::string> other_lines;
- auto other_sink = LogTestBackend::create(other_lines);
+ auto other_sink = LogCaptureBackend::create(other_lines);
other_sink->set_filter(
ComponentSettingsFilter(other_domain, LogManager::global().getGlobalSettings()));
other_sink->set_formatter(PlainFormatter());
diff --git a/src/mongo/logv2/log_test_v2.h b/src/mongo/logv2/log_test_v2.h
index 44f56dba9a4..334023444f3 100644
--- a/src/mongo/logv2/log_test_v2.h
+++ b/src/mongo/logv2/log_test_v2.h
@@ -35,14 +35,6 @@
#include "mongo/logv2/log_manager.h"
#include "mongo/unittest/unittest.h"
-#include <boost/log/attributes/attribute_value_set.hpp>
-#include <boost/log/core/record_view.hpp>
-#include <boost/log/utility/formatting_ostream.hpp>
-
-#include <boost/log/sinks.hpp>
-
-#include <boost/make_shared.hpp>
-
namespace mongo {
namespace logv2 {
diff --git a/src/mongo/s/transaction_router_test.cpp b/src/mongo/s/transaction_router_test.cpp
index d4847dc63ab..dd2e86df0bc 100644
--- a/src/mongo/s/transaction_router_test.cpp
+++ b/src/mongo/s/transaction_router_test.cpp
@@ -3055,11 +3055,11 @@ protected:
}
void assertPrintedExactlyOneSlowLogLine() {
- ASSERT_EQUALS(1, countLogLinesContaining("transaction parameters:"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("transaction parameters:"));
}
void assertDidNotPrintSlowLogLine() {
- ASSERT_EQUALS(0, countLogLinesContaining("transaction parameters:"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("transaction parameters:"));
}
auto routerTxnMetrics() {
@@ -3156,7 +3156,7 @@ TEST_F(TransactionRouterMetricsTest, SlowLoggingPrintsTransactionParameters) {
BSONObjBuilder lsidBob;
getSessionId().serialize(&lsidBob);
ASSERT_EQUALS(1,
- countLogLinesContaining(
+ countTextFormatLogLinesContaining(
str::stream() << "parameters:{ lsid: " << lsidBob.done().toString()
<< ", txnNumber: " << kTxnNumber << ", autocommit: false"));
}
@@ -3166,7 +3166,10 @@ TEST_F(TransactionRouterMetricsTest, SlowLoggingPrintsDurationAtEnd) {
tickSource()->advance(Milliseconds(111));
assertDurationIs(Milliseconds(111));
runCommit(kDummyOkRes);
- ASSERT_EQUALS(1, countLogLinesContaining(" 111ms\n") + countLogLinesContaining(" 111ms\r\n"));
+ const auto& logs = getCapturedTextFormatLogMessages();
+ ASSERT_EQUALS(1, std::count_if(logs.begin(), logs.end(), [](const std::string& line) {
+ return StringData(line).endsWith(" 111ms");
+ }));
}
TEST_F(TransactionRouterMetricsTest, SlowLoggingPrintsTimeActiveAndInactive) {
@@ -3182,8 +3185,8 @@ TEST_F(TransactionRouterMetricsTest, SlowLoggingPrintsTimeActiveAndInactive) {
operationContext(), kTxnNumber, TransactionRouter::TransactionActions::kCommit);
runCommit(kDummyOkRes);
- ASSERT_EQUALS(1, countLogLinesContaining("timeActiveMicros:111,"));
- ASSERT_EQUALS(1, countLogLinesContaining("timeInactiveMicros:222,"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("timeActiveMicros:111,"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("timeInactiveMicros:222,"));
}
//
@@ -3197,8 +3200,8 @@ TEST_F(TransactionRouterMetricsTest, SlowLoggingReadConcern_None) {
beginSlowTxnWithDefaultTxnNumber();
runCommit(kDummyOkRes);
- ASSERT_EQUALS(0, countLogLinesContaining(readConcern.toBSON()["readConcern"]));
- ASSERT_EQUALS(0, countLogLinesContaining("globalReadTimestamp:"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining(readConcern.toBSON()["readConcern"]));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("globalReadTimestamp:"));
}
TEST_F(TransactionRouterMetricsTest, SlowLoggingReadConcern_Local) {
@@ -3208,8 +3211,8 @@ TEST_F(TransactionRouterMetricsTest, SlowLoggingReadConcern_Local) {
beginSlowTxnWithDefaultTxnNumber();
runCommit(kDummyOkRes);
- ASSERT_EQUALS(1, countLogLinesContaining(readConcern.toBSON()["readConcern"]));
- ASSERT_EQUALS(0, countLogLinesContaining("globalReadTimestamp:"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining(readConcern.toBSON()["readConcern"]));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("globalReadTimestamp:"));
}
TEST_F(TransactionRouterMetricsTest, SlowLoggingReadConcern_Majority) {
@@ -3219,8 +3222,8 @@ TEST_F(TransactionRouterMetricsTest, SlowLoggingReadConcern_Majority) {
beginSlowTxnWithDefaultTxnNumber();
runCommit(kDummyOkRes);
- ASSERT_EQUALS(1, countLogLinesContaining(readConcern.toBSON()["readConcern"]));
- ASSERT_EQUALS(0, countLogLinesContaining("globalReadTimestamp:"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining(readConcern.toBSON()["readConcern"]));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("globalReadTimestamp:"));
}
TEST_F(TransactionRouterMetricsTest, SlowLoggingReadConcern_Snapshot) {
@@ -3230,8 +3233,8 @@ TEST_F(TransactionRouterMetricsTest, SlowLoggingReadConcern_Snapshot) {
beginSlowTxnWithDefaultTxnNumber();
runCommit(kDummyOkRes);
- ASSERT_EQUALS(1, countLogLinesContaining(readConcern.toBSON()["readConcern"]));
- ASSERT_EQUALS(1, countLogLinesContaining("globalReadTimestamp:"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining(readConcern.toBSON()["readConcern"]));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("globalReadTimestamp:"));
}
//
@@ -3242,65 +3245,65 @@ TEST_F(TransactionRouterMetricsTest, SlowLoggingCommitType_NoShards) {
beginSlowTxnWithDefaultTxnNumber();
runNoShardCommit();
- ASSERT_EQUALS(1, countLogLinesContaining("commitType:noShards,"));
- ASSERT_EQUALS(1, countLogLinesContaining("numParticipants:0"));
- ASSERT_EQUALS(1, countLogLinesContaining("commitDurationMicros:"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("commitType:noShards,"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("numParticipants:0"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("commitDurationMicros:"));
- ASSERT_EQUALS(0, countLogLinesContaining("coordinator:"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("coordinator:"));
}
TEST_F(TransactionRouterMetricsTest, SlowLoggingCommitType_SingleShard) {
beginSlowTxnWithDefaultTxnNumber();
runSingleShardCommit();
- ASSERT_EQUALS(1, countLogLinesContaining("commitType:singleShard,"));
- ASSERT_EQUALS(1, countLogLinesContaining("numParticipants:1"));
- ASSERT_EQUALS(1, countLogLinesContaining("commitDurationMicros:"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("commitType:singleShard,"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("numParticipants:1"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("commitDurationMicros:"));
- ASSERT_EQUALS(0, countLogLinesContaining("coordinator:"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("coordinator:"));
}
TEST_F(TransactionRouterMetricsTest, SlowLoggingCommitType_SingleWriteShard) {
beginSlowTxnWithDefaultTxnNumber();
runSingleWriteShardCommit();
- ASSERT_EQUALS(1, countLogLinesContaining("commitType:singleWriteShard,"));
- ASSERT_EQUALS(1, countLogLinesContaining("numParticipants:2"));
- ASSERT_EQUALS(1, countLogLinesContaining("commitDurationMicros:"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("commitType:singleWriteShard,"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("numParticipants:2"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("commitDurationMicros:"));
- ASSERT_EQUALS(0, countLogLinesContaining("coordinator:"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("coordinator:"));
}
TEST_F(TransactionRouterMetricsTest, SlowLoggingCommitType_ReadOnly) {
beginSlowTxnWithDefaultTxnNumber();
runReadOnlyCommit();
- ASSERT_EQUALS(1, countLogLinesContaining("commitType:readOnly,"));
- ASSERT_EQUALS(1, countLogLinesContaining("numParticipants:2"));
- ASSERT_EQUALS(1, countLogLinesContaining("commitDurationMicros:"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("commitType:readOnly,"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("numParticipants:2"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("commitDurationMicros:"));
- ASSERT_EQUALS(0, countLogLinesContaining("coordinator:"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("coordinator:"));
}
TEST_F(TransactionRouterMetricsTest, SlowLoggingCommitType_TwoPhase) {
beginSlowTxnWithDefaultTxnNumber();
runTwoPhaseCommit();
- ASSERT_EQUALS(1, countLogLinesContaining("commitType:twoPhaseCommit,"));
- ASSERT_EQUALS(1, countLogLinesContaining("coordinator:"));
- ASSERT_EQUALS(1, countLogLinesContaining("numParticipants:2"));
- ASSERT_EQUALS(1, countLogLinesContaining("commitDurationMicros:"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("commitType:twoPhaseCommit,"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("coordinator:"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("numParticipants:2"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("commitDurationMicros:"));
}
TEST_F(TransactionRouterMetricsTest, SlowLoggingCommitType_Recovery) {
beginSlowRecoverCommitWithDefaultTxnNumber();
runRecoverWithTokenCommit(shard1);
- ASSERT_EQUALS(1, countLogLinesContaining("commitType:recoverWithToken,"));
- ASSERT_EQUALS(1, countLogLinesContaining("commitDurationMicros:"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("commitType:recoverWithToken,"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("commitDurationMicros:"));
- ASSERT_EQUALS(0, countLogLinesContaining("numParticipants:"));
- ASSERT_EQUALS(0, countLogLinesContaining("coordinator:"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("numParticipants:"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("coordinator:"));
}
TEST_F(TransactionRouterMetricsTest, SlowLoggingCommitType_EmptyRecovery) {
@@ -3320,45 +3323,45 @@ TEST_F(TransactionRouterMetricsTest, SlowLoggingOnTerminate_ImplicitAbort) {
beginSlowTxnWithDefaultTxnNumber();
implicitAbortInProgress();
- ASSERT_EQUALS(1, countLogLinesContaining("terminationCause:aborted"));
- ASSERT_EQUALS(1, countLogLinesContaining("abortCause:" + kDummyStatus.codeString()));
- ASSERT_EQUALS(1, countLogLinesContaining("numParticipants:1"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("terminationCause:aborted"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("abortCause:" + kDummyStatus.codeString()));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("numParticipants:1"));
- ASSERT_EQUALS(0, countLogLinesContaining("commitType:"));
- ASSERT_EQUALS(0, countLogLinesContaining("commitDurationMicros:"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("commitType:"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("commitDurationMicros:"));
}
TEST_F(TransactionRouterMetricsTest, SlowLoggingOnTerminate_ExplicitAbort) {
beginSlowTxnWithDefaultTxnNumber();
explicitAbortInProgress();
- ASSERT_EQUALS(1, countLogLinesContaining("terminationCause:aborted"));
- ASSERT_EQUALS(1, countLogLinesContaining("abortCause:abort"));
- ASSERT_EQUALS(1, countLogLinesContaining("numParticipants:1"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("terminationCause:aborted"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("abortCause:abort"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("numParticipants:1"));
- ASSERT_EQUALS(0, countLogLinesContaining("commitType:"));
- ASSERT_EQUALS(0, countLogLinesContaining("commitDurationMicros:"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("commitType:"));
+ ASSERT_EQUALS(0, countTextFormatLogLinesContaining("commitDurationMicros:"));
}
TEST_F(TransactionRouterMetricsTest, SlowLoggingOnTerminate_SuccessfulCommit) {
beginSlowTxnWithDefaultTxnNumber();
runCommit(kDummyOkRes);
- ASSERT_EQUALS(1, countLogLinesContaining("terminationCause:committed"));
- ASSERT_EQUALS(1, countLogLinesContaining("commitType:singleShard"));
- ASSERT_EQUALS(1, countLogLinesContaining("commitDurationMicros:"));
- ASSERT_EQUALS(1, countLogLinesContaining("numParticipants:1"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("terminationCause:committed"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("commitType:singleShard"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("commitDurationMicros:"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("numParticipants:1"));
}
TEST_F(TransactionRouterMetricsTest, SlowLoggingOnTerminate_FailedCommit) {
beginSlowTxnWithDefaultTxnNumber();
runCommit(kDummyErrorRes);
- ASSERT_EQUALS(1, countLogLinesContaining("terminationCause:aborted"));
- ASSERT_EQUALS(1, countLogLinesContaining("abortCause:" + kDummyStatus.codeString()));
- ASSERT_EQUALS(1, countLogLinesContaining("commitType:"));
- ASSERT_EQUALS(1, countLogLinesContaining("commitDurationMicros:"));
- ASSERT_EQUALS(1, countLogLinesContaining("numParticipants:1"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("terminationCause:aborted"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("abortCause:" + kDummyStatus.codeString()));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("commitType:"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("commitDurationMicros:"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("numParticipants:1"));
}
//
@@ -3470,9 +3473,9 @@ TEST_F(TransactionRouterMetricsTest, SlowLoggingAfterUnknownCommitResult_Success
retryCommit(kDummyOkRes);
- ASSERT_EQUALS(1, countLogLinesContaining("terminationCause:committed"));
- ASSERT_EQUALS(1, countLogLinesContaining("commitType:"));
- ASSERT_EQUALS(1, countLogLinesContaining("commitDurationMicros:"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("terminationCause:committed"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("commitType:"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("commitDurationMicros:"));
}
TEST_F(TransactionRouterMetricsTest, SlowLoggingAfterUnknownCommitResult_Abort) {
@@ -3483,9 +3486,9 @@ TEST_F(TransactionRouterMetricsTest, SlowLoggingAfterUnknownCommitResult_Abort)
retryCommit(kDummyErrorRes);
- ASSERT_EQUALS(1, countLogLinesContaining("terminationCause:aborted"));
- ASSERT_EQUALS(1, countLogLinesContaining("commitType:"));
- ASSERT_EQUALS(1, countLogLinesContaining("commitDurationMicros:"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("terminationCause:aborted"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("commitType:"));
+ ASSERT_EQUALS(1, countTextFormatLogLinesContaining("commitDurationMicros:"));
}
TEST_F(TransactionRouterMetricsTest, SlowLoggingAfterUnknownCommitResult_Unknown) {
diff --git a/src/mongo/unittest/unittest.cpp b/src/mongo/unittest/unittest.cpp
index 279b2d07c07..0fc1d57cf5e 100644
--- a/src/mongo/unittest/unittest.cpp
+++ b/src/mongo/unittest/unittest.cpp
@@ -33,6 +33,7 @@
#include "mongo/unittest/unittest.h"
+#include <boost/log/core.hpp>
#include <fmt/format.h>
#include <fmt/printf.h>
#include <functional>
@@ -48,6 +49,12 @@
#include "mongo/logger/logger.h"
#include "mongo/logger/message_event_utf8_encoder.h"
#include "mongo/logger/message_log_domain.h"
+#include "mongo/logv2/component_settings_filter.h"
+#include "mongo/logv2/log_capture_backend.h"
+#include "mongo/logv2/log_domain.h"
+#include "mongo/logv2/log_domain_global.h"
+#include "mongo/logv2/log_manager.h"
+#include "mongo/logv2/plain_formatter.h"
#include "mongo/platform/mutex.h"
#include "mongo/util/assert_util.h"
#include "mongo/util/log.h"
@@ -187,13 +194,30 @@ struct UnitTestEnvironment {
} // namespace
-Test::Test() : _isCapturingLogMessages(false) {}
-
-Test::~Test() {
- if (_isCapturingLogMessages) {
- stopCapturingLogMessages();
+class Test::CaptureLogs {
+public:
+ ~CaptureLogs() {
+ if (_isCapturingLogMessages) {
+ stopCapturingLogMessages();
+ }
}
-}
+ void startCapturingLogMessages();
+ void stopCapturingLogMessages();
+ const std::vector<std::string>& getCapturedTextFormatLogMessages() const;
+ int64_t countTextFormatLogLinesContaining(const std::string& needle);
+ void printCapturedTextFormatLogLines() const;
+
+private:
+ bool _isCapturingLogMessages{false};
+ std::vector<std::string> _capturedLogMessages;
+ logger::MessageLogDomain::AppenderHandle _captureAppenderHandle;
+ std::unique_ptr<logger::MessageLogDomain::EventAppender> _captureAppender;
+ boost::shared_ptr<boost::log::sinks::synchronous_sink<logv2::LogCaptureBackend>> _captureSink;
+};
+
+Test::Test() : _captureLogs(std::make_unique<CaptureLogs>()) {}
+
+Test::~Test() {}
void Test::run() {
UnitTestEnvironment environment(this);
@@ -246,38 +270,77 @@ private:
};
} // namespace
-void Test::startCapturingLogMessages() {
+void Test::CaptureLogs::startCapturingLogMessages() {
invariant(!_isCapturingLogMessages);
_capturedLogMessages.clear();
- if (!_captureAppender) {
- _captureAppender = std::make_unique<StringVectorAppender>(&_capturedLogMessages);
+
+ if (logV2Enabled()) {
+ if (!_captureSink) {
+ _captureSink = logv2::LogCaptureBackend::create(_capturedLogMessages);
+ _captureSink->set_filter(
+ logv2::AllLogsFilter(logv2::LogManager::global().getGlobalDomain()));
+ _captureSink->set_formatter(logv2::PlainFormatter());
+ }
+ boost::log::core::get()->add_sink(_captureSink);
+ } else {
+ if (!_captureAppender) {
+ _captureAppender = std::make_unique<StringVectorAppender>(&_capturedLogMessages);
+ }
+ checked_cast<StringVectorAppender*>(_captureAppender.get())->enable();
+ _captureAppenderHandle =
+ logger::globalLogDomain()->attachAppender(std::move(_captureAppender));
}
- checked_cast<StringVectorAppender*>(_captureAppender.get())->enable();
- _captureAppenderHandle = logger::globalLogDomain()->attachAppender(std::move(_captureAppender));
+
_isCapturingLogMessages = true;
}
-void Test::stopCapturingLogMessages() {
+void Test::CaptureLogs::stopCapturingLogMessages() {
invariant(_isCapturingLogMessages);
- invariant(!_captureAppender);
- _captureAppender = logger::globalLogDomain()->detachAppender(_captureAppenderHandle);
- checked_cast<StringVectorAppender*>(_captureAppender.get())->disable();
+ if (logV2Enabled()) {
+ boost::log::core::get()->remove_sink(_captureSink);
+ } else {
+ invariant(!_captureAppender);
+ _captureAppender = logger::globalLogDomain()->detachAppender(_captureAppenderHandle);
+ checked_cast<StringVectorAppender*>(_captureAppender.get())->disable();
+ }
+
_isCapturingLogMessages = false;
}
-void Test::printCapturedLogLines() const {
+
+const std::vector<std::string>& Test::CaptureLogs::getCapturedTextFormatLogMessages() const {
+ return _capturedLogMessages;
+}
+
+void Test::CaptureLogs::printCapturedTextFormatLogLines() const {
log() << "****************************** Captured Lines (start) *****************************";
- for (const auto& line : getCapturedLogMessages()) {
+ for (const auto& line : getCapturedTextFormatLogMessages()) {
log() << line;
}
log() << "****************************** Captured Lines (end) ******************************";
}
-int64_t Test::countLogLinesContaining(const std::string& needle) {
- const auto& msgs = getCapturedLogMessages();
+int64_t Test::CaptureLogs::countTextFormatLogLinesContaining(const std::string& needle) {
+ const auto& msgs = getCapturedTextFormatLogMessages();
return std::count_if(
msgs.begin(), msgs.end(), [&](const std::string& s) { return stringContains(s, needle); });
}
+void Test::startCapturingLogMessages() {
+ _captureLogs->startCapturingLogMessages();
+}
+void Test::stopCapturingLogMessages() {
+ _captureLogs->stopCapturingLogMessages();
+}
+const std::vector<std::string>& Test::getCapturedTextFormatLogMessages() const {
+ return _captureLogs->getCapturedTextFormatLogMessages();
+}
+int64_t Test::countTextFormatLogLinesContaining(const std::string& needle) {
+ return _captureLogs->countTextFormatLogLinesContaining(needle);
+}
+void Test::printCapturedTextFormatLogLines() const {
+ _captureLogs->printCapturedTextFormatLogLines();
+}
+
Suite::Suite(ConstructorEnable, std::string name) : _name(std::move(name)) {}
void Suite::add(std::string name, std::string fileName, std::function<void()> testFn) {
diff --git a/src/mongo/unittest/unittest.h b/src/mongo/unittest/unittest.h
index ebd63872978..30ff41a6971 100644
--- a/src/mongo/unittest/unittest.h
+++ b/src/mongo/unittest/unittest.h
@@ -569,19 +569,17 @@ protected:
* Gets a vector of strings, one log line per string, captured since
* the last call to startCapturingLogMessages() in this test.
*/
- const std::vector<std::string>& getCapturedLogMessages() const {
- return _capturedLogMessages;
- }
+ const std::vector<std::string>& getCapturedTextFormatLogMessages() const;
/**
* Returns the number of collected log lines containing "needle".
*/
- int64_t countLogLinesContaining(const std::string& needle);
+ int64_t countTextFormatLogLinesContaining(const std::string& needle);
/**
* Prints the captured log lines.
*/
- void printCapturedLogLines() const;
+ void printCapturedTextFormatLogLines() const;
private:
/**
@@ -589,10 +587,9 @@ private:
*/
virtual void _doTest() = 0;
- bool _isCapturingLogMessages;
- std::vector<std::string> _capturedLogMessages;
- logger::MessageLogDomain::AppenderHandle _captureAppenderHandle;
- std::unique_ptr<logger::MessageLogDomain::EventAppender> _captureAppender;
+
+ class CaptureLogs;
+ std::unique_ptr<CaptureLogs> _captureLogs;
};
/**