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]:18333 failed: Network is unreachable (101)
  2018-02-28 18:48:56 connect() to [2001:0:9d38:6aff: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
This commit is contained in:
Wladimir J. van der Laan 2018-04-13 19:15:35 +02:00
commit 23e7fe8be8
No known key found for this signature in database
GPG key ID: 1E4AED62986CD25D
4 changed files with 21 additions and 9 deletions

View file

@ -368,7 +368,7 @@ static CAddress GetBindAddress(SOCKET sock)
return addr_bind; 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 (pszDest == nullptr) {
if (IsLocal(addrConnect)) if (IsLocal(addrConnect))
@ -432,7 +432,7 @@ CNode* CConnman::ConnectNode(CAddress addrConnect, const char *pszDest, bool fCo
if (hSocket == INVALID_SOCKET) { if (hSocket == INVALID_SOCKET) {
return nullptr; return nullptr;
} }
connected = ConnectSocketDirectly(addrConnect, hSocket, nConnectTimeout); connected = ConnectSocketDirectly(addrConnect, hSocket, nConnectTimeout, manual_connection);
} }
if (!proxyConnectionFailed) { if (!proxyConnectionFailed) {
// If a connection to the node was attempted, and failure (if any) is not caused by a problem connecting to // 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))) } else if (FindNode(std::string(pszDest)))
return; return;
CNode* pnode = ConnectNode(addrConnect, pszDest, fCountFailure); CNode* pnode = ConnectNode(addrConnect, pszDest, fCountFailure, manual_connection);
if (!pnode) if (!pnode)
return; return;

View file

@ -338,7 +338,7 @@ private:
CNode* FindNode(const CService& addr); CNode* FindNode(const CService& addr);
bool AttemptToEvictConnection(); 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); bool IsWhitelistedRange(const CNetAddr &addr);
void DeleteNode(CNode* pnode); void DeleteNode(CNode* pnode);

View file

@ -9,6 +9,7 @@
#include <sync.h> #include <sync.h>
#include <uint256.h> #include <uint256.h>
#include <random.h> #include <random.h>
#include <tinyformat.h>
#include <util.h> #include <util.h>
#include <utilstrencodings.h> #include <utilstrencodings.h>
@ -468,7 +469,17 @@ SOCKET CreateSocket(const CService &addrConnect)
return hSocket; 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; struct sockaddr_storage sockaddr;
socklen_t len = sizeof(sockaddr); socklen_t len = sizeof(sockaddr);
@ -513,7 +524,7 @@ bool ConnectSocketDirectly(const CService &addrConnect, const SOCKET& hSocket, i
} }
if (nRet != 0) 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; return false;
} }
} }
@ -523,7 +534,7 @@ bool ConnectSocketDirectly(const CService &addrConnect, const SOCKET& hSocket, i
else else
#endif #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; 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) bool ConnectThroughProxy(const proxyType &proxy, const std::string& strDest, int port, const SOCKET& hSocket, int nTimeout, bool *outProxyConnectionFailed)
{ {
// first connect to proxy server // first connect to proxy server
if (!ConnectSocketDirectly(proxy.proxy, hSocket, nTimeout)) { if (!ConnectSocketDirectly(proxy.proxy, hSocket, nTimeout, true)) {
if (outProxyConnectionFailed) if (outProxyConnectionFailed)
*outProxyConnectionFailed = true; *outProxyConnectionFailed = true;
return false; return false;
@ -601,6 +612,7 @@ bool ConnectThroughProxy(const proxyType &proxy, const std::string& strDest, int
} }
return true; return true;
} }
bool LookupSubNet(const char* pszName, CSubNet& ret) bool LookupSubNet(const char* pszName, CSubNet& ret)
{ {
std::string strSubnet(pszName); std::string strSubnet(pszName);

View file

@ -52,7 +52,7 @@ bool Lookup(const char *pszName, std::vector<CService>& vAddr, int portDefault,
CService LookupNumeric(const char *pszName, int portDefault = 0); CService LookupNumeric(const char *pszName, int portDefault = 0);
bool LookupSubNet(const char *pszName, CSubNet& subnet); bool LookupSubNet(const char *pszName, CSubNet& subnet);
SOCKET CreateSocket(const CService &addrConnect); 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); 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 */ /** Return readable error string for a network error code */
std::string NetworkErrorString(int err); std::string NetworkErrorString(int err);