From 0c4954ac7d9676774434e5779bb5fd88e789bbb6 Mon Sep 17 00:00:00 2001 From: Hodlinator <172445034+hodlinator@users.noreply.github.com> Date: Mon, 30 Dec 2024 17:53:47 +0100 Subject: [PATCH 1/4] net_processing: Add missing use of DisconnectMsg Makes it easier to grep logs for "disconnecting" when investigating disconnections. --- src/net_processing.cpp | 4 ++-- test/functional/p2p_blocksonly.py | 2 +- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/src/net_processing.cpp b/src/net_processing.cpp index a19443c0f56..f45042eb77a 100644 --- a/src/net_processing.cpp +++ b/src/net_processing.cpp @@ -4205,7 +4205,7 @@ void PeerManagerImpl::ProcessMessage(CNode& pfrom, const std::string& msg_type, if (msg_type == NetMsgType::TX) { if (RejectIncomingTxs(pfrom)) { - LogDebug(BCLog::NET, "transaction sent in violation of protocol peer=%d\n", pfrom.GetId()); + LogDebug(BCLog::NET, "transaction sent in violation of protocol, %s", pfrom.DisconnectMsg(fLogIPs)); pfrom.fDisconnect = true; return; } @@ -5207,7 +5207,7 @@ void PeerManagerImpl::MaybeSendPing(CNode& node_to, Peer& peer, std::chrono::mic { // The ping timeout is using mocktime. To disable the check during // testing, increase -peertimeout. - LogDebug(BCLog::NET, "ping timeout: %fs peer=%d\n", 0.000001 * count_microseconds(now - peer.m_ping_start.load()), peer.m_id); + LogDebug(BCLog::NET, "ping timeout: %fs, %s", 0.000001 * count_microseconds(now - peer.m_ping_start.load()), node_to.DisconnectMsg(fLogIPs)); node_to.fDisconnect = true; return; } diff --git a/test/functional/p2p_blocksonly.py b/test/functional/p2p_blocksonly.py index b9e6dc90563..6737cc687ea 100755 --- a/test/functional/p2p_blocksonly.py +++ b/test/functional/p2p_blocksonly.py @@ -115,7 +115,7 @@ class P2PBlocksOnly(BitcoinTestFramework): self.log.info('Check that txs from P2P are rejected and result in disconnect') spendtx = self.miniwallet.create_self_transfer() - with self.nodes[0].assert_debug_log(['transaction sent in violation of protocol peer=0']): + with self.nodes[0].assert_debug_log(['transaction sent in violation of protocol, disconnecting peer=0']): self.nodes[0].p2ps[0].send_message(msg_tx(spendtx['tx'])) self.nodes[0].p2ps[0].wait_for_disconnect() assert_equal(self.nodes[0].getmempoolinfo()['size'], 0) From 04b848e4827f502d0784c5975bc8e652fc459cc8 Mon Sep 17 00:00:00 2001 From: Hodlinator <172445034+hodlinator@users.noreply.github.com> Date: Mon, 30 Dec 2024 17:34:42 +0100 Subject: [PATCH 2/4] net: Specify context in disconnecting log message --- src/net.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/net.cpp b/src/net.cpp index 8ea7f6ce445..18ebf8b6c84 100644 --- a/src/net.cpp +++ b/src/net.cpp @@ -3443,7 +3443,7 @@ void CConnman::StopNodes() std::vector<CNode*> nodes; WITH_LOCK(m_nodes_mutex, nodes.swap(m_nodes)); for (CNode* pnode : nodes) { - LogDebug(BCLog::NET, "%s\n", pnode->DisconnectMsg(fLogIPs)); + LogDebug(BCLog::NET, "Stopping node, %s", pnode->DisconnectMsg(fLogIPs)); pnode->CloseSocketDisconnect(); DeleteNode(pnode); } From bbac17608d1ad3f8af5b32efad5d573c70989361 Mon Sep 17 00:00:00 2001 From: Hodlinator <172445034+hodlinator@users.noreply.github.com> Date: Mon, 30 Dec 2024 17:35:53 +0100 Subject: [PATCH 3/4] net: Bring back log message when resetting socket Useful in case new disconnects creep in which are not using DisconnectMsg(). --- src/net.cpp | 1 + 1 file changed, 1 insertion(+) diff --git a/src/net.cpp b/src/net.cpp index 18ebf8b6c84..b68f5813764 100644 --- a/src/net.cpp +++ b/src/net.cpp @@ -558,6 +558,7 @@ void CNode::CloseSocketDisconnect() fDisconnect = true; LOCK(m_sock_mutex); if (m_sock) { + LogDebug(BCLog::NET, "Resetting socket for peer=%d%s", GetId(), LogIP(fLogIPs)); m_sock.reset(); } m_i2p_sam_session.reset(); From 551a09486c495e1a3cfc296eafdf95e914856bff Mon Sep 17 00:00:00 2001 From: Hodlinator <172445034+hodlinator@users.noreply.github.com> Date: Mon, 30 Dec 2024 17:36:45 +0100 Subject: [PATCH 4/4] net: Switch to DisconnectMsg in CConnman --- src/net.cpp | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/src/net.cpp b/src/net.cpp index b68f5813764..8e43ff59d99 100644 --- a/src/net.cpp +++ b/src/net.cpp @@ -1707,7 +1707,7 @@ bool CConnman::AttemptToEvictConnection() LOCK(m_nodes_mutex); for (CNode* pnode : m_nodes) { if (pnode->GetId() == *node_id_to_evict) { - LogDebug(BCLog::NET, "selected %s connection for eviction peer=%d; disconnecting\n", pnode->ConnectionTypeAsString(), pnode->GetId()); + LogDebug(BCLog::NET, "selected %s connection for eviction, %s", pnode->ConnectionTypeAsString(), pnode->DisconnectMsg(fLogIPs)); pnode->fDisconnect = true; return true; } @@ -3608,7 +3608,7 @@ bool CConnman::DisconnectNode(const std::string& strNode) { LOCK(m_nodes_mutex); if (CNode* pnode = FindNode(strNode)) { - LogDebug(BCLog::NET, "disconnect by address%s matched peer=%d; disconnecting\n", (fLogIPs ? strprintf("=%s", strNode) : ""), pnode->GetId()); + LogDebug(BCLog::NET, "disconnect by address%s match, %s", (fLogIPs ? strprintf("=%s", strNode) : ""), pnode->DisconnectMsg(fLogIPs)); pnode->fDisconnect = true; return true; } @@ -3621,7 +3621,7 @@ bool CConnman::DisconnectNode(const CSubNet& subnet) LOCK(m_nodes_mutex); for (CNode* pnode : m_nodes) { if (subnet.Match(pnode->addr)) { - LogDebug(BCLog::NET, "disconnect by subnet%s matched peer=%d; disconnecting\n", (fLogIPs ? strprintf("=%s", subnet.ToString()) : ""), pnode->GetId()); + LogDebug(BCLog::NET, "disconnect by subnet%s match, %s", (fLogIPs ? strprintf("=%s", subnet.ToString()) : ""), pnode->DisconnectMsg(fLogIPs)); pnode->fDisconnect = true; disconnected = true; } @@ -3639,7 +3639,7 @@ bool CConnman::DisconnectNode(NodeId id) LOCK(m_nodes_mutex); for(CNode* pnode : m_nodes) { if (id == pnode->GetId()) { - LogDebug(BCLog::NET, "disconnect by id peer=%d; disconnecting\n", pnode->GetId()); + LogDebug(BCLog::NET, "disconnect by id, %s", pnode->DisconnectMsg(fLogIPs)); pnode->fDisconnect = true; return true; }