net: Disconnect message follow-ups to #28521

hodlinator commented at 10:43 am on January 10, 2025: contributor

Add missing calls to DisconnectMsg() - #28521 (review)
Specify context when stopping nodes - #28521 (review)
Bring back log message when resetting socket in case new entrypoints are added - #28521 (review)
Use DisconnectMsg() in CConnman as well - #28521 (review)

net_processing: Add missing use of DisconnectMsg

Makes it easier to grep logs for "disconnecting" when investigating disconnections.

0c4954ac7d

net: Specify context in disconnecting log message 04b848e482

net: Bring back log message when resetting socket

Useful in case new disconnects creep in which are not using DisconnectMsg().

bbac17608d

net: Switch to DisconnectMsg in CConnman 286de97496

DrahtBot commented at 10:43 am on January 10, 2025: contributor

The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.

Code Coverage & Benchmarks

For details see: https://corecheck.dev/bitcoin/bitcoin/pulls/31633.

Reviews

See the guideline for information on the review process.

Type	Reviewers
ACK	maflcko, l0rinc, Sjors

If your review is incorrectly listed, please react with 👎 to this comment and the bot will ignore it on the next update.

Conflicts

Reviewers, this pull request conflicts with the following ones:

#30988 (Split CConnman by vasild)

If you consider this pull request important, please also help to review the conflicting pull requests. Ideally, start with the one that should be merged first.

DrahtBot added the label P2P on Jan 10, 2025

maflcko commented at 11:06 am on January 10, 2025: member

review ACK 286de9749612565fd8d42f08f66c8426faf8a1f7 📋

Signature:

0untrusted comment: signature from minisign secret key on empty file; verify via: minisign -Vm "${path_to_any_empty_file}" -P RWTRmVTMeKV5noAMqVlsMugDDCyyTSbA3Re5AkUrhvLVln0tSaFWglOw -x "${path_to_this_whole_four_line_signature_blob}"
1RUTRmVTMeKV5npGrKx1nqXCw5zeVHdtdYURB/KlyA/LMFgpNCs+SkW9a8N95d+U4AP1RJMi+krxU1A3Yux4bpwZNLvVBKy0wLgM=
2trusted comment: review ACK 286de9749612565fd8d42f08f66c8426faf8a1f7 📋
3KIc3ZvWyWMcblu8xFcmTzLk/937/Mbtwhz9zc6/xQx5LWmvhMIpVwAXU2Z+0Lh0UfNs09bOeyVM3/HZtxfNODA==

in src/net.cpp:561 in 286de97496

557@@ -558,6 +558,7 @@ void CNode::CloseSocketDisconnect()
558     fDisconnect = true;
559     LOCK(m_sock_mutex);
560     if (m_sock) {
561+        LogDebug(BCLog::NET, "Resetting socket for peer=%d%s", GetId(), LogIP(fLogIPs));

l0rinc commented at 11:14 am on January 10, 2025:

I found the %d%s format weird at first, but I see it is an existing format, e.g. https://github.com/bitcoin/bitcoin/blob/master/src/net.cpp#L705

Sjors commented at 12:44 pm on January 14, 2025:

This does make the debug level even noisier. But since it doesn’t have the word “disconnect” it’s probably fine.

hodlinator commented at 3:19 pm on January 14, 2025:

What do you think about downgrading it to LogTrace?

in src/net.cpp:3611 in 286de97496

3607@@ -3607,7 +3608,7 @@ bool CConnman::DisconnectNode(const std::string& strNode)
3608 {
3609     LOCK(m_nodes_mutex);
3610     if (CNode* pnode = FindNode(strNode)) {
3611-        LogDebug(BCLog::NET, "disconnect by address%s matched peer=%d; disconnecting\n", (fLogIPs ? strprintf("=%s", strNode) : ""), pnode->GetId());
3612+        LogDebug(BCLog::NET, "disconnect by address%s match; %s", (fLogIPs ? strprintf("=%s", strNode) : ""), pnode->DisconnectMsg(fLogIPs));

l0rinc commented at 11:16 am on January 10, 2025:

super-nit: above we’re using a simple , before the DisconnectMsg, not a ;.

hodlinator commented at 3:20 pm on January 14, 2025:

Agree, will change if I re-touch.

in src/net.cpp:3624 in 286de97496

3620@@ -3620,7 +3621,7 @@ bool CConnman::DisconnectNode(const CSubNet& subnet)
3621     LOCK(m_nodes_mutex);
3622     for (CNode* pnode : m_nodes) {
3623         if (subnet.Match(pnode->addr)) {
3624-            LogDebug(BCLog::NET, "disconnect by subnet%s matched peer=%d; disconnecting\n", (fLogIPs ? strprintf("=%s", subnet.ToString()) : ""), pnode->GetId());
3625+            LogDebug(BCLog::NET, "disconnect by subnet%s match; %s", (fLogIPs ? strprintf("=%s", subnet.ToString()) : ""), pnode->DisconnectMsg(fLogIPs));

l0rinc commented at 11:17 am on January 10, 2025:

nit: many other similar logs here were capitalized

hodlinator commented at 3:28 pm on January 14, 2025:

I feel a slight itch here as well, but will probably leave casing as-is as in keeping with the original pull request.

in src/net_processing.cpp:5210 in 286de97496

5206@@ -5207,7 +5207,7 @@ void PeerManagerImpl::MaybeSendPing(CNode& node_to, Peer& peer, std::chrono::mic
5207     {
5208         // The ping timeout is using mocktime. To disable the check during
5209         // testing, increase -peertimeout.
5210-        LogDebug(BCLog::NET, "ping timeout: %fs peer=%d\n", 0.000001 * count_microseconds(now - peer.m_ping_start.load()), peer.m_id);
5211+        LogDebug(BCLog::NET, "ping timeout: %fs, %s", 0.000001 * count_microseconds(now - peer.m_ping_start.load()), node_to.DisconnectMsg(fLogIPs));

l0rinc commented at 11:30 am on January 10, 2025:

unrelated: do we really need this level of detail for a timeout (i.e. ms precision expressed in seconds)?

hodlinator commented at 3:24 pm on January 14, 2025:

ping on my main system seems to care about ms+3 decimals (I’m guessing that’s milliseconds+3 decimals => microseconds):

0₿ ping 192.168.1.133
1PING 192.168.1.133 (192.168.1.133): 56 data bytes
264 bytes from 192.168.1.133: icmp_seq=0 ttl=214 time=0.765 ms

l0rinc approved

l0rinc commented at 11:30 am on January 10, 2025: contributor

utACK 286de9749612565fd8d42f08f66c8426faf8a1f7

Sjors commented at 12:47 pm on January 14, 2025: member

utACK 286de9749612565fd8d42f08f66c8426faf8a1f7

net: Disconnect message follow-ups to #28521 #31633

Code Coverage & Benchmarks

Reviews

Conflicts