Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

qa: Always refresh cache to be out of ibd #15419

Merged
merged 4 commits into from Feb 25, 2019

Conversation

Projects
None yet
6 participants
@MarcoFalke
Copy link
Member

commented Feb 15, 2019

When starting a test, we are always in IBD because the timestamps on cached blocks are in the past. Usually, we solve that by generating a block at the beginning of the test.

That is clumsy and might even lead to other problems such as #15360 and #14446 (comment)

So fix that by getting rid of mocktime and always refreshing the last block of the cache when starting the test framework.

Should fix #14446

@MarcoFalke MarcoFalke added the Tests label Feb 15, 2019

@MarcoFalke MarcoFalke force-pushed the MarcoFalke:Mf1902-mocktime branch 2 times, most recently from faba821 to fa05eef Feb 15, 2019

@DrahtBot

This comment has been minimized.

Copy link
Contributor

commented Feb 15, 2019

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

Conflicts

Reviewers, this pull request conflicts with the following ones:

  • #12134 (Build previous releases and run functional tests by Sjors)

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.

@promag
Copy link
Member

left a comment

nit, update copyright year.

@promag
Copy link
Member

left a comment

LGTM, some questions though, as I think you could take the opportunity to simplify a bit.

# blocks are created with timestamps 10 minutes apart
# starting from 2010 minutes in the past
block_time = self.mocktime - (201 * 10 * 60)
# The 4th node gets only 24 immature blocks.
for i in range(2):

This comment has been minimized.

Copy link
@promag

promag Feb 18, 2019

Member

Could remove this right?

This comment has been minimized.

Copy link
@MarcoFalke

MarcoFalke Feb 18, 2019

Author Member

Why?

Show resolved Hide resolved test/functional/test_framework/test_framework.py Outdated
for i in range(2):
for peer in range(4):
for j in range(25):
set_node_times(self.nodes, block_time)
if i == 1 and peer == 3 and j == 24:

This comment has been minimized.

Copy link
@promag

promag Feb 18, 2019

Member

Maybe something more straightforward?

def gen_blocks(peer, blocks):
    node = self.nodes[peer]
    address = node.get_deterministic_priv_key().address
    return node.generatetoaddress(blocks, address)

gen_blocks(0, 25)
gen_blocks(1, 25)
gen_blocks(2, 25)
gen_blocks(3, 24)

This comment has been minimized.

Copy link
@MarcoFalke

MarcoFalke Feb 18, 2019

Author Member

No, that would generate 99 blocks, we need 199.

Not sure if this looks simpler:

gen_blocks(0, 25)
gen_blocks(1, 25)
gen_blocks(2, 25)
gen_blocks(3, 25)
gen_blocks(0, 25)
gen_blocks(1, 25)
gen_blocks(2, 25)
gen_blocks(3, 24)

This comment has been minimized.

Copy link
@promag

promag Feb 18, 2019

Member

Oh right, I was doing for 99 🤦‍♂️

This comment has been minimized.

Copy link
@promag

promag Feb 18, 2019

Member

In that case

gen_blocks(0, 50)
gen_blocks(1, 50)
gen_blocks(2, 50)
gen_blocks(3, 49)

Or is there a reason against?

This comment has been minimized.

Copy link
@MarcoFalke

MarcoFalke Feb 18, 2019

Author Member

See the comment two lines up:

            # Create a 199-block-long chain; each of the 4 first nodes
            # gets 25 mature blocks and 25 immature.
# Must sync before next peer starts generating blocks
sync_blocks(self.nodes)

for n in self.nodes:
assert_equal(n.getblockchaininfo()["blocks"], 199)

This comment has been minimized.

Copy link
@promag

promag Feb 18, 2019

Member

Is this really necessary?

This comment has been minimized.

Copy link
@MarcoFalke

MarcoFalke Feb 18, 2019

Author Member

