Use mockable time everywhere in net_processing #20027

sipa · 2020-09-27T21:53:32Z

The fact that net_processing uses a mix of mockable tand non-mockable time functions made it hard to write functional tests for #19988.

I'm opening this as a separate PR as I believe it's independently useful. In some ways this doesn't go quite as far as it could, as there are now several data structures that could be converted to std::chrono types as well now. I haven't done that here, but I'm happy to reconsider that.

DrahtBot · 2020-09-28T03:53:01Z

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

Conflicts

Reviewers, this pull request conflicts with the following ones:

Make all of net_processing (and some of net) use std::chrono types #20044 (Make all of net_processing (and some of net) use std::chrono types by sipa)
test: Remove or explain syncwithvalidationinterfacequeue #19893 (test: Remove or explain syncwithvalidationinterfacequeue by MarcoFalke)

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.

maflcko

Concept ACK, but I don't like that this patch makes the code more fragile.

src/net_processing.cpp

test/functional/wallet_resendwallettransactions.py

src/net_processing.cpp

naumenkogs · 2020-09-28T06:42:22Z

Concept ACK

practicalswift · 2020-09-28T13:13:50Z

Concept ACK

ajtowns

ACK e5c0223

Checked conversion from GetTime() to count_microsecounds(GetTime<>()) and that variables that are now mockable are only compared with mockable times.

ajtowns · 2020-10-07T00:14:01Z

test/functional/p2p_tx_download.py

-
-        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.


I'm not sure it's a good idea to link mockable time to network delays in general -- if you bump the mocktime by a hours/days that shouldn't risk triggering "hey this peer hasn't said anything for ages, let's disconnect" conditions, and equally if you backdate the mocktime for some reason, that shouldn't cause network tasks to say "oh, we decided we don't need to do anything until time t, which is apparently years away" and effectively hang. Having to tweak tests feels a bit like a canary...

My intuition for this was we have two sorts of delays -- short ones (<30s) that just prevent us busy looping when there's nothing to actually do and don't generally need to be precisely controlled, and long ones (minutes/hours/days) that are human visible and that we'll obviously need mocktime to test because minutes/hours/days is effectively forever.

But maybe we've really got two different sorts of mocking that we want to do -- "set the time to X" and it stays there until we're ready to set it to some different time "Y" (what we've got now), and "everything that was going to happen in the next 5 minutes, get it done now" (something more like what the mockscheduler rpc does)? You could implement the latter by bumping the system clock (rather than replacing it), and only allowing the bump amount to increase.

I suspect at a minimum we'd want to switch to the std::chrono::time_point abstraction and use different clocks so that we could tell these cases apart by type, but that doesn't seem like a good thing to dive into immediately before feature freeze. (I had a sketch I was working on a while back at https://github.com/ajtowns/bitcoin/commits/201908-systime fwiw)

And mocktime is only relevant for regtest, so the downsides of this approach are pretty limited (presumably to just these test case changes)

I think we'll indeed a number of timers for different purposes, eventually:

System time (possibly adjusted by peer data), for use in block and wallet transaction timestamps (as they have an absolute UNIX epoch as reference ).

Steady time, mockable, for timing application level events (tx relay, pinging, addr rebroadcast, ...).

Steady time, for avoiding busy looping (like select() timeout, message handler 100ms delay, ...).

The last one indeed I think shouldn't be mockable, but things like ping timeouts I think should be. It just becomes too complicated when multiple clocks are mixed within one layer of the code - even if it means using a mockable clock for some delays that are in practice very short.

As for dealing with the fact that making small delays mockable complicates testing, I think the best solution is a "add X to mock time offset, but keep the clock running", if that's what you meant.

I disagree that system time (used for blocks and wallet txs) should not be mockable. For example, sometimes we want to create a deterministic blockchain, so the block times need to be fixed. I know it is possible to use the python block generator, but I don't see a strong reason to disallow system time to be mocked.

Edit: So it is also important to be able to say "set time to a constant" instead of just "add offset, but keep clock running".

I think the idea was to have two ways of mocking -- fix the system time to X (and prevent it from advancing, so time goes t, t+1, t+2, t+3, X, X, X, X), or bump the system time by D (so time goes t, t+1, t+2, t+3, t+D+3, t+D+4, t+D+5).

src/net_processing.cpp

jnewbery · 2020-10-07T08:41:15Z

ACK e5c0223

maflcko

ACK 93fca5f 🐎

Show signature and timestamp

Signature:

Timestamp of file with hash 03cb2a91902242d76811cd547cea6874233f1f46c555bd142069e3cbfa6b48fc -

test/functional/wallet_resendwallettransactions.py

maflcko · 2020-10-08T08:15:05Z

ACK b6834e3 🌶

Show signature and timestamp

Signature:

Timestamp of file with hash df57ab8fe3ed162f8bb109f94ab3daf5cb2dd502b92b384bc065c8b7c69084eb -

jnewbery · 2020-10-08T09:17:29Z

utACK b6834e3

naumenkogs · 2020-10-08T09:31:05Z

utACK b6834e3

I agree with the comments by @ajtowns, but I guess it can only introduce problems on regtest? And since this PR is necessary for #19988, I think it's fine, that can be fixed later.

rebroad · 2021-02-23T15:35:12Z

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<std::chrono::microseconds>()));


