[qa] Create cached blocks with current timestamps #15360
Conversation
| # blockchain sync later in the test when nodes are connected, due to | ||
| # timing issues. | ||
| for n in self.nodes: | ||
| assert n.getblockchaininfo()["initialblockdownload"] == False |
There was a problem hiding this comment.
This assertion would fail when the tests are called "manually", since the cache is not reset when calling tests individually (not through) the test_runner script.
$ ./test/functional/wallet_txn_doublespend.py
2019-02-08T17:09:47.027000Z TestFramework (INFO): Initializing test directory /tmp/bitcoin_func_test_62_g4dwe
2019-02-08T17:09:48.015000Z TestFramework (INFO): Stopping nodes
2019-02-08T17:09:48.275000Z TestFramework (INFO): Cleaning up /tmp/bitcoin_func_test_62_g4dwe on exit
2019-02-08T17:09:48.275000Z TestFramework (INFO): Tests successful
[... time travel to +1 day]
$ ./test/functional/wallet_txn_doublespend.py
2019-02-09T17:10:07.360000Z TestFramework (INFO): Initializing test directory /tmp/bitcoin_func_test_jck9m01h
2019-02-09T17:10:08.138000Z TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
File "/home/marco/workspace/bitcoin/test/functional/test_framework/test_framework.py", line 176, in main
self.run_test()
File "./test/functional/wallet_txn_doublespend.py", line 43, in run_test
assert n.getblockchaininfo()["initialblockdownload"] == False
AssertionError
There was a problem hiding this comment.
Ah, I misunderstood how the cache worked (I thought it only persisted between calls to tests in the same test_runner run, and otherwise was being cleared between tests).
| # blockchain sync later in the test when nodes are connected, due to | ||
| # timing issues. | ||
| for n in self.nodes: | ||
| assert n.getblockchaininfo()["initialblockdownload"] == False |
There was a problem hiding this comment.
Couldn't this be moved to setup_nodes under a condition of if not self.setup_clean_chain. This way there'd be a nice assumption that all nodes in tests could send and receive txs right away initially.
If the assertion failed, you could put a comment like # Cache might be outdated, please run test through the test_runner script
| # 2014 + (201 * 10 * 60)""" | ||
| self.mocktime = 1388534400 + (201 * 10 * 60) | ||
| # Create the blocks, spaced 10 minutes apart, starting now | ||
| self.mocktime = int(time.time()) |
There was a problem hiding this comment.
Seems arbitrary to still use mocktime, but only change the magic value. Also, wouldn't mining blocks with timestamps in the future lead to block sync issues? IIRC a node woulnd't even attempt to download a block when the header has a future timestamp?
I'd prefer to remove mocktime altogether and only use it in tests that require it for some reason (see the test below you modified for example)
Just my opinion, no need to fix in this pull request.
|
I'm not sure what the best fix here is, closing. |
|
:( Was good to see someone working on this, finally. |
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
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
3 participants
There doesn't seem to be any benefit to creating the cached data directories with old timestamps, but it does seem to interfere with tests because nodes using the cached chain were starting off in IBD, which interferes with chain sync.
This PR changes the cache to use current timestamps. One test seemed to be relying on the blocks in the cache being old, so I modified it to explicitly create old blocks.
Changing the cache to use recent timestamps -- and thus have nodes be out of IBD on startup -- fixes a bug in the wallet_txn_doublespend.py test, noted in #14446. Block sync to a node in IBD might fail because we are willing to wait a long time for our headers-sync peer to respond before we send getheaders messages to other peers. In wallet_txn_doublespend.py, the test tries to workaround this issue by mining a block after connection, which happens to trigger the IBD-node to send a getheaders after receiving the block INV. However, there is a race, where node connection and initial handshake could take longer than the call to generate the block, resulting in no block announcement going to the IBD peer, causing test failure.