SERVER-28760 Add egress logging to DBConnectionPool

2 files changed, 46 insertions, 5 deletions

diff --git a/src/mongo/client/connpool.cpp b/src/mongo/client/connpool.cpp
index 9ad9d62bb5e..8fd4a5f1b8b 100644
--- a/src/mongo/client/connpool.cpp
+++ b/src/mongo/client/connpool.cpp
@@ -62,6 +62,9 @@ PoolForHost::~PoolForHost() {
 }
 
 void PoolForHost::clear() {
+    log() << "Dropping all pooled connections to " << _hostName << "(with timeout of "
+          << _socketTimeout << " seconds)";
+
     _pool = decltype(_pool){};
 }
 
@@ -80,11 +83,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 +106,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 +198,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 +228,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 +279,7 @@ DBClientBase* DBConnectionPool::get(const string& host, double socketTimeout) {
                               host,
                               11002,
                               str::stream() << _name << " error: " << errmsg);
+
     return _finishCreate(host, socketTimeout, c);
 }
 
diff --git a/src/mongo/client/connpool.h b/src/mongo/client/connpool.h
index 4599a6fdf30..7ce7022390e 100644
--- a/src/mongo/client/connpool.h
+++ b/src/mongo/client/connpool.h
@@ -103,6 +103,13 @@ public:
         _maxPoolSize = maxPoolSize;
     }
 
+    /**
+     * Sets the socket timeout on this host, for reporting purposes only.
+     */
+    void setSocketTimeout(double socketTimeout) {
+        _socketTimeout = socketTimeout;
+    }
+
     int numAvailable() const {
         return (int)_pool.size();
     }
@@ -111,6 +118,13 @@ public:
         return _checkedOut;
     }
 
+    /**
+     * Returns the number of open connections in this pool.
+     */
+    int openConnections() const {
+        return numInUse() + numAvailable();
+    }
+
     void createdOne(DBClientBase* base);
     long long numCreated() const {
         return _created;
@@ -163,6 +177,7 @@ private:
     };
 
     std::string _hostName;
+    double _socketTimeout;
     std::stack<StoredConnection> _pool;
 
     int64_t _created;
@@ -224,6 +239,11 @@ public:
     }
 
     /**
+     * Returns the number of connections to the given host pool.
+     */
+    int openConnections(const std::string& ident, double socketTimeout);
+
+    /**
      * Sets the maximum number of connections pooled per-host.
      *
      * This setting only applies to new host connection pools, previously-pooled host pools are