Merge #12569: net: Increase signal-to-noise ratio in debug.log by adjusting log level when logging failed non-manual connect():s

cba2800 Increase signal-to-noise ratio in debug.log by adjusting log level when logging failed non-manual connect():s (practicalswift)

Pull request description:

  Increase signal-to-noise ratio in `debug.log` by adjusting log level when logging failed non-manual `connect()`:s.

  Before this patch:

  ```
  $ src/bitcoind -printtoconsole
  …
  2018-02-28 18:42:51 UpdateTip: new best=0000000000005448b10a219683d34b770a28044e1cc421032dea1a79ff548948 height=1286903 version=0x20000000 log2_work=69.791313 tx=17408546 date='2018-02-28 18:42:46' progress=1.000000 cache=0.0MiB(173txo)
  2018-02-28 18:37:52 connect() 10.11.21.34:18333 failed after select(): Connection refused (111)
  2018-02-28 18:43:22 connect() to 10.11.43.14:18333 failed after select(): Network is unreachable (101)
  2018-02-28 18:44:49 UpdateTip: new best=000000000000029a521ff2803e1441b09413b876accff5084a4cccf7747d798b height=1286904 version=0x20000000 log2_work=69.791345 tx=17408559 date='2018-02-28 18:44:51' progress=1.000000 cache=0.1MiB(502txo)
  2018-02-28 18:46:54 connect() to [2001:0:9d38:78ff:1234:1234:1234:1234]:18333 failed: Network is unreachable (101)
  2018-02-28 18:48:56 connect() to [2001:0:9d38:6aff:1234:1234:1234:1234]:18333 failed: Network is unreachable (101)
  2018-02-28 18:49:11 UpdateTip: new best=000000000000000206b79eb235e5dd907b6369de0e5d764330bf40ec0d460311 height=1286905 version=0x20000000 log2_work=69.791377 tx=17408577 date='2018-02-28 18:49:12' progress=1.000000 cache=1.0MiB(5245txo)
  ```

  After this patch:

  ```
  $ src/bitcoind -printtoconsole
  …
  2018-02-28 18:42:51 UpdateTip: new best=0000000000005448b10a219683d34b770a28044e1cc421032dea1a79ff548948 height=1286903 version=0x20000000 log2_work=69.791313 tx=17408546 date='2018-02-28 18:42:46' progress=1.000000 cache=0.0MiB(173txo)
  2018-02-28 18:44:49 UpdateTip: new best=000000000000029a521ff2803e1441b09413b876accff5084a4cccf7747d798b height=1286904 version=0x20000000 log2_work=69.791345 tx=17408559 date='2018-02-28 18:44:51' progress=1.000000 cache=0.1MiB(502txo)
  2018-02-28 18:49:11 UpdateTip: new best=000000000000000206b79eb235e5dd907b6369de0e5d764330bf40ec0d460311 height=1286905 version=0x20000000 log2_work=69.791377 tx=17408577 date='2018-02-28 18:49:12' progress=1.000000 cache=1.0MiB(5245txo)
  ```

  Please note that "manual `connect()`:s" (invoked via `-connect`, `-proxy` or `addnode`) are still reported at the default log level as these messages are likely to be relevant to end-users:

  ```
  $ src/bitcoind -printtoconsole -connect=127.0.0.1:1234
  …
  2018-02-28 18:31:13 connect() to 127.0.0.1:1234 failed after select(): Connection refused (111)

  $ src/bitcoind -printtoconsole -proxy=127.0.0.1:1234
  …
  2018-02-28 18:32:32 connect() to 127.0.0.1:1234 failed after select(): Connection refused (111)

  $ src/bitcoind -printtoconsole &
  $ src/bitcoin-cli addnode 127.0.0.1:1234 onetry
  …
  2018-02-28 18:33:40 connect() to 127.0.0.1:1234 failed after select(): Connection refused (111)
  ```

Tree-SHA512: 92e3c1e4b54ce8ccdd7ec31de147c8505710cd799ceb2bbc8576a086709967802403c9184df364b3cfa59bd98859f6ac8feb27fb09b9324194c6c47a042fc6d3

4 files changed, 21 insertions, 9 deletions

diff --git a/src/net.cpp b/src/net.cpp
index 342dfbaeb9..db40371772 100644
--- a/src/net.cpp
+++ b/src/net.cpp
@@ -368,7 +368,7 @@ static CAddress GetBindAddress(SOCKET sock)
     return addr_bind;
 }
 
