SERVER-29152 Do not cache logging ostream in threadlocal when in other thread-specific contexts

4 files changed, 47 insertions, 20 deletions

diff --git a/src/mongo/client/connpool.cpp b/src/mongo/client/connpool.cpp
index a0c491f1a40..dc2678e655b 100644
--- a/src/mongo/client/connpool.cpp
+++ b/src/mongo/client/connpool.cpp
@@ -63,8 +63,8 @@ PoolForHost::~PoolForHost() {
 
 void PoolForHost::clear() {
     if (!_parentDestroyed) {
-        log() << "Dropping all pooled connections to " << _hostName << "(with timeout of "
-              << _socketTimeout << " seconds)";
+        logNoCache() << "Dropping all pooled connections to " << _hostName << "(with timeout of "
+                     << _socketTimeout << " seconds)";
     }
 
     while (!_pool.empty()) {
@@ -88,18 +88,18 @@ void PoolForHost::done(DBConnectionPool* pool, DBClientBase* c) {
     bool isBroken = c->getSockCreationMicroSec() < _minValidCreationTimeMicroSec;
     if (isFailed || isBroken) {
         _badConns++;
-        log() << "Ending connection to host " << _hostName << "(with timeout of " << _socketTimeout
-              << " seconds)"
-              << " due to bad connection status; " << openConnections()
-              << " connections to that host remain open";
+        logNoCache() << "Ending connection to host " << _hostName << "(with timeout of "
+                     << _socketTimeout << " seconds)"
+                     << " due to bad connection status; " << openConnections()
+                     << " connections to that host remain open";
         pool->onDestroy(c);
         delete c;
     } else if (_maxPoolSize >= 0 && static_cast<int>(_pool.size()) >= _maxPoolSize) {
         // We have a pool size that we need to enforce
-        log() << "Ending idle connection to host " << _hostName << "(with timeout of "
-              << _socketTimeout << " seconds)"
-              << " because the pool meets constraints; " << openConnections()
-              << " connections to that host remain open";
+        logNoCache() << "Ending idle connection to host " << _hostName << "(with timeout of "
+                     << _socketTimeout << " seconds)"
+                     << " because the pool meets constraints; " << openConnections()
+                     << " connections to that host remain open";
         pool->onDestroy(c);
         delete c;
     } else {
@@ -112,9 +112,9 @@ void PoolForHost::reportBadConnectionAt(uint64_t microSec) {
     if (microSec != DBClientBase::INVALID_SOCK_CREATION_TIME &&
         microSec > _minValidCreationTimeMicroSec) {
         _minValidCreationTimeMicroSec = microSec;
-        log() << "Detected bad connection created at " << _minValidCreationTimeMicroSec
-              << " microSec, clearing pool for " << _hostName << " of " << openConnections()
-              << " connections" << endl;
+        logNoCache() << "Detected bad connection created at " << _minValidCreationTimeMicroSec
+                     << " microSec, clearing pool for " << _hostName << " of " << openConnections()
+                     << " connections" << endl;
         clear();
     }
 }
@@ -558,8 +558,8 @@ ScopedDbConnection::~ScopedDbConnection() {
             }
         } else {
             /* see done() comments above for why we log this line */
-            log() << "scoped connection to " << _conn->getServerAddress()
-                  << " not being returned to the pool" << endl;
+            logNoCache() << "scoped connection to " << _conn->getServerAddress()
+                         << " not being returned to the pool" << endl;
             kill();
         }
     }
diff --git a/src/mongo/logger/logstream_builder.cpp b/src/mongo/logger/logstream_builder.cpp
index af055be3120..2378558bd4a 100644
--- a/src/mongo/logger/logstream_builder.cpp
+++ b/src/mongo/logger/logstream_builder.cpp
@@ -80,12 +80,14 @@ LogstreamBuilder::LogstreamBuilder(MessageLogDomain* domain,
 LogstreamBuilder::LogstreamBuilder(MessageLogDomain* domain,
                                    StringData contextName,
                                    LogSeverity severity,
-                                   LogComponent component)
+                                   LogComponent component,
+                                   bool shouldCache)
     : _domain(domain),
       _contextName(contextName.toString()),
       _severity(std::move(severity)),
       _component(std::move(component)),
-      _tee(nullptr) {}
+      _tee(nullptr),
+      _shouldCache(shouldCache) {}
 
 LogstreamBuilder::LogstreamBuilder(logger::MessageLogDomain* domain,
                                    StringData contextName,
@@ -110,7 +112,8 @@ LogstreamBuilder::~LogstreamBuilder() {
             _tee->write(_os->str());
         }
         _os->str("");
-        if (isThreadOstreamCacheInitialized && !threadOstreamCache.getMake()->get()) {
+        if (_shouldCache && isThreadOstreamCacheInitialized &&
+            !threadOstreamCache.getMake()->get()) {
             *threadOstreamCache.get() = std::move(_os);
         }
     }
@@ -124,7 +127,8 @@ void LogstreamBuilder::operator<<(Tee* tee) {
 
 void LogstreamBuilder::makeStream() {
     if (!_os) {
-        if (isThreadOstreamCacheInitialized && threadOstreamCache.getMake()->get()) {
+        if (_shouldCache && isThreadOstreamCacheInitialized &&
+            threadOstreamCache.getMake()->get()) {
             _os = std::move(*threadOstreamCache.get());
         } else {
             _os = stdx::make_unique<std::ostringstream>();
diff --git a/src/mongo/logger/logstream_builder.h b/src/mongo/logger/logstream_builder.h
index 1dac8462564..7c1cd62882f 100644
--- a/src/mongo/logger/logstream_builder.h
+++ b/src/mongo/logger/logstream_builder.h
@@ -73,11 +73,17 @@ public:
      * "contextName" is a short name of the thread or other context.
      * "severity" is the logging severity of the message.
      * "component" is the primary log component of the message.
+     *
+     * By default, this class will create one ostream per thread, and it
+     * will cache that object in a threadlocal and reuse it for subsequent
+     * logs messages. Set "shouldCache" to false to create a new ostream
+     * for each instance of this class rather than cacheing.
      */
     LogstreamBuilder(MessageLogDomain* domain,
                      StringData contextName,
                      LogSeverity severity,
-                     LogComponent component);
+                     LogComponent component,
+                     bool shouldCache = true);
 
     /**
      * Deprecated.
@@ -225,6 +231,7 @@ private:
     std::unique_ptr<std::ostringstream> _os;
     Tee* _tee;
     bool _isTruncatable = true;
+    bool _shouldCache;
 };
 
 
diff --git a/src/mongo/util/log.h b/src/mongo/util/log.h
index aed08960309..662db7afe47 100644
--- a/src/mongo/util/log.h
+++ b/src/mongo/util/log.h
@@ -133,6 +133,22 @@ inline LogstreamBuilder log() {
                             ::MongoLogDefaultComponent_component);
 }
 
+/**
+ * Returns a LogstreamBuilder that does not cache its ostream in a threadlocal cache.
+ * Use this variant when logging from places that may not be able to access threadlocals,
+ * such as from within other threadlocal-managed objects, or thread_specific_ptr-managed
+ * objects.
+ *
+ * Once SERVER-29377 is completed, this overload can be removed.
+ */
+inline LogstreamBuilder logNoCache() {
+    return LogstreamBuilder(logger::globalLogDomain(),
+                            getThreadName(),
+                            logger::LogSeverity::Log(),
+                            ::MongoLogDefaultComponent_component,
+                            false);
+}
+
 inline LogstreamBuilder log(logger::LogComponent component) {
     return LogstreamBuilder(
         logger::globalLogDomain(), getThreadName(), logger::LogSeverity::Log(), component);