diff options
-rw-r--r-- | src/net.cpp | 32 | ||||
-rw-r--r-- | src/net.h | 16 | ||||
-rw-r--r-- | src/net_processing.cpp | 5 | ||||
-rw-r--r-- | src/qt/guiutil.cpp | 4 | ||||
-rw-r--r-- | src/qt/guiutil.h | 2 | ||||
-rw-r--r-- | src/qt/rpcconsole.cpp | 14 | ||||
-rw-r--r-- | src/qt/rpcconsole.h | 5 | ||||
-rw-r--r-- | src/rpc/net.cpp | 4 | ||||
-rw-r--r-- | src/test/denialofservice_tests.cpp | 2 | ||||
-rw-r--r-- | src/test/util/net.h | 2 | ||||
-rwxr-xr-x | test/functional/p2p_timeouts.py | 30 | ||||
-rw-r--r-- | test/functional/test_framework/util.py | 8 |
12 files changed, 66 insertions, 58 deletions
diff --git a/src/net.cpp b/src/net.cpp index 2d9e69b6fb..2adccce11e 100644 --- a/src/net.cpp +++ b/src/net.cpp @@ -586,8 +586,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); @@ -634,7 +634,7 @@ bool CNode::ReceiveMsgBytes(Span<const uint8_t> msg_bytes, bool& complete) complete = false; const auto time = GetTime<std::chrono::microseconds>(); LOCK(cs_vRecv); - nLastRecv = std::chrono::duration_cast<std::chrono::seconds>(time).count(); + m_last_recv = std::chrono::duration_cast<std::chrono::seconds>(time); nRecvBytes += msg_bytes.size(); while (msg_bytes.size() > 0) { // absorb network data @@ -805,7 +805,7 @@ size_t CConnman::SocketSendData(CNode& node) const nBytes = send(node.hSocket, reinterpret_cast<const char*>(data.data()) + node.nSendOffset, data.size() - node.nSendOffset, MSG_NOSIGNAL | MSG_DONTWAIT); } if (nBytes > 0) { - node.nLastSend = GetTimeSeconds(); + node.m_last_send = GetTime<std::chrono::seconds>(); node.nSendBytes += nBytes; node.nSendOffset += nBytes; nSentSize += nBytes; @@ -1318,31 +1318,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<std::chrono::seconds>()}; + 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.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 (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.nLastSend + TIMEOUT_INTERVAL) { - LogPrint(BCLog::NET, "socket sending timeout: %is peer=%d\n", now - node.nLastSend, 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.nLastRecv + TIMEOUT_INTERVAL) { - LogPrint(BCLog::NET, "socket receive timeout: %is peer=%d\n", now - node.nLastRecv, 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; } @@ -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 nLastSend; - int64_t nLastRecv; + 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<int64_t> nLastSend{0}; - std::atomic<int64_t> nLastRecv{0}; + std::atomic<std::chrono::seconds> m_last_send{0s}; + std::atomic<std::chrono::seconds> m_last_recv{0s}; //! Unix epoch time at peer connection, in seconds. const int64_t nTimeConnected; std::atomic<int64_t> 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 { @@ -1084,7 +1084,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 e4b8e9b6a9..809fb8efde 100644 --- a/src/net_processing.cpp +++ b/src/net_processing.cpp @@ -4357,9 +4357,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<std::chrono::seconds>(now).count()) && + if (m_connman.ShouldRunInactivityChecks(node_to, std::chrono::duration_cast<std::chrono::seconds>(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 <script/script.h> #include <script/standard.h> #include <util/system.h> +#include <util/time.h> #ifdef WIN32 #ifndef NOMINMAX @@ -705,8 +706,9 @@ QString ConnectionTypeToQString(ConnectionType conn_type, bool prepend_direction assert(false); } -QString formatDurationStr(int secs) +QString formatDurationStr(std::chrono::seconds dur) { + const auto secs = count_seconds(dur); QStringList strList; int days = secs / 86400; int hours = (secs % 86400) / 3600; diff --git a/src/qt/guiutil.h b/src/qt/guiutil.h index 364962ee9a..fb0dbba88b 100644 --- a/src/qt/guiutil.h +++ b/src/qt/guiutil.h @@ -221,7 +221,7 @@ namespace GUIUtil QString ConnectionTypeToQString(ConnectionType conn_type, bool prepend_direction); /** Convert seconds into a QString with days, hours, mins, secs */ - QString formatDurationStr(int secs); + QString formatDurationStr(std::chrono::seconds dur); /** Format CNodeStats.nServices bitmask into a user-readable string */ QString formatServicesStr(quint64 mask); diff --git a/src/qt/rpcconsole.cpp b/src/qt/rpcconsole.cpp index 1c19fb4b27..5d08aff6b9 100644 --- a/src/qt/rpcconsole.cpp +++ b/src/qt/rpcconsole.cpp @@ -1141,7 +1141,7 @@ void RPCConsole::on_sldGraphRange_valueChanged(int value) void RPCConsole::setTrafficGraphRange(int mins) { ui->trafficGraph->setGraphRangeMins(mins); - ui->lblGraphRange->setText(GUIUtil::formatDurationStr(mins * 60)); + ui->lblGraphRange->setText(GUIUtil::formatDurationStr(std::chrono::minutes{mins})); } void RPCConsole::updateTrafficStats(quint64 totalBytesIn, quint64 totalBytesOut) @@ -1172,12 +1172,12 @@ void RPCConsole::updateDetailWidget() if (stats->nodeStats.m_bip152_highbandwidth_from) bip152_hb_settings += (bip152_hb_settings.isEmpty() ? ts.from : QLatin1Char('/') + ts.from); if (bip152_hb_settings.isEmpty()) bip152_hb_settings = ts.no; ui->peerHighBandwidth->setText(bip152_hb_settings); - const int64_t time_now{GetTimeSeconds()}; - 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)); + const auto time_now{GetTime<std::chrono::seconds>()}; + ui->peerConnTime->setText(GUIUtil::formatDurationStr(time_now - std::chrono::seconds{stats->nodeStats.nTimeConnected})); + ui->peerLastBlock->setText(TimeDurationField(time_now, std::chrono::seconds{stats->nodeStats.nLastBlockTime})); + ui->peerLastTx->setText(TimeDurationField(time_now, std::chrono::seconds{stats->nodeStats.nLastTXTime})); + 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/qt/rpcconsole.h b/src/qt/rpcconsole.h index 2412ae543c..fc6e85b41a 100644 --- a/src/qt/rpcconsole.h +++ b/src/qt/rpcconsole.h @@ -175,8 +175,9 @@ private: void updateNetworkState(); /** Helper for the output of a time duration field. Inputs are UNIX epoch times. */ - QString TimeDurationField(uint64_t time_now, uint64_t time_at_event) const { - return time_at_event ? GUIUtil::formatDurationStr(time_now - time_at_event) : tr("Never"); + QString TimeDurationField(std::chrono::seconds time_now, std::chrono::seconds time_at_event) const + { + return time_at_event.count() ? GUIUtil::formatDurationStr(time_now - time_at_event) : tr("Never"); } private Q_SLOTS: diff --git a/src/rpc/net.cpp b/src/rpc/net.cpp index 4db8a00180..756f6860f6 100644 --- a/src/rpc/net.cpp +++ b/src/rpc/net.cpp @@ -196,8 +196,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", count_seconds(stats.m_last_send)); + obj.pushKV("lastrecv", count_seconds(stats.m_last_recv)); obj.pushKV("last_transaction", stats.nLastTXTime); obj.pushKV("last_block", stats.nLastBlockTime); obj.pushKV("bytessent", stats.nSendBytes); diff --git a/src/test/denialofservice_tests.cpp b/src/test/denialofservice_tests.cpp index ef18ed1385..f1abd5183a 100644 --- a/src/test/denialofservice_tests.cpp +++ b/src/test/denialofservice_tests.cpp @@ -53,7 +53,7 @@ BOOST_AUTO_TEST_CASE(outbound_slow_chain_eviction) const CChainParams& chainparams = Params(); auto connman = std::make_unique<CConnman>(0x1337, 0x1337, *m_node.addrman); // Disable inactivity checks for this test to avoid interference - static_cast<ConnmanTestMsg*>(connman.get())->SetPeerConnectTimeout(99999); + static_cast<ConnmanTestMsg*>(connman.get())->SetPeerConnectTimeout(99999s); auto peerLogic = PeerManager::make(chainparams, *connman, *m_node.addrman, nullptr, *m_node.chainman, *m_node.mempool, false); diff --git a/src/test/util/net.h b/src/test/util/net.h index 2de6e712a2..ad1061a451 100644 --- a/src/test/util/net.h +++ b/src/test/util/net.h @@ -18,7 +18,7 @@ struct ConnmanTestMsg : public CConnman { using CConnman::CConnman; - void SetPeerConnectTimeout(int64_t timeout) + void SetPeerConnectTimeout(std::chrono::seconds timeout) { m_peer_connect_timeout = timeout; } diff --git a/test/functional/p2p_timeouts.py b/test/functional/p2p_timeouts.py index a7e240dcfa..cf714bc888 100755 --- a/test/functional/p2p_timeouts.py +++ b/test/functional/p2p_timeouts.py @@ -4,13 +4,12 @@ # file COPYING or http://www.opensource.org/licenses/mit-license.php. """Test various net timeouts. -- Create three bitcoind nodes: +- Create three peers: no_verack_node - we never send a verack in response to their version no_version_node - we never send a version (only a ping) no_send_node - we never send any P2P message. -- Start all three nodes - Wait 1 second - Assert that we're connected - Send a ping to no_verack_node and no_version_node @@ -21,12 +20,12 @@ - Assert that we're no longer connected (timeout to receive version/verack is 3 seconds) """ -from time import sleep - from test_framework.messages import msg_ping from test_framework.p2p import P2PInterface from test_framework.test_framework import BitcoinTestFramework +import time + class TestP2PConn(P2PInterface): def on_version(self, message): @@ -41,7 +40,14 @@ class TimeoutsTest(BitcoinTestFramework): # set timeout to receive version/verack to 3 seconds self.extra_args = [["-peertimeout=3"]] + def mock_forward(self, delta): + self.mock_time += delta + self.nodes[0].setmocktime(self.mock_time) + def run_test(self): + self.mock_time = int(time.time()) + self.mock_forward(0) + # Setup the p2p connections no_verack_node = self.nodes[0].add_p2p_connection(TestP2PConn(), wait_for_verack=False) no_version_node = self.nodes[0].add_p2p_connection(TestP2PConn(), send_version=False, wait_for_verack=False) @@ -51,7 +57,7 @@ class TimeoutsTest(BitcoinTestFramework): # verack, since we never sent one no_verack_node.wait_for_verack() - sleep(1) + self.mock_forward(1) assert no_verack_node.is_connected assert no_version_node.is_connected @@ -62,7 +68,7 @@ class TimeoutsTest(BitcoinTestFramework): with self.nodes[0].assert_debug_log(['non-version message before version handshake. Message "ping" from peer=1']): no_version_node.send_message(msg_ping()) - sleep(1) + self.mock_forward(1) assert "version" in no_verack_node.last_message @@ -80,14 +86,10 @@ class TimeoutsTest(BitcoinTestFramework): ] with self.nodes[0].assert_debug_log(expected_msgs=expected_timeout_logs): - sleep(3) - # By now, we waited a total of 5 seconds. Off-by-two for two - # reasons: - # * The internal precision is one second - # * Account for network delay - assert not no_verack_node.is_connected - assert not no_version_node.is_connected - assert not no_send_node.is_connected + self.mock_forward(2) + no_verack_node.wait_for_disconnect(timeout=1) + no_version_node.wait_for_disconnect(timeout=1) + no_send_node.wait_for_disconnect(timeout=1) if __name__ == '__main__': diff --git a/test/functional/test_framework/util.py b/test/functional/test_framework/util.py index c3a9029d55..195af14914 100644 --- a/test/functional/test_framework/util.py +++ b/test/functional/test_framework/util.py @@ -379,10 +379,10 @@ def write_config(config_path, *, n, chain, extra_config="", disable_autoconnect= f.write("fixedseeds=0\n") f.write("listenonion=0\n") # Increase peertimeout to avoid disconnects while using mocktime. - # peertimeout is measured in wall clock time, so setting it to the - # duration of the longest test is sufficient. It can be overridden in - # tests. - f.write("peertimeout=999999\n") + # peertimeout is measured in mock time, so setting it large enough to + # cover any duration in mock time is sufficient. It can be overridden + # in tests. + f.write("peertimeout=999999999\n") f.write("printtoconsole=0\n") f.write("upnp=0\n") f.write("natpmp=0\n") |