SERVER-28760 Add egress logging to DBConnectionPool

1 files changed, 35 insertions, 6 deletions

diff --git a/src/mongo/client/connpool.cpp b/src/mongo/client/connpool.cpp
index 9ad9d62bb5e..fce7beb2224 100644
--- a/src/mongo/client/connpool.cpp
+++ b/src/mongo/client/connpool.cpp
@@ -62,6 +62,11 @@ PoolForHost::~PoolForHost() {
 }
 
 void PoolForHost::clear() {
+    if (!_parentDestroyed) {
+        log() << "Dropping all pooled connections to " << _hostName << "(with timeout of "
+              << _socketTimeout << " seconds)";
+    }
+
     _pool = decltype(_pool){};
 }
 
@@ -80,11 +85,17 @@ void PoolForHost::done(DBConnectionPool* pool, DBClientBase* c_raw) {
     bool isBroken = c->getSockCreationMicroSec() < _minValidCreationTimeMicroSec;
     if (isFailed || isBroken) {
         _badConns++;
-    }
-
-    if (isFailed || isBroken ||
+        log() << "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.get());
+    } else if (_maxPoolSize >= 0 && static_cast<int>(_pool.size()) >= _maxPoolSize) {
         // We have a pool size that we need to enforce
-        (_maxPoolSize >= 0 && static_cast<int>(_pool.size()) >= _maxPoolSize)) {
+        log() << "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.get());
     } else {
         // The connection is probably fine, save for later
@@ -97,7 +108,7 @@ void PoolForHost::reportBadConnectionAt(uint64_t microSec) {
         microSec > _minValidCreationTimeMicroSec) {
         _minValidCreationTimeMicroSec = microSec;
         log() << "Detected bad connection created at " << _minValidCreationTimeMicroSec
-              << " microSec, clearing pool for " << _hostName << " of " << _pool.size()
+              << " microSec, clearing pool for " << _hostName << " of " << openConnections()
               << " connections" << endl;
         clear();
     }
@@ -189,10 +200,17 @@ DBClientBase* DBConnectionPool::_get(const string& ident, double socketTimeout)
     stdx::lock_guard<stdx::mutex> L(_mutex);
     PoolForHost& p = _pools[PoolKey(ident, socketTimeout)];
     p.setMaxPoolSize(_maxPoolSize);
+    p.setSocketTimeout(socketTimeout);
     p.initializeHostName(ident);
     return p.get(this, socketTimeout);
 }
 
+int DBConnectionPool::openConnections(const string& ident, double socketTimeout) {
+    stdx::lock_guard<stdx::mutex> L(_mutex);
+    PoolForHost& p = _pools[PoolKey(ident, socketTimeout)];
+    return p.openConnections();
+}
+
 DBClientBase* DBConnectionPool::_finishCreate(const string& ident,
                                               double socketTimeout,
                                               DBClientBase* conn) {
@@ -212,6 +230,10 @@ DBClientBase* DBConnectionPool::_finishCreate(const string& ident,
         throw;
     }
 
+    log() << "Successfully connected to " << ident << " (" << openConnections(ident, socketTimeout)
+          << " connections now open to " << ident << " with a " << socketTimeout
+          << " second timeout)";
+
     return conn;
 }
 
@@ -259,6 +281,7 @@ DBClientBase* DBConnectionPool::get(const string& host, double socketTimeout) {
                               host,
                               11002,
                               str::stream() << _name << " error: " << errmsg);
+
     return _finishCreate(host, socketTimeout, c);
 }
 
@@ -307,7 +330,13 @@ void DBConnectionPool::release(const string& host, DBClientBase* c) {
 
 
 DBConnectionPool::~DBConnectionPool() {
-    // connection closing is handled by ~PoolForHost
+    // Do not log in destruction, because global connection pools get
+    // destroyed after the logging framework.
+    stdx::lock_guard<stdx::mutex> L(_mutex);
+    for (PoolMap::iterator i = _pools.begin(); i != _pools.end(); i++) {
+        PoolForHost& p = i->second;
+        p._parentDestroyed = true;
+    }
 }
 
 void DBConnectionPool::flush() {