No, but nice to see that the cache really is 199 blocks high

@MarcoFalke MarcoFalke force-pushed the MarcoFalke:Mf1902-mocktime branch 3 times, most recently from fa9fda9 to fa5bc93 Feb 18, 2019

@jnewbery

This comment has been minimized.

Copy link
Member

commented Feb 18, 2019

Concept ACK. Please remove unrelated code style fixes from your commits.

I think 'rot' is the wrong terminology, and the comment here: faeb65a#diff-64721c5ee64d44f7114d6d0d2226db4dR495 isn't clear.

@sipa

This comment has been minimized.

Copy link
Member

commented Feb 19, 2019

By rotten, you mean dirty? :)

@MarcoFalke

This comment has been minimized.

Copy link
Member Author

commented Feb 19, 2019

rotten as in from yesterday or from last week. If the cache was edible, it would be rotten, no?

@jnewbery

This comment has been minimized.

Copy link
Member

commented Feb 19, 2019

rotten as in from yesterday or from last week. If the cache was edible, it would be rotten, no?

There's nothing wrong with the block, it's just old. I think this would be much clearer to people reading the tests if you removed the rotten terminology and just said that the latest block needs to be within the last 24 hours for the nodes to consider themselves sync'ed to the tip, possibly with reference to IsInitialBlockDownload() and

static const int64_t DEFAULT_MAX_TIP_AGE = 24 * 60 * 60;
.

@Sjors

This comment has been minimized.

Copy link
Member

commented Feb 19, 2019

the latest block needs to be within the last 24 hours for the nodes to consider themselves sync'ed to the tip

That's definitely useful to remind the reader of (including yours truly).

@MarcoFalke MarcoFalke changed the title qa: Always refresh rotten cache to be out of ibd qa: Always refresh stale cache to be out of ibd Feb 19, 2019

@MarcoFalke

This comment has been minimized.

Copy link
Member Author

commented Feb 19, 2019

Ok, going to fixup that comment as per @jnewbery's suggestion

@MarcoFalke MarcoFalke force-pushed the MarcoFalke:Mf1902-mocktime branch 2 times, most recently from fa0c88c to faff8d6 Feb 19, 2019

@jnewbery

This comment has been minimized.

Copy link
Member

commented Feb 19, 2019

stale is still wrong:

  • in caching terminology, stale is commonly understood as meaning that a piece of data in a cache is no longer valid because the underlying value for that data has been updated.
  • In Bitcoin terminology, a stale block is one which is valid, but not part of the main chain as its on a fork which has less work than the main chain.

Neither of those is the case here. The old block is not stale, it's just old.

I suggest not creating new (confusing) terminology here and just describe what's actually being implemented.

@MarcoFalke MarcoFalke changed the title qa: Always refresh stale cache to be out of ibd qa: Always refresh cache to be out of ibd Feb 19, 2019

@Sjors
Copy link
Member

left a comment

The following tests failed on macOS 10.14.3 on the first run. logs:

mining_basic.py                       | ✖ Failed  | 15 s
p2p_invalid_messages.py               | ✖ Failed  | 8 s
tool_wallet.py                        | ✖ Failed  | 2 s
wallet_txn_clone.py                   | ✖ Failed  | 11 s
wallet_txn_clone.py --mineblock       | ✖ Failed  | 9 s
wallet_txn_clone.py --segwit          | ✖ Failed  | 11 s

Some of that seems to be usage of modern Python, which might be unrelated.

@jnewbery agreed. The problem seems to be that cache is not properly invalidated. Our test suite cache items should probably have an expiration timestamp, but that's perhaps a bit overkill to engineer.

for i in range(2):
for peer in range(4):
for j in range(25):
if i == 1 and peer == 3 and j == 24:
# Don't store the very last block in the cache to avoid having it go stale
# See IsInitialBlockDownload()

This comment has been minimized.

Copy link
@Sjors

