From fa6d5a238d2c94440105ddd4f1554f85659d6c5b Mon Sep 17 00:00:00 2001 From: MarcoFalke Date: Fri, 22 Oct 2021 11:06:23 +0200 Subject: scripted-diff: Rename m_last_send and m_last_recv -BEGIN VERIFY SCRIPT- ren() { sed -i "s/\<$1\>/$2/g" $(git grep -l "$1" ./src) ; } ren nLastSend m_last_send ren nLastRecv m_last_recv -END VERIFY SCRIPT- --- src/net.cpp | 20 ++++++++++---------- src/net.h | 8 ++++---- src/qt/rpcconsole.cpp | 4 ++-- src/rpc/net.cpp | 4 ++-- 4 files changed, 18 insertions(+), 18 deletions(-) diff --git a/src/net.cpp b/src/net.cpp index 82e55d4189..767b0e1a82 100644 --- a/src/net.cpp +++ b/src/net.cpp @@ -585,8 +585,8 @@ void CNode::CopyStats(CNodeStats& stats) } else { stats.fRelayTxes = false; } - X(nLastSend); - X(nLastRecv); + X(m_last_send); + X(m_last_recv); X(nLastTXTime); X(nLastBlockTime); X(nTimeConnected); @@ -633,7 +633,7 @@ bool CNode::ReceiveMsgBytes(Span msg_bytes, bool& complete) complete = false; const auto time = GetTime(); LOCK(cs_vRecv); - nLastRecv = std::chrono::duration_cast(time).count(); + m_last_recv = std::chrono::duration_cast(time).count(); nRecvBytes += msg_bytes.size(); while (msg_bytes.size() > 0) { // absorb network data @@ -804,7 +804,7 @@ size_t CConnman::SocketSendData(CNode& node) const nBytes = send(node.hSocket, reinterpret_cast(data.data()) + node.nSendOffset, data.size() - node.nSendOffset, MSG_NOSIGNAL | MSG_DONTWAIT); } if (nBytes > 0) { - node.nLastSend = GetTimeSeconds(); + node.m_last_send = GetTimeSeconds(); node.nSendBytes += nBytes; node.nSendOffset += nBytes; nSentSize += nBytes; @@ -1330,18 +1330,18 @@ bool CConnman::InactivityCheck(const CNode& node) const if (!ShouldRunInactivityChecks(node, now)) return false; - if (node.nLastRecv == 0 || node.nLastSend == 0) { - 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()); + if (node.m_last_recv == 0 || node.m_last_send == 0) { + LogPrint(BCLog::NET, "socket no message in first %i seconds, %d %d peer=%d\n", m_peer_connect_timeout, node.m_last_recv != 0, node.m_last_send != 0, node.GetId()); return true; } - if (now > node.nLastSend + TIMEOUT_INTERVAL) { - LogPrint(BCLog::NET, "socket sending timeout: %is peer=%d\n", now - node.nLastSend, node.GetId()); + if (now > node.m_last_send + TIMEOUT_INTERVAL) { + LogPrint(BCLog::NET, "socket sending timeout: %is peer=%d\n", now - node.m_last_send, node.GetId()); return true; } - if (now > node.nLastRecv + TIMEOUT_INTERVAL) { - LogPrint(BCLog::NET, "socket receive timeout: %is peer=%d\n", now - node.nLastRecv, node.GetId()); + if (now > node.m_last_recv + TIMEOUT_INTERVAL) { + LogPrint(BCLog::NET, "socket receive timeout: %is peer=%d\n", now - node.m_last_recv, node.GetId()); return true; } diff --git a/src/net.h b/src/net.h index 878f10cd42..cf1f8f0407 100644 --- a/src/net.h +++ b/src/net.h @@ -241,8 +241,8 @@ public: NodeId nodeid; ServiceFlags nServices; bool fRelayTxes; - int64_t nLastSend; - int64_t nLastRecv; + int64_t m_last_send; + int64_t m_last_recv; int64_t nLastTXTime; int64_t nLastBlockTime; int64_t nTimeConnected; @@ -420,8 +420,8 @@ public: uint64_t nRecvBytes GUARDED_BY(cs_vRecv){0}; - std::atomic nLastSend{0}; - std::atomic nLastRecv{0}; + std::atomic m_last_send{0}; + std::atomic m_last_recv{0}; //! Unix epoch time at peer connection, in seconds. const int64_t nTimeConnected; std::atomic nTimeOffset{0}; diff --git a/src/qt/rpcconsole.cpp b/src/qt/rpcconsole.cpp index 0c3332ab76..5b95c92392 100644 --- a/src/qt/rpcconsole.cpp +++ b/src/qt/rpcconsole.cpp @@ -1172,8 +1172,8 @@ void RPCConsole::updateDetailWidget() ui->peerConnTime->setText(GUIUtil::formatDurationStr(time_now - stats->nodeStats.nTimeConnected)); ui->peerLastBlock->setText(TimeDurationField(time_now, stats->nodeStats.nLastBlockTime)); ui->peerLastTx->setText(TimeDurationField(time_now, stats->nodeStats.nLastTXTime)); - ui->peerLastSend->setText(TimeDurationField(time_now, stats->nodeStats.nLastSend)); - ui->peerLastRecv->setText(TimeDurationField(time_now, stats->nodeStats.nLastRecv)); + ui->peerLastSend->setText(TimeDurationField(time_now, stats->nodeStats.m_last_send)); + ui->peerLastRecv->setText(TimeDurationField(time_now, stats->nodeStats.m_last_recv)); ui->peerBytesSent->setText(GUIUtil::formatBytes(stats->nodeStats.nSendBytes)); ui->peerBytesRecv->setText(GUIUtil::formatBytes(stats->nodeStats.nRecvBytes)); ui->peerPingTime->setText(GUIUtil::formatPingTime(stats->nodeStats.m_last_ping_time)); diff --git a/src/rpc/net.cpp b/src/rpc/net.cpp index e33f1ce4a3..f0082fe60a 100644 --- a/src/rpc/net.cpp +++ b/src/rpc/net.cpp @@ -211,8 +211,8 @@ static RPCHelpMan getpeerinfo() obj.pushKV("services", strprintf("%016x", stats.nServices)); obj.pushKV("servicesnames", GetServicesNames(stats.nServices)); obj.pushKV("relaytxes", stats.fRelayTxes); - obj.pushKV("lastsend", stats.nLastSend); - obj.pushKV("lastrecv", stats.nLastRecv); + obj.pushKV("lastsend", stats.m_last_send); + obj.pushKV("lastrecv", stats.m_last_recv); obj.pushKV("last_transaction", stats.nLastTXTime); obj.pushKV("last_block", stats.nLastBlockTime); obj.pushKV("bytessent", stats.nSendBytes); -- cgit v1.2.3 From fadc0c80ae4e526fb2b503f7cc02f6122aaf1de5 Mon Sep 17 00:00:00 2001 From: MarcoFalke Date: Fri, 10 Jul 2020 18:19:11 +0200 Subject: p2p: Make timeout mockable and type safe, speed up test --- src/net.cpp | 28 +++++++++++++++------------- src/net.h | 16 ++++++++-------- src/net_processing.cpp | 5 +++-- src/qt/guiutil.cpp | 4 +++- src/qt/guiutil.h | 2 +- src/qt/rpcconsole.cpp | 10 +++++----- src/qt/rpcconsole.h | 5 +++-- src/rpc/net.cpp | 4 ++-- src/test/denialofservice_tests.cpp | 2 +- src/test/util/net.h | 2 +- test/functional/p2p_timeouts.py | 30 ++++++++++++++++-------------- test/functional/test_framework/util.py | 8 ++++---- 12 files changed, 62 insertions(+), 54 deletions(-) diff --git a/src/net.cpp b/src/net.cpp index 767b0e1a82..352758fe64 100644 --- a/src/net.cpp +++ b/src/net.cpp @@ -633,7 +633,7 @@ bool CNode::ReceiveMsgBytes(Span msg_bytes, bool& complete) complete = false; const auto time = GetTime(); LOCK(cs_vRecv); - m_last_recv = std::chrono::duration_cast(time).count(); + m_last_recv = std::chrono::duration_cast(time); nRecvBytes += msg_bytes.size(); while (msg_bytes.size() > 0) { // absorb network data @@ -804,7 +804,7 @@ size_t CConnman::SocketSendData(CNode& node) const nBytes = send(node.hSocket, reinterpret_cast(data.data()) + node.nSendOffset, data.size() - node.nSendOffset, MSG_NOSIGNAL | MSG_DONTWAIT); } if (nBytes > 0) { - node.m_last_send = GetTimeSeconds(); + node.m_last_send = GetTime(); node.nSendBytes += nBytes; node.nSendOffset += nBytes; nSentSize += nBytes; @@ -1317,31 +1317,33 @@ void CConnman::NotifyNumConnectionsChanged() } } -bool CConnman::ShouldRunInactivityChecks(const CNode& node, int64_t now) const +bool CConnman::ShouldRunInactivityChecks(const CNode& node, std::chrono::seconds now) const { - return node.nTimeConnected + m_peer_connect_timeout < now; + return std::chrono::seconds{node.nTimeConnected} + m_peer_connect_timeout < now; } bool CConnman::InactivityCheck(const CNode& node) const { - // Use non-mockable system time (otherwise these timers will pop when we - // use setmocktime in the tests). - int64_t now = GetTimeSeconds(); + // Tests that see disconnects after using mocktime can start nodes with a + // large timeout. For example, -peertimeout=999999999. + const auto now{GetTime()}; + const auto last_send{node.m_last_send.load()}; + const auto last_recv{node.m_last_recv.load()}; if (!ShouldRunInactivityChecks(node, now)) return false; - if (node.m_last_recv == 0 || node.m_last_send == 0) { - LogPrint(BCLog::NET, "socket no message in first %i seconds, %d %d peer=%d\n", m_peer_connect_timeout, node.m_last_recv != 0, node.m_last_send != 0, node.GetId()); + if (last_recv.count() == 0 || last_send.count() == 0) { + LogPrint(BCLog::NET, "socket no message in first %i seconds, %d %d peer=%d\n", count_seconds(m_peer_connect_timeout), last_recv.count() != 0, last_send.count() != 0, node.GetId()); return true; } - if (now > node.m_last_send + TIMEOUT_INTERVAL) { - LogPrint(BCLog::NET, "socket sending timeout: %is peer=%d\n", now - node.m_last_send, node.GetId()); + if (now > last_send + TIMEOUT_INTERVAL) { + LogPrint(BCLog::NET, "socket sending timeout: %is peer=%d\n", count_seconds(now - last_send), node.GetId()); return true; } - if (now > node.m_last_recv + TIMEOUT_INTERVAL) { - LogPrint(BCLog::NET, "socket receive timeout: %is peer=%d\n", now - node.m_last_recv, node.GetId()); + if (now > last_recv + TIMEOUT_INTERVAL) { + LogPrint(BCLog::NET, "socket receive timeout: %is peer=%d\n", count_seconds(now - last_recv), node.GetId()); return true; } diff --git a/src/net.h b/src/net.h index cf1f8f0407..e0aee10a61 100644 --- a/src/net.h +++ b/src/net.h @@ -48,7 +48,7 @@ static const bool DEFAULT_WHITELISTRELAY = true; static const bool DEFAULT_WHITELISTFORCERELAY = false; /** Time after which to disconnect, after waiting for a ping response (or inactivity). */ -static const int TIMEOUT_INTERVAL = 20 * 60; +static constexpr std::chrono::minutes TIMEOUT_INTERVAL{20}; /** Run the feeler connection loop once every 2 minutes. **/ static constexpr auto FEELER_INTERVAL = 2min; /** Run the extra block-relay-only connection loop once every 5 minutes. **/ @@ -241,8 +241,8 @@ public: NodeId nodeid; ServiceFlags nServices; bool fRelayTxes; - int64_t m_last_send; - int64_t m_last_recv; + std::chrono::seconds m_last_send; + std::chrono::seconds m_last_recv; int64_t nLastTXTime; int64_t nLastBlockTime; int64_t nTimeConnected; @@ -420,8 +420,8 @@ public: uint64_t nRecvBytes GUARDED_BY(cs_vRecv){0}; - std::atomic m_last_send{0}; - std::atomic m_last_recv{0}; + std::atomic m_last_send{0s}; + std::atomic m_last_recv{0s}; //! Unix epoch time at peer connection, in seconds. const int64_t nTimeConnected; std::atomic nTimeOffset{0}; @@ -784,7 +784,7 @@ public: m_msgproc = connOptions.m_msgproc; nSendBufferMaxSize = connOptions.nSendBufferMaxSize; nReceiveFloodSize = connOptions.nReceiveFloodSize; - m_peer_connect_timeout = connOptions.m_peer_connect_timeout; + m_peer_connect_timeout = std::chrono::seconds{connOptions.m_peer_connect_timeout}; { LOCK(cs_totalBytesSent); nMaxOutboundLimit = connOptions.nMaxOutboundLimit; @@ -942,7 +942,7 @@ public: std::chrono::microseconds PoissonNextSendInbound(std::chrono::microseconds now, std::chrono::seconds average_interval); /** Return true if we should disconnect the peer for failing an inactivity check. */ - bool ShouldRunInactivityChecks(const CNode& node, int64_t secs_now) const; + bool ShouldRunInactivityChecks(const CNode& node, std::chrono::seconds now) const; private: struct ListenSocket { @@ -1037,7 +1037,7 @@ private: uint64_t nMaxOutboundLimit GUARDED_BY(cs_totalBytesSent); // P2P timeout in seconds - int64_t m_peer_connect_timeout; + std::chrono::seconds m_peer_connect_timeout; // Whitelisted ranges. Any node connecting from these is automatically // whitelisted (as well as those connecting to whitelisted binds). diff --git a/src/net_processing.cpp b/src/net_processing.cpp index 2185ccc700..2608307c6e 100644 --- a/src/net_processing.cpp +++ b/src/net_processing.cpp @@ -4312,9 +4312,10 @@ void PeerManagerImpl::CheckForStaleTipAndEvictPeers() void PeerManagerImpl::MaybeSendPing(CNode& node_to, Peer& peer, std::chrono::microseconds now) { - if (m_connman.ShouldRunInactivityChecks(node_to, std::chrono::duration_cast(now).count()) && + if (m_connman.ShouldRunInactivityChecks(node_to, std::chrono::duration_cast(now)) && peer.m_ping_nonce_sent && - now > peer.m_ping_start.load() + std::chrono::seconds{TIMEOUT_INTERVAL}) { + now > peer.m_ping_start.load() + TIMEOUT_INTERVAL) + { // The ping timeout is using mocktime. To disable the check during // testing, increase -peertimeout. LogPrint(BCLog::NET, "ping timeout: %fs peer=%d\n", 0.000001 * count_microseconds(now - peer.m_ping_start.load()), peer.m_id); diff --git a/src/qt/guiutil.cpp b/src/qt/guiutil.cpp index 4262866f32..35e4ab4ecd 100644 --- a/src/qt/guiutil.cpp +++ b/src/qt/guiutil.cpp @@ -20,6 +20,7 @@ #include