-CNode* CConnman::ConnectNode(CAddress addrConnect, const char *pszDest, bool fCountFailure)
+CNode* CConnman::ConnectNode(CAddress addrConnect, const char *pszDest, bool fCountFailure, bool manual_connection)
 {
     if (pszDest == nullptr) {
         if (IsLocal(addrConnect))
@@ -432,7 +432,7 @@ CNode* CConnman::ConnectNode(CAddress addrConnect, const char *pszDest, bool fCo
             if (hSocket == INVALID_SOCKET) {
                 return nullptr;
             }
-            connected = ConnectSocketDirectly(addrConnect, hSocket, nConnectTimeout);
+            connected = ConnectSocketDirectly(addrConnect, hSocket, nConnectTimeout, manual_connection);
         }
         if (!proxyConnectionFailed) {
             // If a connection to the node was attempted, and failure (if any) is not caused by a problem connecting to
@@ -1992,7 +1992,7 @@ void CConnman::OpenNetworkConnection(const CAddress& addrConnect, bool fCountFai
     } else if (FindNode(std::string(pszDest)))
         return;
 
-    CNode* pnode = ConnectNode(addrConnect, pszDest, fCountFailure);
+    CNode* pnode = ConnectNode(addrConnect, pszDest, fCountFailure, manual_connection);
 
     if (!pnode)
         return;
diff --git a/src/net.h b/src/net.h
index 7839b75a86..1bcc3cbb44 100644
--- a/src/net.h
+++ b/src/net.h
@@ -338,7 +338,7 @@ private:
     CNode* FindNode(const CService& addr);
 
     bool AttemptToEvictConnection();
-    CNode* ConnectNode(CAddress addrConnect, const char *pszDest, bool fCountFailure);
+    CNode* ConnectNode(CAddress addrConnect, const char *pszDest, bool fCountFailure, bool manual_connection);
     bool IsWhitelistedRange(const CNetAddr &addr);
 
     void DeleteNode(CNode* pnode);
diff --git a/src/netbase.cpp b/src/netbase.cpp
index 92ac1c4c85..5d3d2f25c8 100644
--- a/src/netbase.cpp
+++ b/src/netbase.cpp
@@ -9,6 +9,7 @@
 #include <sync.h>
 #include <uint256.h>
 #include <random.h>
+#include <tinyformat.h>
 #include <util.h>
 #include <utilstrencodings.h>
 
@@ -468,7 +469,17 @@ SOCKET CreateSocket(const CService &addrConnect)
     return hSocket;
 }
 
-bool ConnectSocketDirectly(const CService &addrConnect, const SOCKET& hSocket, int nTimeout)
+template<typename... Args>
+static void LogConnectFailure(bool manual_connection, const char* fmt, const Args&... args) {
+    std::string error_message = tfm::format(fmt, args...);
+    if (manual_connection) {
+        LogPrintf("%s\n", error_message);
+    } else {
+        LogPrint(BCLog::NET, "%s\n", error_message);
+    }
+}
+
+bool ConnectSocketDirectly(const CService &addrConnect, const SOCKET& hSocket, int nTimeout, bool manual_connection)
 {
     struct sockaddr_storage sockaddr;
     socklen_t len = sizeof(sockaddr);
@@ -513,7 +524,7 @@ bool ConnectSocketDirectly(const CService &addrConnect, const SOCKET& hSocket, i
             }
             if (nRet != 0)
             {
-                LogPrintf("connect() to %s failed after select(): %s\n", addrConnect.ToString(), NetworkErrorString(nRet));
+                LogConnectFailure(manual_connection, "connect() to %s failed after select(): %s", addrConnect.ToString(), NetworkErrorString(nRet));
                 return false;
             }
         }
@@ -523,7 +534,7 @@ bool ConnectSocketDirectly(const CService &addrConnect, const SOCKET& hSocket, i
         else
 #endif
         {
-            LogPrintf("connect() to %s failed: %s\n", addrConnect.ToString(), NetworkErrorString(WSAGetLastError()));
+            LogConnectFailure(manual_connection, "connect() to %s failed: %s", addrConnect.ToString(), NetworkErrorString(WSAGetLastError()));
             return false;
         }
     }
@@ -581,7 +592,7 @@ bool IsProxy(const CNetAddr &addr) {
 bool ConnectThroughProxy(const proxyType &proxy, const std::string& strDest, int port, const SOCKET& hSocket, int nTimeout, bool *outProxyConnectionFailed)
 {
     // first connect to proxy server
-    if (!ConnectSocketDirectly(proxy.proxy, hSocket, nTimeout)) {
+    if (!ConnectSocketDirectly(proxy.proxy, hSocket, nTimeout, true)) {
         if (outProxyConnectionFailed)
             *outProxyConnectionFailed = true;
         return false;
@@ -601,6 +612,7 @@ bool ConnectThroughProxy(const proxyType &proxy, const std::string& strDest, int
     }
     return true;
 }
+
 bool LookupSubNet(const char* pszName, CSubNet& ret)
 {
     std::string strSubnet(pszName);
diff --git a/src/netbase.h b/src/netbase.h
index c0921b6441..50d4bc54fa 100644
--- a/src/netbase.h
+++ b/src/netbase.h
@@ -52,7 +52,7 @@ bool Lookup(const char *pszName, std::vector<CService>& vAddr, int portDefault,
 CService LookupNumeric(const char *pszName, int portDefault = 0);
 bool LookupSubNet(const char *pszName, CSubNet& subnet);
 SOCKET CreateSocket(const CService &addrConnect);
-bool ConnectSocketDirectly(const CService &addrConnect, const SOCKET& hSocketRet, int nTimeout);
+bool ConnectSocketDirectly(const CService &addrConnect, const SOCKET& hSocketRet, int nTimeout, bool manual_connection);
 bool ConnectThroughProxy(const proxyType &proxy, const std::string& strDest, int port, const SOCKET& hSocketRet, int nTimeout, bool *outProxyConnectionFailed);
 /** Return readable error string for a network error code */
 std::string NetworkErrorString(int err);