Sjors Feb 19, 2019

Member

This needs more explanation, since iiuc it's very relevant to the bug you're trying to squash. What cache is going stale and what is the consequence of that? And in what we should one see IsInitialBlockDownload? What about the cache causes nodes to think they're in or out of IBD? The absolute age of the block in the cache?

It's explained a bit in the next commit, but that's in a very different place.

This comment has been minimized.

Copy link
@MarcoFalke

MarcoFalke Feb 19, 2019

Author Member

There are other conditions that keep our node in IBD, but the one we care about here is the tip age (difference between now and the time the miner claimed to have mined the block)

@jnewbery

This comment has been minimized.

Copy link
Member

commented Feb 19, 2019

Can you remove unrelated style changes?

I don't care much about additional new lines between classes (https://github.com/bitcoin/bitcoin/pull/15419/files#diff-a12894108450a68b27252d39d7b6e704R44) or terminating lists with commas (https://github.com/bitcoin/bitcoin/pull/15419/files#diff-86294e5ae5283eebdd9f98d79007a0e1R93).

If you think that should be the project code style, the right thing to do would be update the developer notes and add linters.

MarcoFalke added some commits Feb 11, 2019

@MarcoFalke MarcoFalke force-pushed the MarcoFalke:Mf1902-mocktime branch from faff8d6 to fa25210 Feb 19, 2019

@MarcoFalke

This comment has been minimized.

Copy link
Member Author

commented Feb 19, 2019

@jnewbery We agreed to not add any style-related linters to this project several times already. Personally I format all changed code according to https://github.com/bitcoin/bitcoin/blob/master/doc/productivity.md#writing-code, so that review can focus on the actual changes and is not wasted on counting how many spaces or newlines are between non-whitepace characters.

@jnewbery

This comment has been minimized.

Copy link
Member

commented Feb 19, 2019

so that review can focus on the actual changes and is not wasted on counting how many spaces or newlines are between non-whitepace characters.

My suggestion is to not change code style in PRs which are supposed to be changing behaviour. Here for example: https://github.com/bitcoin/bitcoin/pull/15419/files#diff-64721c5ee64d44f7114d6d0d2226db4dR36 you add a newline that has nothing to do with the changes in this PR.

If you want review to focus on the actual changes, just remove unnecessary noise.

@MarcoFalke

This comment has been minimized.

Copy link
Member Author

commented Feb 19, 2019

I fixed up the comment and removed a newline that the formatter added. I missed the newline you pointed in the previous comment. Though, I am going to leave this as is for now unless there are actual concerns about the code.

@Sjors

This comment has been minimized.

Copy link
Member

commented Feb 20, 2019

Python syntax issue are fixed in #15439. Also ignore the tool_wallet.py failure, since I forgot to build that target.

utACK fa25210

@jnewbery
Copy link
Member

left a comment

Looks good. A few suggestions inline.

I still don't like the fact that this PR adds random newlines to various files but if you insist, then I don't care enough to block merging.

if not self.setup_clean_chain:
for n in self.nodes:
assert_equal(n.getblockchaininfo()["blocks"], 199)
self.log.debug('Generate a block with current time to finalize the cache and assert we are out of IBD')

This comment has been minimized.

Copy link
@jnewbery

jnewbery Feb 21, 2019

Member

I don't think "finalize the cache" would mean anything to people without more context. I'd suggest changing this to:

            # To ensure that all nodes are out of IBD, the most recent block must
            # be within the last 24 hours (see IsInitialBlockDownload()). Generate it here.
            self.log.debug('Generate a block with current time')
block = self.nodes[0].getblock(blockhash=block_hash, verbosity=0)
for n in self.nodes:
n.submitblock(block)
chain_info = n.getblockchaininfo()

This comment has been minimized.

Copy link
@jnewbery

jnewbery Feb 21, 2019

Member

