merge bitcoin#20724: Cleanup of -debug=net log messages

This commit is contained in:
Kittywhiskers Van Gogh 2024-03-24 08:01:35 +00:00
parent 8c63868d9b
commit bcd383c2d6
No known key found for this signature in database
GPG Key ID: 30CD0C065E5C4AAD
3 changed files with 34 additions and 19 deletions

View File

@ -909,9 +909,8 @@ size_t CConnman::SocketSendData(CNode& node)
if (nBytes < 0) {
// error
int nErr = WSAGetLastError();
if (nErr != WSAEWOULDBLOCK && nErr != WSAEMSGSIZE && nErr != WSAEINTR && nErr != WSAEINPROGRESS)
{
LogPrintf("socket send error %s (peer=%d)\n", NetworkErrorString(nErr), node.GetId());
if (nErr != WSAEWOULDBLOCK && nErr != WSAEMSGSIZE && nErr != WSAEINTR && nErr != WSAEINPROGRESS) {
LogPrint(BCLog::NET, "socket send error for peer=%d: %s\n", node.GetId(), NetworkErrorString(nErr));
node.fDisconnect = true;
}
}
@ -1122,6 +1121,7 @@ bool CConnman::AttemptToEvictConnection()
LOCK(cs_vNodes);
for (CNode* pnode : vNodes) {
if (pnode->GetId() == *node_id_to_evict) {
LogPrint(BCLog::NET_NETCONN, "selected %s connection for eviction peer=%d; disconnecting\n", pnode->ConnectionTypeAsString(), pnode->GetId());
pnode->fDisconnect = true;
return true;
}
@ -1195,7 +1195,7 @@ void CConnman::CreateNodeFromAcceptedSocket(SOCKET hSocket,
}
if (!fNetworkActive) {
LogPrintf("%s: not accepting new connections\n", strDropped);
LogPrint(BCLog::NET_NETCONN, "%s: not accepting new connections\n", strDropped);
CloseSocket(hSocket);
return;
}
@ -1492,17 +1492,17 @@ bool CConnman::InactivityCheck(const CNode& node) const
}
if (node.nLastRecv == 0 || node.nLastSend == 0) {
LogPrint(BCLog::NET, "socket no message in first %i seconds, %d %d from %d\n", m_peer_connect_timeout, node.nLastRecv != 0, node.nLastSend != 0, node.GetId());
LogPrint(BCLog::NET, "socket no message in first %i seconds, %d %d peer=%d\n", m_peer_connect_timeout, node.nLastRecv != 0, node.nLastSend != 0, node.GetId());
return true;
}
if (now > node.nLastSend + TIMEOUT_INTERVAL) {
LogPrintf("socket sending timeout: %is\n", now - node.nLastSend);
LogPrint(BCLog::NET, "socket sending timeout: %is peer=%d\n", now - node.nLastSend, node.GetId());
return true;
}
if (now > node.nLastRecv + TIMEOUT_INTERVAL) {
LogPrintf("socket receive timeout: %is\n", now - node.nLastRecv);
LogPrint(BCLog::NET, "socket receive timeout: %is peer=%d\n", now - node.nLastRecv, node.GetId());
return true;
}
@ -1510,12 +1510,12 @@ bool CConnman::InactivityCheck(const CNode& node) const
// We use mockable time for ping timeouts. This means that setmocktime
// may cause pings to time out for peers that have been connected for
// longer than m_peer_connect_timeout.
LogPrintf("ping timeout: %fs\n", 0.000001 * count_microseconds(GetTime<std::chrono::microseconds>() - node.m_ping_start.load()));
LogPrint(BCLog::NET, "ping timeout: %fs peer=%d\n", 0.000001 * count_microseconds(GetTime<std::chrono::microseconds>() - node.m_ping_start.load()), node.GetId());
return true;
}
if (!node.fSuccessfullyConnected) {
LogPrint(BCLog::NET, "version handshake timeout from %d\n", node.GetId());
LogPrint(BCLog::NET, "version handshake timeout peer=%d\n", node.GetId());
return true;
}
@ -3814,6 +3814,7 @@ bool CConnman::DisconnectNode(const std::string& strNode)
{
LOCK(cs_vNodes);
if (CNode* pnode = FindNode(strNode)) {
LogPrint(BCLog::NET_NETCONN, "disconnect by address%s matched peer=%d; disconnecting\n", (fLogIPs ? strprintf("=%s", strNode) : ""), pnode->GetId());
pnode->fDisconnect = true;
return true;
}
@ -3826,6 +3827,7 @@ bool CConnman::DisconnectNode(const CSubNet& subnet)
LOCK(cs_vNodes);
for (CNode* pnode : vNodes) {
if (subnet.Match(pnode->addr)) {
LogPrint(BCLog::NET_NETCONN, "disconnect by subnet%s matched peer=%d; disconnecting\n", (fLogIPs ? strprintf("=%s", subnet.ToString()) : ""), pnode->GetId());
pnode->fDisconnect = true;
disconnected = true;
}
@ -3843,6 +3845,7 @@ bool CConnman::DisconnectNode(NodeId id)
LOCK(cs_vNodes);
for(CNode* pnode : vNodes) {
if (id == pnode->GetId()) {
LogPrint(BCLog::NET_NETCONN, "disconnect by id peer=%d; disconnecting\n", pnode->GetId());
pnode->fDisconnect = true;
return true;
}

View File

@ -1066,13 +1066,14 @@ void PeerManagerImpl::PushNodeVersion(CNode& pnode, int64_t nTime)
nProtocolVersion = gArgs.GetArg("-pushversion", PROTOCOL_VERSION);
}
const bool tx_relay = !m_ignore_incoming_txs && pnode.RelayAddrsWithConn();
m_connman.PushMessage(&pnode, CNetMsgMaker(INIT_PROTO_VERSION).Make(NetMsgType::VERSION, nProtocolVersion, (uint64_t)nLocalNodeServices, nTime, addrYou, addrMe,
nonce, strSubVersion, nNodeStartingHeight, !m_ignore_incoming_txs && pnode.RelayAddrsWithConn(), mnauthChallenge, pnode.m_masternode_connection.load()));
nonce, strSubVersion, nNodeStartingHeight, tx_relay, mnauthChallenge, pnode.m_masternode_connection.load()));
if (fLogIPs) {
LogPrint(BCLog::NET, "send version message: version %d, blocks=%d, us=%s, them=%s, peer=%d\n", nProtocolVersion, nNodeStartingHeight, addrMe.ToString(), addrYou.ToString(), nodeid);
LogPrint(BCLog::NET, "send version message: version %d, blocks=%d, us=%s, them=%s, txrelay=%d, peer=%d\n", nProtocolVersion, nNodeStartingHeight, addrMe.ToString(), addrYou.ToString(), tx_relay, nodeid);
} else {
LogPrint(BCLog::NET, "send version message: version %d, blocks=%d, us=%s, peer=%d\n", nProtocolVersion, nNodeStartingHeight, addrMe.ToString(), nodeid);
LogPrint(BCLog::NET, "send version message: version %d, blocks=%d, us=%s, txrelay=%d, peer=%d\n", nProtocolVersion, nNodeStartingHeight, addrMe.ToString(), tx_relay, nodeid);
}
}
@ -3133,9 +3134,9 @@ void PeerManagerImpl::ProcessMessage(
if (fLogIPs)
remoteAddr = ", peeraddr=" + pfrom.addr.ToString();
LogPrint(BCLog::NET, "receive version message: %s: version %d, blocks=%d, us=%s, peer=%d%s\n",
LogPrint(BCLog::NET, "receive version message: %s: version %d, blocks=%d, us=%s, txrelay=%d, peer=%d%s\n",
cleanSubVer, pfrom.nVersion,
peer->m_starting_height, addrMe.ToString(), pfrom.GetId(),
peer->m_starting_height, addrMe.ToString(), fRelay, pfrom.GetId(),
remoteAddr);
int64_t nTimeOffset = nTime - GetTime();
@ -3144,6 +3145,7 @@ void PeerManagerImpl::ProcessMessage(
// Feeler connections exist only to verify if address is online.
if (pfrom.IsFeelerConn()) {
LogPrint(BCLog::NET_NETCONN, "feeler connection completed peer=%d; disconnecting\n", pfrom.GetId());
pfrom.fDisconnect = true;
}
return;
@ -3161,7 +3163,10 @@ void PeerManagerImpl::ProcessMessage(
bool fBlocksOnly = pfrom.IsBlockRelayOnly();
if (msg_type == NetMsgType::VERACK) {
if (pfrom.fSuccessfullyConnected) return;
if (pfrom.fSuccessfullyConnected) {
LogPrint(BCLog::NET, "ignoring redundant verack message from peer=%d\n", pfrom.GetId());
return;
}
if (!pfrom.IsInboundConn()) {
LogPrintf("New outbound peer connected: version: %d, blocks=%d, peer=%d%s (%s)\n",
@ -3212,6 +3217,7 @@ void PeerManagerImpl::ProcessMessage(
if (pfrom.fSuccessfullyConnected) {
// Disconnect peers that send SENDADDRV2 message after VERACK; this
// must be negotiated between VERSION and VERACK.
LogPrint(BCLog::NET_NETCONN, "sendaddrv2 received after verack from peer=%d; disconnecting\n", pfrom.GetId());
pfrom.fDisconnect = true;
return;
}
@ -3258,6 +3264,7 @@ void PeerManagerImpl::ProcessMessage(
s >> vAddr;
if (!pfrom.RelayAddrsWithConn()) {
LogPrint(BCLog::NET, "ignoring %s message from %s peer=%d\n", msg_type, pfrom.ConnectionTypeAsString(), pfrom.GetId());
return;
}
if (vAddr.size() > MAX_ADDR_TO_SEND)
@ -3300,8 +3307,10 @@ void PeerManagerImpl::ProcessMessage(
m_addrman.Add(vAddrOk, pfrom.addr, 2 * 60 * 60);
if (vAddr.size() < 1000)
pfrom.fGetAddr = false;
if (pfrom.IsAddrFetchConn())
if (pfrom.IsAddrFetchConn()) {
LogPrint(BCLog::NET_NETCONN, "addrfetch connection completed peer=%d; disconnecting\n", pfrom.GetId());
pfrom.fDisconnect = true;
}
return;
}
@ -4319,6 +4328,7 @@ void PeerManagerImpl::ProcessMessage(
if (msg_type == NetMsgType::FILTERLOAD) {
if (!(pfrom.GetLocalServices() & NODE_BLOOM)) {
LogPrint(BCLog::NET_NETCONN, "filterload received despite not offering bloom services from peer=%d; disconnecting\n", pfrom.GetId());
pfrom.fDisconnect = true;
return;
}
@ -4341,6 +4351,7 @@ void PeerManagerImpl::ProcessMessage(
if (msg_type == NetMsgType::FILTERADD) {
if (!(pfrom.GetLocalServices() & NODE_BLOOM)) {
LogPrint(BCLog::NET_NETCONN, "filteradd received despite not offering bloom services from peer=%d; disconnecting\n", pfrom.GetId());
pfrom.fDisconnect = true;
return;
}
@ -4368,6 +4379,7 @@ void PeerManagerImpl::ProcessMessage(
if (msg_type == NetMsgType::FILTERCLEAR) {
if (!(pfrom.GetLocalServices() & NODE_BLOOM)) {
LogPrint(BCLog::NET_NETCONN, "filterclear received despite not offering bloom services from peer=%d; disconnecting\n", pfrom.GetId());
pfrom.fDisconnect = true;
return;
}

View File

@ -72,9 +72,9 @@ class TimeoutsTest(BitcoinTestFramework):
no_version_node.send_message(msg_ping())
expected_timeout_logs = [
"version handshake timeout from 0",
"socket no message in first 3 seconds, 1 0 from 1",
"socket no message in first 3 seconds, 0 0 from 2",
"version handshake timeout peer=0",
"socket no message in first 3 seconds, 1 0 peer=1",
"socket no message in first 3 seconds, 0 0 peer=2",
]
with self.nodes[0].assert_debug_log(expected_msgs=expected_timeout_logs):