SERVER-51679 Fix race condition in Free Monitoring when free monitoring document is deleted

7 files changed, 104 insertions, 6 deletions

diff --git a/src/mongo/db/free_mon/free_mon_controller.cpp b/src/mongo/db/free_mon/free_mon_controller.cpp
index 45f4b4b5461..7302859bbd1 100644
--- a/src/mongo/db/free_mon/free_mon_controller.cpp
+++ b/src/mongo/db/free_mon/free_mon_controller.cpp
@@ -201,13 +201,22 @@ void FreeMonController::turnCrankForTest(size_t countMessagesToIgnore) {
         invariant(_state == State::kStarted);
     }
 
-    LOGV2(20610,
-          "Turning Crank: {countMessagesToIgnore}",
-          "countMessagesToIgnore"_attr = countMessagesToIgnore);
+    LOGV2(20610, "Turning Crank", "count"_attr = countMessagesToIgnore);
 
     _processor->turnCrankForTest(countMessagesToIgnore);
 }
 
+void FreeMonController::deprioritizeFirstMessageForTest(FreeMonMessageType type) {
+    {
+        stdx::lock_guard<Latch> lock(_mutex);
+        invariant(_state == State::kStarted);
+    }
+
+    LOGV2(5167901, "Deprioritize message", "type"_attr = static_cast<int>(type));
+
+    _processor->deprioritizeFirstMessageForTest(type);
+}
+
 void FreeMonController::getStatus(OperationContext* opCtx, BSONObjBuilder* status) {
     {
         stdx::lock_guard<Latch> lock(_mutex);
diff --git a/src/mongo/db/free_mon/free_mon_controller.h b/src/mongo/db/free_mon/free_mon_controller.h
index 5c74a8a4b5f..7cebd2f2c07 100644
--- a/src/mongo/db/free_mon/free_mon_controller.h
+++ b/src/mongo/db/free_mon/free_mon_controller.h
@@ -75,6 +75,11 @@ public:
     void turnCrankForTest(size_t countMessagesToIgnore);
 
     /**
+     * Deproritize the first message to force interleavings of messages.
+     */
+    void deprioritizeFirstMessageForTest(FreeMonMessageType type);
+
+    /**
      * Add a metric collector to collect on registration
      */
     void addRegistrationCollector(std::unique_ptr<FreeMonCollectorInterface> collector);
diff --git a/src/mongo/db/free_mon/free_mon_controller_test.cpp b/src/mongo/db/free_mon/free_mon_controller_test.cpp
index e1b6f7afd81..4225e71efbb 100644
--- a/src/mongo/db/free_mon/free_mon_controller_test.cpp
+++ b/src/mongo/db/free_mon/free_mon_controller_test.cpp
@@ -1360,7 +1360,7 @@ void FreeMonControllerRSTest::tearDown() {
 TEST_F(FreeMonControllerRSTest, TransitionToPrimary) {
     ControllerHolder controller(_mockThreadPool.get(), FreeMonNetworkInterfaceMock::Options());
 
-    // Now become a secondary, then primary, and try what happens when we become primary
+    // Now become a secondary, then primary, and see what happens when we become primary
     ASSERT_OK(_getReplCoord()->setFollowerMode(repl::MemberState::RS_SECONDARY));
     ASSERT_OK(_getReplCoord()->setFollowerMode(repl::MemberState::RS_PRIMARY));
 
@@ -1384,7 +1384,7 @@ TEST_F(FreeMonControllerRSTest, StartupOnSecondary) {
 
     FreeMonStorage::replace(_opCtx.get(), initStorage(StorageStateEnum::enabled));
 
-    // Now become a secondary, then primary, and try what happens when we become primary
+    // Now become a secondary, then primary, and see what happens when we become primary
     ASSERT_OK(_getReplCoord()->setFollowerMode(repl::MemberState::RS_SECONDARY));
 
     controller.start(RegistrationType::RegisterAfterOnTransitionToPrimary);
@@ -1555,6 +1555,54 @@ TEST_F(FreeMonControllerRSTest, SecondaryStopOnDocumentDrop) {
     ASSERT_GTE(controller.metricsCollector->count(), 2UL);
 }
 
+
+// Positive: Test Metrics works on secondary after opObserver delete of document between metrics
+// send and metrics async complete
+TEST_F(FreeMonControllerRSTest, SecondaryStopOnDocumentDropDuringCollect) {
+    ControllerHolder controller(_mockThreadPool.get(), FreeMonNetworkInterfaceMock::Options());
+
+    FreeMonStorage::replace(_opCtx.get(), initStorage(StorageStateEnum::enabled));
+
+    // Now become a secondary
+    ASSERT_OK(_getReplCoord()->setFollowerMode(repl::MemberState::RS_SECONDARY));
+
+    controller.start(RegistrationType::RegisterAfterOnTransitionToPrimary);
+
+    controller->turnCrankForTest(Turner().registerServer().registerCommand().collect(1));
+
+    ASSERT_EQ(controller.metricsCollector->count(), 1UL);
+
+    // Crank the metrics send but not the complete
+    controller->turnCrankForTest(Turner().collect(1));
+
+    controller->notifyOnDelete();
+
+    // Move the notify delete above the async metrics complete
+    controller->deprioritizeFirstMessageForTest(FreeMonMessageType::AsyncMetricsComplete);
+
+    // There is a race condition where sometimes metrics send sneaks in
+    // Crank the notifyDelete and the async metrics complete.
+    controller->turnCrankForTest(Turner().notifyDelete().collect(1));
+
+    controller->turnCrankForTest(Turner().metricsSend().collect(2));
+
+    ASSERT_TRUE(FreeMonStorage::read(_opCtx.get()).is_initialized());
+
+    // Since there is no local write, it remains enabled
+    ASSERT_TRUE(FreeMonStorage::read(_opCtx.get()).get().getState() == StorageStateEnum::enabled);
+
+    BSONObjBuilder builder;
+    controller->getServerStatus(_opCtx.get(), &builder);
+    auto obj = builder.obj();
+    ASSERT_BSONOBJ_EQ(BSON("state"
+                           << "undecided"),
+                      obj);
+
+    ASSERT_EQ(controller.registerCollector->count(), 1UL);
+    ASSERT_EQ(controller.metricsCollector->count(), 5UL);
+}
+
+
 // Negative: Test nice shutdown on bad update
 TEST_F(FreeMonControllerRSTest, SecondaryStartOnBadUpdate) {
     ControllerHolder controller(_mockThreadPool.get(), FreeMonNetworkInterfaceMock::Options());
diff --git a/src/mongo/db/free_mon/free_mon_processor.cpp b/src/mongo/db/free_mon/free_mon_processor.cpp
index ac2d9355635..c91d62204b8 100644
--- a/src/mongo/db/free_mon/free_mon_processor.cpp
+++ b/src/mongo/db/free_mon/free_mon_processor.cpp
@@ -153,6 +153,10 @@ void FreeMonProcessor::turnCrankForTest(size_t countMessagesToIgnore) {
     _countdown.wait();
 }
 
+void FreeMonProcessor::deprioritizeFirstMessageForTest(FreeMonMessageType type) {
+    _queue.deprioritizeFirstMessageForTest(type);
+}
+
 void FreeMonProcessor::run() {
     try {
 
@@ -659,7 +663,7 @@ void FreeMonProcessor::doAsyncRegisterComplete(
 
     LOGV2(20615,
           "Free Monitoring is Enabled. Frequency: {interval} seconds",
-          "Free Moniforing is Enabled",
+          "Free Monitoring is Enabled",
           "interval"_attr = resp.getReportingInterval());
 
     // Enqueue next metrics upload immediately to deliver a good experience
@@ -792,6 +796,13 @@ void FreeMonProcessor::doAsyncMetricsComplete(
     Client* client,
     const FreeMonMessageWithPayload<FreeMonMessageType::AsyncMetricsComplete>* msg) {
 
+    // If we have disabled the store between the metrics send message and the metrcs complete
+    // message then it means that we need to stop processing metrics on this instance. We ignore the
+    // message entirely including an errors as the disabling of the store takes priority.
+    if (_lastReadState == boost::none) {
+        return;
+    }
+
     auto& resp = msg->getPayload();
 
     Status s = validateMetricsResponse(resp);
diff --git a/src/mongo/db/free_mon/free_mon_processor.h b/src/mongo/db/free_mon/free_mon_processor.h
index ab519bfb84d..4064a1d3a8d 100644
--- a/src/mongo/db/free_mon/free_mon_processor.h
+++ b/src/mongo/db/free_mon/free_mon_processor.h
@@ -325,6 +325,11 @@ public:
     void turnCrankForTest(size_t countMessagesToIgnore);
 
     /**
+     * Deproritize the first message to force interleavings of messages.
+     */
+    void deprioritizeFirstMessageForTest(FreeMonMessageType type);
+
+    /**
      * Processes messages forever
      */
     void run();
diff --git a/src/mongo/db/free_mon/free_mon_queue.cpp b/src/mongo/db/free_mon/free_mon_queue.cpp
index 56b01eade93..2e3582f663e 100644
--- a/src/mongo/db/free_mon/free_mon_queue.cpp
+++ b/src/mongo/db/free_mon/free_mon_queue.cpp
@@ -95,6 +95,21 @@ void FreeMonMessageQueue::enqueue(std::shared_ptr<FreeMonMessage> msg) {
     }
 }
 
+void FreeMonMessageQueue::deprioritizeFirstMessageForTest(FreeMonMessageType type) {
+    {
+        stdx::lock_guard<Latch> lock(_mutex);
+
+        auto item = _queue.top();
+        uassert(5167902, "Wrong message type", item->getType() == type);
+
+        _queue.pop();
+
+        ++_counter;
+        item->setId(_counter);
+        _queue.push(item);
+    }
+}
+
 boost::optional<std::shared_ptr<FreeMonMessage>> FreeMonMessageQueue::dequeue(
     ClockSource* clockSource) {
     {
diff --git a/src/mongo/db/free_mon/free_mon_queue.h b/src/mongo/db/free_mon/free_mon_queue.h
index 6e7bb85dcbf..de401e68841 100644
--- a/src/mongo/db/free_mon/free_mon_queue.h
+++ b/src/mongo/db/free_mon/free_mon_queue.h
@@ -128,6 +128,11 @@ public:
      */
     void turnCrankForTest(size_t countMessagesToIgnore);
 
+    /**
+     * Deproritize the first message to force interleavings of messages.
+     */
+    void deprioritizeFirstMessageForTest(FreeMonMessageType type);
+
 private:
     // Condition variable to signal consumer
     stdx::condition_variable _condvar;