There's no race here since submitblock() will only return after ActivateBestChain(), but if we ever make ProcessNewBlock() multithreaded, then there could be a race if submitblock() returns before the best chain has been activated.

I don't think you need to do anything here, but you could add a comment or a wait_until() if you wanted to make this clear to readers.

self.mocktime = 1388534400 + (201 * 10 * 60)

# Create a 200-block-long chain; each of the 4 first nodes
# Create a 199-block-long chain; each of the 4 first nodes

This comment has been minimized.

Copy link
@jnewbery

jnewbery Feb 21, 2019

Member

A couple of suggestions that could make this more efficient/clear:

  • you could generate all blocks on node0, generating to the other nodes' addresses in turn. This would avoid the sync_blocks() calls.
  • do any of the tests rely on the immature blocks becoming mature during the test? I'd hope not. If they don't, you could generate those immature blocks to a dummy address, and change this to:
self.nodes[0].generatetoaddress(25, <node0_address>)
self.nodes[0].generatetoaddress(25, <node1_address>)
self.nodes[0].generatetoaddress(25, <node2_address>)
self.nodes[0].generatetoaddress(25, <node3_address>)
self.nodes[0].generatetoaddress(99, <dummy_address>)

or:

for i in range(4):
    self.nodes[0].generatetoaddress(25, self.nodes[i].get_deterministic_priv_key().address())
self.nodes[0].generatetoaddress(99, <dummy_address>)

This comment has been minimized.

Copy link
@MarcoFalke

MarcoFalke Feb 25, 2019

Author Member

Done, I measured that it wouldn't make it faster, but at least the code is shorter

# If the nodes are not all out of IBD, that can interfere with
# blockchain sync later in the test when nodes are connected, due to
# timing issues.
for n in self.nodes:

This comment has been minimized.

Copy link
@jnewbery

jnewbery Feb 21, 2019

Member

Suggestion: combine this with the for loop below.

@MarcoFalke MarcoFalke force-pushed the MarcoFalke:Mf1902-mocktime branch 3 times, most recently from fa68960 to 2550188 Feb 23, 2019

@MarcoFalke MarcoFalke force-pushed the MarcoFalke:Mf1902-mocktime branch from 2550188 to fa2cdc9 Feb 25, 2019

MarcoFalke added a commit to MarcoFalke/bitcoin that referenced this pull request Feb 25, 2019

Merge bitcoin#15419: qa: Always refresh cache to be out of ibd
fa2cdc9 test: Simplify create_cache (MarcoFalke)
fa25210 qa: Fix wallet_txn_doublespend issue (MarcoFalke)
1111aec qa: Always refresh stale cache to be out of ibd (MarcoFalke)
fab0d85 qa: Remove mocktime unless required (MarcoFalke)

Pull request description:

  When starting a test, we are always in IBD because the timestamps on cached blocks are in the past. Usually, we solve that by generating a block at the beginning of the test.

  That is clumsy and might even lead to other problems such as bitcoin#15360 and bitcoin#14446 (comment)

  So fix that by getting rid of mocktime and always refreshing the last block of the cache when starting the test framework.

  Should fix bitcoin#14446

Tree-SHA512: 6af09800f9c86131349a103af617a54551f5f3f3260d38e14e3f30fdd3d91a0feb0100c56cbb12eae4aeac5571ae4b530b16345cbb831d2670237b53351a22c1

@MarcoFalke MarcoFalke merged commit fa2cdc9 into bitcoin:master Feb 25, 2019

1 of 2 checks passed

continuous-integration/appveyor/pr Waiting for AppVeyor build to complete
Details
continuous-integration/travis-ci/pr The Travis CI build passed
Details

@MarcoFalke MarcoFalke deleted the MarcoFalke:Mf1902-mocktime branch Feb 25, 2019

@jnewbery

This comment has been minimized.

Copy link
Member

commented Feb 25, 2019

utACK fa2cdc9

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.