seems like a backwards step turning neat code into lengthy code - why not use a function for this or change GetTimeMicros() itself?

Summary: ``` The fact that net_processing uses a mix of mockable tand non-mockable time functions made it hard to write functional tests for #19988. I'm opening this as a separate PR as I believe it's independently useful. In some ways this doesn't go quite as far as it could, as there are now several data structures that could be converted to std::chrono types as well now. I haven't done that here, but I'm happy to reconsider that. ``` Backport of [[bitcoin/bitcoin#20027 | core#20027]]. Test Plan: ninja all check-all Reviewers: #bitcoin_abc, deadalnix Reviewed By: #bitcoin_abc, deadalnix Differential Revision: https://reviews.bitcoinabc.org/D9542

sipa force-pushed the 202009_mockable_netproc branch from 1576f76 to 155a4de Compare September 27, 2020 22:17

DrahtBot added the P2P label Sep 27, 2020

sipa force-pushed the 202009_mockable_netproc branch from 155a4de to 1281d7d Compare September 28, 2020 00:29

bitcoin deleted a comment Sep 28, 2020

DrahtBot mentioned this pull request Sep 28, 2020

test: Remove or explain syncwithvalidationinterfacequeue #19893

Merged

maflcko reviewed Sep 28, 2020

View reviewed changes

src/net_processing.cpp Outdated Show resolved Hide resolved

src/net_processing.cpp Show resolved Hide resolved

test/functional/wallet_resendwallettransactions.py Outdated Show resolved Hide resolved

src/net_processing.cpp Outdated Show resolved Hide resolved

sipa force-pushed the 202009_mockable_netproc branch from 1281d7d to e5c0223 Compare September 28, 2020 06:55

maflcko added the Refactoring label Sep 28, 2020

sipa mentioned this pull request Sep 30, 2020

Make all of net_processing (and some of net) use std::chrono types #20044

Closed

ajtowns approved these changes Oct 7, 2020

View reviewed changes

sipa force-pushed the 202009_mockable_netproc branch from e5c0223 to d7fad16 Compare October 7, 2020 23:24

DrahtBot mentioned this pull request Oct 8, 2020

Overhaul transaction request logic #19988

Merged

sipa force-pushed the 202009_mockable_netproc branch from d7fad16 to 93fca5f Compare October 8, 2020 02:13

maflcko approved these changes Oct 8, 2020

View reviewed changes

test/functional/wallet_resendwallettransactions.py Outdated Show resolved Hide resolved

sipa added 2 commits October 8, 2020 01:04

Use mockable time everywhere in net_processing

ec3916f

Avoid 'timing mishap' warnings when mocking

b6834e3

sipa force-pushed the 202009_mockable_netproc branch from 44b17b2 to b6834e3 Compare October 8, 2020 08:05

fanquake requested a review from ajtowns October 8, 2020 09:28

maflcko merged commit 9dd4de2 into bitcoin:master Oct 8, 2020

dhruv mentioned this pull request Jan 26, 2021

Make all of net_processing (and some of net) use std::chrono types #21015

Merged

jnewbery mentioned this pull request Feb 10, 2021

Net: Move ping data to net_processing #20721

Merged

rebroad reviewed Feb 23, 2021

View reviewed changes

bitcoin locked as resolved and limited conversation to collaborators Aug 16, 2022

Use mockable time everywhere in net_processing #20027

Use mockable time everywhere in net_processing #20027

Uh oh!

Conversation

sipa commented Sep 27, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

DrahtBot commented Sep 28, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Conflicts

Uh oh!

maflcko left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

naumenkogs commented Sep 28, 2020

Uh oh!

practicalswift commented Sep 28, 2020

Uh oh!

ajtowns left a comment

Choose a reason for hiding this comment

Uh oh!

ajtowns Oct 7, 2020

Choose a reason for hiding this comment

Uh oh!

sipa Oct 7, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

maflcko Oct 8, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

ajtowns Oct 8, 2020

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

jnewbery commented Oct 7, 2020

Uh oh!

maflcko left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

maflcko commented Oct 8, 2020

Uh oh!

jnewbery commented Oct 8, 2020

Uh oh!

naumenkogs commented Oct 8, 2020

Uh oh!

rebroad Feb 23, 2021

Choose a reason for hiding this comment

Uh oh!

Uh oh!

sipa commented Sep 27, 2020 •

edited

Loading

DrahtBot commented Sep 28, 2020 •

edited

Loading

sipa Oct 7, 2020 •

edited

Loading

maflcko Oct 8, 2020 •

edited

Loading