SERVER-19127 Fix race condition in unittest log line capturing.

The approach of this fix is to first make the appender for capturing log lines
thread safe, and then to make it very unlikely that bad things happen if a test
races between logging and detaching the special capture appender.  We make it
unlikely by taking advantage of the fact that appenders are removed by setting a
pointer in a vector to NULL, and make sure that the capture appender is not
destroyed when it is detached, but rather when the test fixture destructor runs.
This means that if logging only occurs while a test fixture exists (likely if
tests don't start threads outside of fixtures), tests will not try to use a
capture appender that has gone out of scope.

2 files changed, 30 insertions, 4 deletions

diff --git a/src/mongo/unittest/unittest.cpp b/src/mongo/unittest/unittest.cpp
index ac0820de084..3e81b89b65e 100644
--- a/src/mongo/unittest/unittest.cpp
+++ b/src/mongo/unittest/unittest.cpp
@@ -35,12 +35,15 @@
 #include <iostream>
 #include <map>
 
+#include "mongo/base/checked_cast.h"
 #include "mongo/base/init.h"
 #include "mongo/logger/console_appender.h"
 #include "mongo/logger/log_manager.h"
 #include "mongo/logger/logger.h"
 #include "mongo/logger/message_event_utf8_encoder.h"
 #include "mongo/logger/message_log_domain.h"
+#include "mongo/stdx/memory.h"
+#include "mongo/stdx/mutex.h"
 #include "mongo/util/assert_util.h"
 #include "mongo/util/log.h"
 #include "mongo/util/timer.h"
@@ -160,11 +163,28 @@ public:
         if (!_encoder.encode(event, _os)) {
             return Status(ErrorCodes::LogWriteFailed, "Failed to append to LogTestAppender.");
         }
-        _lines->push_back(_os.str());
+        stdx::lock_guard<stdx::mutex> lk(_mutex);
+        if (_enabled) {
+            _lines->push_back(_os.str());
+        }
         return Status::OK();
     }
 
+    void enable() {
+        stdx::lock_guard<stdx::mutex> lk(_mutex);
+        invariant(!_enabled);
+        _enabled = true;
+    }
+
+    void disable() {
+        stdx::lock_guard<stdx::mutex> lk(_mutex);
+        invariant(_enabled);
+        _enabled = false;
+    }
+
 private:
+    stdx::mutex _mutex;
+    bool _enabled = false;
     logger::MessageEventDetailsEncoder _encoder;
     std::vector<std::string>* _lines;
 };
@@ -173,14 +193,19 @@ private:
 void Test::startCapturingLogMessages() {
     invariant(!_isCapturingLogMessages);
     _capturedLogMessages.clear();
-    _captureAppenderHandle = logger::globalLogDomain()->attachAppender(
-        logger::MessageLogDomain::AppenderAutoPtr(new StringVectorAppender(&_capturedLogMessages)));
+    if (!_captureAppender) {
+        _captureAppender = stdx::make_unique<StringVectorAppender>(&_capturedLogMessages);
+    }
+    checked_cast<StringVectorAppender*>(_captureAppender.get())->enable();
+    _captureAppenderHandle = logger::globalLogDomain()->attachAppender(std::move(_captureAppender));
     _isCapturingLogMessages = true;
 }
 
 void Test::stopCapturingLogMessages() {
     invariant(_isCapturingLogMessages);
-    logger::globalLogDomain()->detachAppender(_captureAppenderHandle);
+    invariant(!_captureAppender);
+    _captureAppender = logger::globalLogDomain()->detachAppender(_captureAppenderHandle);
+    checked_cast<StringVectorAppender*>(_captureAppender.get())->disable();
     _isCapturingLogMessages = false;
 }
 
diff --git a/src/mongo/unittest/unittest.h b/src/mongo/unittest/unittest.h
index 0ea7b8e4cc5..d613822441e 100644
--- a/src/mongo/unittest/unittest.h
+++ b/src/mongo/unittest/unittest.h
@@ -339,6 +339,7 @@ private:
     bool _isCapturingLogMessages;
     std::vector<std::string> _capturedLogMessages;
     logger::MessageLogDomain::AppenderHandle _captureAppenderHandle;
+    logger::MessageLogDomain::AppenderAutoPtr _captureAppender;
 };
 
 /**