Merge #11707: [tests] Fix sendheaders

9d42cc333 [tests] address review comments (John Newbery)
f0c4ab9a7 [tests] fix flakiness in sendheaders.py (John Newbery)
25fd6e2c2 [tests] refactor check_last_announcement() in sendheaders.py (John Newbery)
f39d4bbd1 [tests] tidy up BaseNode in sendheaders.py (John Newbery)
2613c545f [tests] fix flake8 warnings in sendheaders.py (John Newbery)

Pull request description:

  This PR should fix the intermittent failure of sendheaders.py described in #11673. The first three commits are tidying up and refactoring the file. The final commit _fix flakiness in sendheaders.py_ fixes the intermittent failures. The commit message for that commit describes the problems that are being fixed.

  I think @laanwj @MeshCollider @MarcoFalke have seen these failures.

  fixes #11673

Tree-SHA512: 278e1af85f2eae00f970f2d8ef33686dd52b4f62180dea4cfdaff7bcf3287c6f1c2930355d99461a12f0c51c4d42cc3b1cb3275174134028ca4d06ffc24c18dd
This commit is contained in:
MarcoFalke 2017-11-18 17:30:14 -05:00
commit 0d89fa0877
No known key found for this signature in database
GPG Key ID: D2EA4850E7528B25

View File

