From ec3916f40a3fc644ecbbaaddef6258937c7fcfbc Mon Sep 17 00:00:00 2001 From: Pieter Wuille Date: Sun, 27 Sep 2020 14:43:27 -0700 Subject: [PATCH] Use mockable time everywhere in net_processing --- src/net_processing.cpp | 37 ++++++++----------- test/functional/p2p_tx_download.py | 30 +++++++-------- .../wallet_resendwallettransactions.py | 4 ++ 3 files changed, 33 insertions(+), 38 deletions(-) diff --git a/src/net_processing.cpp b/src/net_processing.cpp index 41fe1e02983..631981217bb 100644 --- a/src/net_processing.cpp +++ b/src/net_processing.cpp @@ -582,7 +582,7 @@ static bool MarkBlockAsReceived(const uint256& hash) EXCLUSIVE_LOCKS_REQUIRED(cs } if (state->vBlocksInFlight.begin() == itInFlight->second.second) { // First block on the queue was received, update the start download time for the next one - state->nDownloadingSince = std::max(state->nDownloadingSince, GetTimeMicros()); + state->nDownloadingSince = std::max(state->nDownloadingSince, count_microseconds(GetTime())); } state->vBlocksInFlight.erase(itInFlight->second.second); state->nBlocksInFlight--; @@ -617,7 +617,7 @@ static bool MarkBlockAsInFlight(CTxMemPool& mempool, NodeId nodeid, const uint25 state->nBlocksInFlightValidHeaders += it->fValidatedHeaders; if (state->nBlocksInFlight == 1) { // We're starting a block download (batch) from this peer. - state->nDownloadingSince = GetTimeMicros(); + state->nDownloadingSince = GetTime().count(); } if (state->nBlocksInFlightValidHeaders == 1 && pindex != nullptr) { nPeersWithValidatedDownloads++; @@ -4102,7 +4102,6 @@ bool PeerManager::SendMessages(CNode* pto) CNodeState &state = *State(pto->GetId()); // Address refresh broadcast - int64_t nNow = GetTimeMicros(); auto current_time = GetTime(); if (pto->RelayAddrsWithConn() && !::ChainstateActive().IsInitialBlockDownload() && pto->m_next_local_addr_send < current_time) { @@ -4148,7 +4147,7 @@ bool PeerManager::SendMessages(CNode* pto) // Only actively request headers from a single peer, unless we're close to today. if ((nSyncStarted == 0 && fFetch) || pindexBestHeader->GetBlockTime() > GetAdjustedTime() - 24 * 60 * 60) { state.fSyncStarted = true; - state.nHeadersSyncTimeout = GetTimeMicros() + HEADERS_DOWNLOAD_TIMEOUT_BASE + HEADERS_DOWNLOAD_TIMEOUT_PER_HEADER * (GetAdjustedTime() - pindexBestHeader->GetBlockTime())/(consensusParams.nPowTargetSpacing); + state.nHeadersSyncTimeout = count_microseconds(current_time) + HEADERS_DOWNLOAD_TIMEOUT_BASE + HEADERS_DOWNLOAD_TIMEOUT_PER_HEADER * (GetAdjustedTime() - pindexBestHeader->GetBlockTime())/(consensusParams.nPowTargetSpacing); nSyncStarted++; const CBlockIndex *pindexStart = pindexBestHeader; /* If possible, start at the block preceding the currently @@ -4329,7 +4328,7 @@ bool PeerManager::SendMessages(CNode* pto) if (pto->m_tx_relay->nNextInvSend < current_time) { fSendTrickle = true; if (pto->IsInboundConn()) { - pto->m_tx_relay->nNextInvSend = std::chrono::microseconds{m_connman.PoissonNextSendInbound(nNow, INVENTORY_BROADCAST_INTERVAL)}; + pto->m_tx_relay->nNextInvSend = std::chrono::microseconds{m_connman.PoissonNextSendInbound(count_microseconds(current_time), INVENTORY_BROADCAST_INTERVAL)}; } else { // Use half the delay for outbound peers, as there is less privacy concern for them. pto->m_tx_relay->nNextInvSend = PoissonNextSend(current_time, std::chrono::seconds{INVENTORY_BROADCAST_INTERVAL >> 1}); @@ -4428,7 +4427,7 @@ bool PeerManager::SendMessages(CNode* pto) nRelayedTransactions++; { // Expire old relay messages - while (!vRelayExpiration.empty() && vRelayExpiration.front().first < nNow) + while (!vRelayExpiration.empty() && vRelayExpiration.front().first < count_microseconds(current_time)) { mapRelay.erase(vRelayExpiration.front().second); vRelayExpiration.pop_front(); @@ -4436,12 +4435,12 @@ bool PeerManager::SendMessages(CNode* pto) auto ret = mapRelay.emplace(txid, std::move(txinfo.tx)); if (ret.second) { - vRelayExpiration.emplace_back(nNow + std::chrono::microseconds{RELAY_TX_CACHE_TIME}.count(), ret.first); + vRelayExpiration.emplace_back(count_microseconds(current_time + std::chrono::microseconds{RELAY_TX_CACHE_TIME}), ret.first); } // Add wtxid-based lookup into mapRelay as well, so that peers can request by wtxid auto ret2 = mapRelay.emplace(wtxid, ret.first->second); if (ret2.second) { - vRelayExpiration.emplace_back(nNow + std::chrono::microseconds{RELAY_TX_CACHE_TIME}.count(), ret2.first); + vRelayExpiration.emplace_back(count_microseconds(current_time + std::chrono::microseconds{RELAY_TX_CACHE_TIME}), ret2.first); } } if (vInv.size() == MAX_INV_SZ) { @@ -4466,10 +4465,7 @@ bool PeerManager::SendMessages(CNode* pto) // Detect whether we're stalling current_time = GetTime(); - // nNow is the current system time (GetTimeMicros is not mockable) and - // should be replaced by the mockable current_time eventually - nNow = GetTimeMicros(); - if (state.nStallingSince && state.nStallingSince < nNow - 1000000 * BLOCK_STALLING_TIMEOUT) { + if (state.nStallingSince && state.nStallingSince < count_microseconds(current_time) - 1000000 * BLOCK_STALLING_TIMEOUT) { // Stalling only triggers when the block download window cannot move. During normal steady state, // the download window should be much larger than the to-be-downloaded set of blocks, so disconnection // should only happen during initial block download. @@ -4485,7 +4481,7 @@ bool PeerManager::SendMessages(CNode* pto) if (state.vBlocksInFlight.size() > 0) { QueuedBlock &queuedBlock = state.vBlocksInFlight.front(); int nOtherPeersWithValidatedDownloads = nPeersWithValidatedDownloads - (state.nBlocksInFlightValidHeaders > 0); - if (nNow > state.nDownloadingSince + consensusParams.nPowTargetSpacing * (BLOCK_DOWNLOAD_TIMEOUT_BASE + BLOCK_DOWNLOAD_TIMEOUT_PER_PEER * nOtherPeersWithValidatedDownloads)) { + if (count_microseconds(current_time) > state.nDownloadingSince + consensusParams.nPowTargetSpacing * (BLOCK_DOWNLOAD_TIMEOUT_BASE + BLOCK_DOWNLOAD_TIMEOUT_PER_PEER * nOtherPeersWithValidatedDownloads)) { LogPrintf("Timeout downloading block %s from peer=%d, disconnecting\n", queuedBlock.hash.ToString(), pto->GetId()); pto->fDisconnect = true; return true; @@ -4495,7 +4491,7 @@ bool PeerManager::SendMessages(CNode* pto) if (state.fSyncStarted && state.nHeadersSyncTimeout < std::numeric_limits::max()) { // Detect whether this is a stalling initial-headers-sync peer if (pindexBestHeader->GetBlockTime() <= GetAdjustedTime() - 24 * 60 * 60) { - if (nNow > state.nHeadersSyncTimeout && nSyncStarted == 1 && (nPreferredDownload - state.fPreferredDownload >= 1)) { + if (count_microseconds(current_time) > state.nHeadersSyncTimeout && nSyncStarted == 1 && (nPreferredDownload - state.fPreferredDownload >= 1)) { // Disconnect a peer (without the noban permission) if it is our only sync peer, // and we have others we could be using instead. // Note: If all our peers are inbound, then we won't @@ -4545,7 +4541,7 @@ bool PeerManager::SendMessages(CNode* pto) } if (state.nBlocksInFlight == 0 && staller != -1) { if (State(staller)->nStallingSince == 0) { - State(staller)->nStallingSince = nNow; + State(staller)->nStallingSince = count_microseconds(current_time); LogPrint(BCLog::NET, "Stall started peer=%d\n", staller); } } @@ -4629,7 +4625,6 @@ bool PeerManager::SendMessages(CNode* pto) !pto->HasPermission(PF_FORCERELAY) // peers with the forcerelay permission should not filter txs to us ) { CAmount currentFilter = m_mempool.GetMinFee(gArgs.GetArg("-maxmempool", DEFAULT_MAX_MEMPOOL_SIZE) * 1000000).GetFeePerK(); - int64_t timeNow = GetTimeMicros(); static FeeFilterRounder g_filter_rounder{CFeeRate{DEFAULT_MIN_RELAY_TX_FEE}}; if (m_chainman.ActiveChainstate().IsInitialBlockDownload()) { // Received tx-inv messages are discarded when the active @@ -4640,10 +4635,10 @@ bool PeerManager::SendMessages(CNode* pto) if (pto->m_tx_relay->lastSentFeeFilter == MAX_FILTER) { // Send the current filter if we sent MAX_FILTER previously // and made it out of IBD. - pto->m_tx_relay->nextSendTimeFeeFilter = timeNow - 1; + pto->m_tx_relay->nextSendTimeFeeFilter = count_microseconds(current_time) - 1; } } - if (timeNow > pto->m_tx_relay->nextSendTimeFeeFilter) { + if (count_microseconds(current_time) > pto->m_tx_relay->nextSendTimeFeeFilter) { CAmount filterToSend = g_filter_rounder.round(currentFilter); // We always have a fee filter of at least minRelayTxFee filterToSend = std::max(filterToSend, ::minRelayTxFee.GetFeePerK()); @@ -4651,13 +4646,13 @@ bool PeerManager::SendMessages(CNode* pto) m_connman.PushMessage(pto, msgMaker.Make(NetMsgType::FEEFILTER, filterToSend)); pto->m_tx_relay->lastSentFeeFilter = filterToSend; } - pto->m_tx_relay->nextSendTimeFeeFilter = PoissonNextSend(timeNow, AVG_FEEFILTER_BROADCAST_INTERVAL); + pto->m_tx_relay->nextSendTimeFeeFilter = PoissonNextSend(count_microseconds(current_time), AVG_FEEFILTER_BROADCAST_INTERVAL); } // If the fee filter has changed substantially and it's still more than MAX_FEEFILTER_CHANGE_DELAY // until scheduled broadcast, then move the broadcast to within MAX_FEEFILTER_CHANGE_DELAY. - else if (timeNow + MAX_FEEFILTER_CHANGE_DELAY * 1000000 < pto->m_tx_relay->nextSendTimeFeeFilter && + else if (count_microseconds(current_time) + MAX_FEEFILTER_CHANGE_DELAY * 1000000 < pto->m_tx_relay->nextSendTimeFeeFilter && (currentFilter < 3 * pto->m_tx_relay->lastSentFeeFilter / 4 || currentFilter > 4 * pto->m_tx_relay->lastSentFeeFilter / 3)) { - pto->m_tx_relay->nextSendTimeFeeFilter = timeNow + GetRandInt(MAX_FEEFILTER_CHANGE_DELAY) * 1000000; + pto->m_tx_relay->nextSendTimeFeeFilter = count_microseconds(current_time) + GetRandInt(MAX_FEEFILTER_CHANGE_DELAY) * 1000000; } } } // release cs_main diff --git a/test/functional/p2p_tx_download.py b/test/functional/p2p_tx_download.py index 653c7ae43f1..5c3f021b3fd 100755 --- a/test/functional/p2p_tx_download.py +++ b/test/functional/p2p_tx_download.py @@ -158,23 +158,19 @@ class TxDownloadTest(BitcoinTestFramework): self.nodes[0].p2ps[0].send_message(msg_notfound(vec=[CInv(MSG_TX, 1)])) def run_test(self): - # Setup the p2p connections - self.peers = [] - for node in self.nodes: - for _ in range(NUM_INBOUND): - self.peers.append(node.add_p2p_connection(TestP2PConn())) - - self.log.info("Nodes are setup with {} incoming connections each".format(NUM_INBOUND)) - - self.test_spurious_notfound() - - # Test the in-flight max first, because we want no transactions in - # flight ahead of this test. - self.test_in_flight_max() - - self.test_inv_block() - - self.test_tx_requests() + # Run each test against new bitcoind instances, as setting mocktimes has long-term effects on when + # the next trickle relay event happens. + for test in [self.test_spurious_notfound, self.test_in_flight_max, self.test_inv_block, self.test_tx_requests]: + self.stop_nodes() + self.start_nodes() + self.connect_nodes(1, 0) + # Setup the p2p connections + self.peers = [] + for node in self.nodes: + for _ in range(NUM_INBOUND): + self.peers.append(node.add_p2p_connection(TestP2PConn())) + self.log.info("Nodes are setup with {} incoming connections each".format(NUM_INBOUND)) + test() if __name__ == '__main__': diff --git a/test/functional/wallet_resendwallettransactions.py b/test/functional/wallet_resendwallettransactions.py index d3c03c47644..1dcb12de08a 100755 --- a/test/functional/wallet_resendwallettransactions.py +++ b/test/functional/wallet_resendwallettransactions.py @@ -64,6 +64,10 @@ class ResendWalletTransactionsTest(BitcoinTestFramework): # Transaction should be rebroadcast approximately 24 hours in the future, # but can range from 12-36. So bump 36 hours to be sure. node.setmocktime(now + 36 * 60 * 60) + # Tell scheduler to call MaybeResendWalletTxn now. + node.mockscheduler(1) + # Give some time for trickle to occur + node.setmocktime(now + 36 * 60 * 60 + 600) peer_second.wait_for_broadcast([txid])