@ -6,9 +6,11 @@
Setup: Setup:
- Two nodes, two p2p connections to node0. One p2p connection should only ever - Two nodes:
receive inv's (omitted from testing description below, this is our control). - node0 is the node-under-test. We create two p2p connections to it. The
Second node is used for creating reorgs. first p2p connection is a control and should only ever receive inv's. The
second p2p connection tests the headers sending logic.
- node1 is used to create reorgs.
test_null_locators test_null_locators
================== ==================
@ -83,35 +85,45 @@ d. Announce 49 headers that don't connect.
e. Announce one more that doesn't connect. e. Announce one more that doesn't connect.
Expect: disconnect. Expect: disconnect.
""" """
from test_framework.mininode import *
from test_framework.test_framework import BitcoinTestFramework
from test_framework.util import *
from test_framework.blocktools import create_block, create_coinbase from test_framework.blocktools import create_block, create_coinbase
from test_framework.mininode import (
CBlockHeader,
CInv,
NODE_WITNESS,
NetworkThread,
NodeConnCB,
mininode_lock,
msg_block,
msg_getblocks,
msg_getdata,
msg_getheaders,
msg_headers,
msg_inv,
msg_sendheaders,
)
from test_framework.test_framework import BitcoinTestFramework
from test_framework.util import (
assert_equal,
sync_blocks,
wait_until,
)
DIRECT_FETCH_RESPONSE_TIME = 0.05
direct_fetch_response_time = 0.05 class BaseNode(NodeConnCB):
class TestNode(NodeConnCB):
def __init__(self): def __init__(self):
super().__init__() super().__init__()
self.block_announced = False self.block_announced = False
self.last_blockhash_announced = None self.last_blockhash_announced = None
def clear_last_announcement(self): def send_get_data(self, block_hashes):
with mininode_lock: """Request data for a list of block hashes."""
self.block_announced = False
self.last_message.pop("inv", None)
self.last_message.pop("headers", None)
# Request data for a list of block hashes
def get_data(self, block_hashes):
msg = msg_getdata() msg = msg_getdata()
for x in block_hashes: for x in block_hashes:
msg.inv.append(CInv(2, x)) msg.inv.append(CInv(2, x))
self.connection.send_message(msg) self.connection.send_message(msg)
def get_headers(self, locator, hashstop): def send_get_headers(self, locator, hashstop):
msg = msg_getheaders() msg = msg_getheaders()
msg.locator.vHave = locator msg.locator.vHave = locator
msg.hashstop = hashstop msg.hashstop = hashstop
@ -122,58 +134,6 @@ class TestNode(NodeConnCB):
msg.inv = [CInv(2, blockhash)] msg.inv = [CInv(2, blockhash)]
self.connection.send_message(msg) self.connection.send_message(msg)
def on_inv(self, conn, message):
self.block_announced = True
self.last_blockhash_announced = message.inv[-1].hash
def on_headers(self, conn, message):
if len(message.headers):
self.block_announced = True
message.headers[-1].calc_sha256()
self.last_blockhash_announced = message.headers[-1].sha256
# Test whether the last announcement we received had the
# right header or the right inv
# inv and headers should be lists of block hashes
def check_last_announcement(self, headers=None, inv=None):
expect_headers = headers if headers != None else []
expect_inv = inv if inv != None else []
test_function = lambda: self.block_announced
wait_until(test_function, timeout=60, lock=mininode_lock)
with mininode_lock:
self.block_announced = False
success = True
compare_inv = []
if "inv" in self.last_message:
compare_inv = [x.hash for x in self.last_message["inv"].inv]
if compare_inv != expect_inv:
success = False
hash_headers = []
if "headers" in self.last_message:
# treat headers as a list of block hashes
hash_headers = [ x.sha256 for x in self.last_message["headers"].headers ]
if hash_headers != expect_headers:
success = False
self.last_message.pop("inv", None)
self.last_message.pop("headers", None)
return success
def wait_for_getdata(self, hash_list, timeout=60):
if hash_list == []:
return
test_function = lambda: "getdata" in self.last_message and [x.hash for x in self.last_message["getdata"].inv] == hash_list
wait_until(test_function, timeout=timeout, lock=mininode_lock)
return
def wait_for_block_announcement(self, block_hash, timeout=60):
test_function = lambda: self.last_blockhash_announced == block_hash
wait_until(test_function, timeout=timeout, lock=mininode_lock)
return
def send_header_for_blocks(self, new_blocks): def send_header_for_blocks(self, new_blocks):
headers_message = msg_headers() headers_message = msg_headers()
headers_message.headers = [CBlockHeader(b) for b in new_blocks] headers_message.headers = [CBlockHeader(b) for b in new_blocks]
@ -184,24 +144,79 @@ class TestNode(NodeConnCB):
getblocks_message.locator.vHave = locator getblocks_message.locator.vHave = locator
self.send_message(getblocks_message) self.send_message(getblocks_message)
def wait_for_getdata(self, hash_list, timeout=60):
if hash_list == []:
return
test_function = lambda: "getdata" in self.last_message and [x.hash for x in self.last_message["getdata"].inv] == hash_list
wait_until(test_function, timeout=timeout, lock=mininode_lock)
def wait_for_block_announcement(self, block_hash, timeout=60):
test_function = lambda: self.last_blockhash_announced == block_hash
wait_until(test_function, timeout=timeout, lock=mininode_lock)
def on_inv(self, conn, message):
self.block_announced = True
self.last_blockhash_announced = message.inv[-1].hash
def on_headers(self, conn, message):
if len(message.headers):
self.block_announced = True
message.headers[-1].calc_sha256()
self.last_blockhash_announced = message.headers[-1].sha256
def clear_last_announcement(self):
with mininode_lock:
self.block_announced = False
self.last_message.pop("inv", None)
self.last_message.pop("headers", None)
def check_last_announcement(self, headers=None, inv=None):
"""Test whether the last announcement received had the right header or the right inv.
inv and headers should be lists of block hashes."""
test_function = lambda: self.block_announced
wait_until(test_function, timeout=60, lock=mininode_lock)
with mininode_lock:
self.block_announced = False
compare_inv = []
if "inv" in self.last_message:
compare_inv = [x.hash for x in self.last_message["inv"].inv]
if inv is not None:
assert_equal(compare_inv, inv)
compare_headers = []
if "headers" in self.last_message:
compare_headers = [x.sha256 for x in self.last_message["headers"].headers]
if headers is not None:
assert_equal(compare_headers, headers)
self.last_message.pop("inv", None)
self.last_message.pop("headers", None)
class SendHeadersTest(BitcoinTestFramework): class SendHeadersTest(BitcoinTestFramework):
def set_test_params(self): def set_test_params(self):
self.setup_clean_chain = True self.setup_clean_chain = True
self.num_nodes = 2 self.num_nodes = 2
# mine count blocks and return the new tip
def mine_blocks(self, count): def mine_blocks(self, count):
"""Mine count blocks and return the new tip."""
# Clear out last block announcement from each p2p listener # Clear out last block announcement from each p2p listener
[x.clear_last_announcement() for x in self.nodes[0].p2ps] [x.clear_last_announcement() for x in self.nodes[0].p2ps]
self.nodes[0].generate(count) self.nodes[0].generate(count)
return int(self.nodes[0].getbestblockhash(), 16) return int(self.nodes[0].getbestblockhash(), 16)
# mine a reorg that invalidates length blocks (replacing them with
# length+1 blocks).
# Note: we clear the state of our p2p connections after the
# to-be-reorged-out blocks are mined, so that we don't break later tests.
# return the list of block hashes newly mined
def mine_reorg(self, length): def mine_reorg(self, length):
"""Mine a reorg that invalidates length blocks (replacing them with # length+1 blocks).
Note: we clear the state of our p2p connections after the
to-be-reorged-out blocks are mined, so that we don't break later tests.
return the list of block hashes newly mined."""
self.nodes[0].generate(length) # make sure all invalidated blocks are node0's self.nodes[0].generate(length) # make sure all invalidated blocks are node0's
sync_blocks(self.nodes, wait=0.1) sync_blocks(self.nodes, wait=0.1)
for x in self.nodes[0].p2ps: for x in self.nodes[0].p2ps:
@ -217,10 +232,10 @@ class SendHeadersTest(BitcoinTestFramework):
def run_test(self): def run_test(self):
# Setup the p2p connections and start up the network thread. # Setup the p2p connections and start up the network thread.
inv_node = self.nodes[0].add_p2p_connection(TestNode()) inv_node = self.nodes[0].add_p2p_connection(BaseNode())
# Set nServices to 0 for test_node, so no block download will occur outside of # Make sure NODE_NETWORK is not set for test_node, so no block download
# direct fetching # will occur outside of direct fetching
test_node = self.nodes[0].add_p2p_connection(TestNode(), services=NODE_WITNESS) test_node = self.nodes[0].add_p2p_connection(BaseNode(), services=NODE_WITNESS)
NetworkThread().start() # Start up network handling in another thread NetworkThread().start() # Start up network handling in another thread
@ -232,27 +247,32 @@ class SendHeadersTest(BitcoinTestFramework):
inv_node.sync_with_ping() inv_node.sync_with_ping()
test_node.sync_with_ping() test_node.sync_with_ping()
self.test_null_locators(test_node) self.test_null_locators(test_node, inv_node)
self.test_nonnull_locators(test_node, inv_node) self.test_nonnull_locators(test_node, inv_node)
def test_null_locators(self, test_node): def test_null_locators(self, test_node, inv_node):
tip = self.nodes[0].getblockheader(self.nodes[0].generate(1)[0]) tip = self.nodes[0].getblockheader(self.nodes[0].generate(1)[0])
tip_hash = int(tip["hash"], 16) tip_hash = int(tip["hash"], 16)
inv_node.check_last_announcement(inv=[tip_hash], headers=[])
test_node.check_last_announcement(inv=[tip_hash], headers=[])
self.log.info("Verify getheaders with null locator and valid hashstop returns headers.") self.log.info("Verify getheaders with null locator and valid hashstop returns headers.")
test_node.clear_last_announcement() test_node.clear_last_announcement()
test_node.get_headers(locator=[], hashstop=tip_hash) test_node.send_get_headers(locator=[], hashstop=tip_hash)
assert_equal(test_node.check_last_announcement(headers=[tip_hash]), True) test_node.check_last_announcement(headers=[tip_hash])
self.log.info("Verify getheaders with null locator and invalid hashstop does not return headers.") self.log.info("Verify getheaders with null locator and invalid hashstop does not return headers.")
block = create_block(int(tip["hash"], 16), create_coinbase(tip["height"] + 1), tip["mediantime"] + 1) block = create_block(int(tip["hash"], 16), create_coinbase(tip["height"] + 1), tip["mediantime"] + 1)
block.solve() block.solve()
test_node.send_header_for_blocks([block]) test_node.send_header_for_blocks([block])
test_node.clear_last_announcement() test_node.clear_last_announcement()
test_node.get_headers(locator=[], hashstop=int(block.hash, 16)) test_node.send_get_headers(locator=[], hashstop=int(block.hash, 16))
test_node.sync_with_ping() test_node.sync_with_ping()
assert_equal(test_node.block_announced, False) assert_equal(test_node.block_announced, False)
inv_node.clear_last_announcement()
test_node.send_message(msg_block(block)) test_node.send_message(msg_block(block))
inv_node.check_last_announcement(inv=[int(block.hash, 16)], headers=[])
def test_nonnull_locators(self, test_node, inv_node): def test_nonnull_locators(self, test_node, inv_node):
tip = int(self.nodes[0].getbestblockhash(), 16) tip = int(self.nodes[0].getbestblockhash(), 16)
@ -263,17 +283,17 @@ class SendHeadersTest(BitcoinTestFramework):
for i in range(4): for i in range(4):
old_tip = tip old_tip = tip
tip = self.mine_blocks(1) tip = self.mine_blocks(1)
assert_equal(inv_node.check_last_announcement(inv=[tip]), True) inv_node.check_last_announcement(inv=[tip], headers=[])
assert_equal(test_node.check_last_announcement(inv=[tip]), True) test_node.check_last_announcement(inv=[tip], headers=[])
# Try a few different responses; none should affect next announcement # Try a few different responses; none should affect next announcement
if i == 0: if i == 0:
# first request the block # first request the block
test_node.get_data([tip]) test_node.send_get_data([tip])
test_node.wait_for_block(tip) test_node.wait_for_block(tip)
elif i == 1: elif i == 1:
# next try requesting header and block # next try requesting header and block
test_node.get_headers(locator=[old_tip], hashstop=tip) test_node.send_get_headers(locator=[old_tip], hashstop=tip)
test_node.get_data([tip]) test_node.send_get_data([tip])
test_node.wait_for_block(tip) test_node.wait_for_block(tip)
test_node.clear_last_announcement() # since we requested headers... test_node.clear_last_announcement() # since we requested headers...
elif i == 2: elif i == 2:
@ -297,13 +317,13 @@ class SendHeadersTest(BitcoinTestFramework):
# commence and keep working. # commence and keep working.
test_node.send_message(msg_sendheaders()) test_node.send_message(msg_sendheaders())
prev_tip = int(self.nodes[0].getbestblockhash(), 16) prev_tip = int(self.nodes[0].getbestblockhash(), 16)
test_node.get_headers(locator=[prev_tip], hashstop=0) test_node.send_get_headers(locator=[prev_tip], hashstop=0)
test_node.sync_with_ping() test_node.sync_with_ping()
# Now that we've synced headers, headers announcements should work # Now that we've synced headers, headers announcements should work
tip = self.mine_blocks(1) tip = self.mine_blocks(1)
assert_equal(inv_node.check_last_announcement(inv=[tip]), True) inv_node.check_last_announcement(inv=[tip], headers=[])
assert_equal(test_node.check_last_announcement(headers=[tip]), True) test_node.check_last_announcement(headers=[tip])
height = self.nodes[0].getblockcount() + 1 height = self.nodes[0].getblockcount() + 1
block_time += 10 # Advance far enough ahead block_time += 10 # Advance far enough ahead
@ -347,8 +367,8 @@ class SendHeadersTest(BitcoinTestFramework):
assert "inv" not in inv_node.last_message assert "inv" not in inv_node.last_message
assert "headers" not in inv_node.last_message assert "headers" not in inv_node.last_message
tip = self.mine_blocks(1) tip = self.mine_blocks(1)
assert_equal(inv_node.check_last_announcement(inv=[tip]), True) inv_node.check_last_announcement(inv=[tip], headers=[])
assert_equal(test_node.check_last_announcement(headers=[tip]), True) test_node.check_last_announcement(headers=[tip])
height += 1 height += 1
block_time += 1 block_time += 1
@ -362,16 +382,16 @@ class SendHeadersTest(BitcoinTestFramework):
# First try mining a reorg that can propagate with header announcement # First try mining a reorg that can propagate with header announcement
new_block_hashes = self.mine_reorg(length=7) new_block_hashes = self.mine_reorg(length=7)
tip = new_block_hashes[-1] tip = new_block_hashes[-1]
assert_equal(inv_node.check_last_announcement(inv=[tip]), True) inv_node.check_last_announcement(inv=[tip], headers=[])
assert_equal(test_node.check_last_announcement(headers=new_block_hashes), True) test_node.check_last_announcement(headers=new_block_hashes)
block_time += 8 block_time += 8
# Mine a too-large reorg, which should be announced with a single inv # Mine a too-large reorg, which should be announced with a single inv
new_block_hashes = self.mine_reorg(length=8) new_block_hashes = self.mine_reorg(length=8)
tip = new_block_hashes[-1] tip = new_block_hashes[-1]
assert_equal(inv_node.check_last_announcement(inv=[tip]), True) inv_node.check_last_announcement(inv=[tip], headers=[])
assert_equal(test_node.check_last_announcement(inv=[tip]), True) test_node.check_last_announcement(inv=[tip], headers=[])
block_time += 9 block_time += 9
@ -380,41 +400,41 @@ class SendHeadersTest(BitcoinTestFramework):
# Use getblocks/getdata # Use getblocks/getdata
test_node.send_getblocks(locator=[fork_point]) test_node.send_getblocks(locator=[fork_point])
assert_equal(test_node.check_last_announcement(inv=new_block_hashes), True) test_node.check_last_announcement(inv=new_block_hashes, headers=[])
test_node.get_data(new_block_hashes) test_node.send_get_data(new_block_hashes)
test_node.wait_for_block(new_block_hashes[-1]) test_node.wait_for_block(new_block_hashes[-1])
for i in range(3): for i in range(3):
# Mine another block, still should get only an inv # Mine another block, still should get only an inv
tip = self.mine_blocks(1) tip = self.mine_blocks(1)
assert_equal(inv_node.check_last_announcement(inv=[tip]), True) inv_node.check_last_announcement(inv=[tip], headers=[])
assert_equal(test_node.check_last_announcement(inv=[tip]), True) test_node.check_last_announcement(inv=[tip], headers=[])
if i == 0: if i == 0:
# Just get the data -- shouldn't cause headers announcements to resume # Just get the data -- shouldn't cause headers announcements to resume
test_node.get_data([tip]) test_node.send_get_data([tip])
test_node.wait_for_block(tip) test_node.wait_for_block(tip)
elif i == 1: elif i == 1:
# Send a getheaders message that shouldn't trigger headers announcements # Send a getheaders message that shouldn't trigger headers announcements
# to resume (best header sent will be too old) # to resume (best header sent will be too old)
test_node.get_headers(locator=[fork_point], hashstop=new_block_hashes[1]) test_node.send_get_headers(locator=[fork_point], hashstop=new_block_hashes[1])
test_node.get_data([tip]) test_node.send_get_data([tip])
test_node.wait_for_block(tip) test_node.wait_for_block(tip)
elif i == 2: elif i == 2:
test_node.get_data([tip]) test_node.send_get_data([tip])
test_node.wait_for_block(tip) test_node.wait_for_block(tip)
# This time, try sending either a getheaders to trigger resumption # This time, try sending either a getheaders to trigger resumption
# of headers announcements, or mine a new block and inv it, also # of headers announcements, or mine a new block and inv it, also
# triggering resumption of headers announcements. # triggering resumption of headers announcements.
if j == 0: if j == 0:
test_node.get_headers(locator=[tip], hashstop=0) test_node.send_get_headers(locator=[tip], hashstop=0)
test_node.sync_with_ping() test_node.sync_with_ping()
else: else:
test_node.send_block_inv(tip) test_node.send_block_inv(tip)
test_node.sync_with_ping() test_node.sync_with_ping()
# New blocks should now be announced with header # New blocks should now be announced with header
tip = self.mine_blocks(1) tip = self.mine_blocks(1)
assert_equal(inv_node.check_last_announcement(inv=[tip]), True) inv_node.check_last_announcement(inv=[tip], headers=[])
assert_equal(test_node.check_last_announcement(headers=[tip]), True) test_node.check_last_announcement(headers=[tip])
self.log.info("Part 3: success!") self.log.info("Part 3: success!")
@ -453,7 +473,7 @@ class SendHeadersTest(BitcoinTestFramework):
test_node.send_header_for_blocks(blocks) test_node.send_header_for_blocks(blocks)
test_node.sync_with_ping() test_node.sync_with_ping()
test_node.wait_for_getdata([x.sha256 for x in blocks], timeout=direct_fetch_response_time) test_node.wait_for_getdata([x.sha256 for x in blocks], timeout=DIRECT_FETCH_RESPONSE_TIME)
[test_node.send_message(msg_block(x)) for x in blocks] [test_node.send_message(msg_block(x)) for x in blocks]
@ -484,13 +504,13 @@ class SendHeadersTest(BitcoinTestFramework):
# both blocks (same work as tip) # both blocks (same work as tip)
test_node.send_header_for_blocks(blocks[1:2]) test_node.send_header_for_blocks(blocks[1:2])
test_node.sync_with_ping() test_node.sync_with_ping()
test_node.wait_for_getdata([x.sha256 for x in blocks[0:2]], timeout=direct_fetch_response_time) test_node.wait_for_getdata([x.sha256 for x in blocks[0:2]], timeout=DIRECT_FETCH_RESPONSE_TIME)
# Announcing 16 more headers should trigger direct fetch for 14 more # Announcing 16 more headers should trigger direct fetch for 14 more
# blocks # blocks
test_node.send_header_for_blocks(blocks[2:18]) test_node.send_header_for_blocks(blocks[2:18])
test_node.sync_with_ping() test_node.sync_with_ping()
test_node.wait_for_getdata([x.sha256 for x in blocks[2:16]], timeout=direct_fetch_response_time) test_node.wait_for_getdata([x.sha256 for x in blocks[2:16]], timeout=DIRECT_FETCH_RESPONSE_TIME)
# Announcing 1 more header should not trigger any response # Announcing 1 more header should not trigger any response
test_node.last_message.pop("getdata", None) test_node.last_message.pop("getdata", None)