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
test: Test new header sync behavior in loadtxoutset #29478
Conversation
The following sections might be updated with supplementary metadata relevant to reviewers and maintainers. Code CoverageFor detailed information about the code coverage, see the test coverage report. ReviewsSee the guideline for information on the review process.
If your review is incorrectly listed, please react with 👎 to this comment and the bot will ignore it on the next update. ConflictsReviewers, this pull request conflicts with the following ones:
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. |
rebased |
The nodes are not connected at this point and no blocks have been mined, so it does not seem do anything
6dca647
to
fb77be6
Compare
🚧 At least one of the CI tasks failed. Make sure to run all tests locally, according to the Possibly this is due to a silent merge conflict (the changes in this pull request being Leave a comment here, if you need help tracking down a confusing failure. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
tACK 1ec6684
Since this PR is based on top of #29345, I've backed it out from src/rpc/blockchain.cpp
in order to hit the mentioned timeout
.
git log --oneline src/rpc/blockchain.cpp
faa30a4c56 (2401-rpc-loadtxoutset-) rpc: Do not wait for headers inside loadtxoutset
fa9108941f rpc: Fix race in loadtxoutset
git checkout fa9108941fa1a0e83484114e2d8a99d264c2ad09 -- src/rpc/blockchain.cpp
- Note: a reviewer could extend the timeout changing
self.rpc_timeout
ontest/functional/feature_assumeutxo.py
./test/functional/feature_assumeutxo.py
2024-02-27T16:30:31.156000Z TestFramework (INFO): PRNG seed is: 1857178557572365167
2024-02-27T16:30:31.157000Z TestFramework (INFO): Initializing test directory /tmp/bitcoin_func_test_7fznd8ax
2024-02-27T16:30:32.583000Z TestFramework (INFO): -- Testing assumeutxo + some indexes + pruning
2024-02-27T16:30:32.584000Z TestFramework (INFO): Creating a UTXO snapshot at height 299
2024-02-27T16:30:32.619000Z TestFramework (INFO): Test loading snapshot when headers are not synced
2024-02-27T16:31:32.679000Z TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
File "/home/pablo/workspace/bitcoin/test/functional/test_framework/authproxy.py", line 151, in _get_response
http_response = self.__conn.getresponse()
File "/usr/lib/python3.10/http/client.py", line 1375, in getresponse
response.begin()
File "/usr/lib/python3.10/http/client.py", line 318, in begin
version, status, reason = self._read_status()
File "/usr/lib/python3.10/http/client.py", line 279, in _read_status
line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
File "/usr/lib/python3.10/socket.py", line 705, in readinto
return self._sock.recv_into(b)
TimeoutError: timed out
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/home/pablo/workspace/bitcoin/test/functional/test_framework/util.py", line 140, in try_rpc
fun(*args, **kwds)
File "/home/pablo/workspace/bitcoin/test/functional/test_framework/coverage.py", line 50, in __call__
return_val = self.auth_service_proxy_instance.__call__(*args, **kwargs)
File "/home/pablo/workspace/bitcoin/test/functional/test_framework/authproxy.py", line 127, in __call__
response, status = self._request('POST', self.__url.path, postdata.encode('utf-8'))
File "/home/pablo/workspace/bitcoin/test/functional/test_framework/authproxy.py", line 106, in _request
return self._get_response()
File "/home/pablo/workspace/bitcoin/test/functional/test_framework/authproxy.py", line 153, in _get_response
raise JSONRPCException({
test_framework.authproxy.JSONRPCException: 'loadtxoutset' RPC took longer than 60.000000 seconds. Consider using larger timeout for calls that take longer to return. (-344)
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/home/pablo/workspace/bitcoin/test/functional/test_framework/test_framework.py", line 131, in main
self.run_test()
File "/home/pablo/workspace/bitcoin/./test/functional/feature_assumeutxo.py", line 191, in run_test
self.test_headers_not_synced(dump_output['path'])
File "/home/pablo/workspace/bitcoin/./test/functional/feature_assumeutxo.py", line 118, in test_headers_not_synced
assert_raises_rpc_error(-32603, "The base block header (3bb7ce5eba0be48939b7a521ac1ba9316afee2c7bada3a0cca24188e6d7d96c0) must appear in the headers chain. Make sure all headers are syncing, and call this RPC again.",
File "/home/pablo/workspace/bitcoin/test/functional/test_framework/util.py", line 131, in assert_raises_rpc_error
assert try_rpc(code, message, fun, *args, **kwds), "No exception raised"
File "/home/pablo/workspace/bitcoin/test/functional/test_framework/util.py", line 144, in try_rpc
raise AssertionError("Unexpected JSONRPC error code %i" % e.error["code"])
AssertionError: Unexpected JSONRPC error code -344
2024-02-27T16:31:32.741000Z TestFramework (INFO): Stopping nodes
2024-02-27T16:31:32.742000Z TestFramework.node1 (ERROR): Unable to stop node.
Traceback (most recent call last):
File "/home/pablo/workspace/bitcoin/test/functional/test_framework/test_node.py", line 377, in stop_node
self.stop(wait=wait)
File "/home/pablo/workspace/bitcoin/test/functional/test_framework/coverage.py", line 50, in __call__
return_val = self.auth_service_proxy_instance.__call__(*args, **kwargs)
File "/home/pablo/workspace/bitcoin/test/functional/test_framework/authproxy.py", line 127, in __call__
response, status = self._request('POST', self.__url.path, postdata.encode('utf-8'))
File "/home/pablo/workspace/bitcoin/test/functional/test_framework/authproxy.py", line 105, in _request
self.__conn.request(method, path, postdata, headers)
File "/usr/lib/python3.10/http/client.py", line 1283, in request
self._send_request(method, url, body, headers, encode_chunked)
File "/usr/lib/python3.10/http/client.py", line 1294, in _send_request
self.putrequest(method, url, **skips)
File "/usr/lib/python3.10/http/client.py", line 1120, in putrequest
raise CannotSendRequest(self.__state)
http.client.CannotSendRequest: Request-sent
2024-02-27T16:32:32.889000Z TestFramework.utils (ERROR): wait_until() failed. Predicate: ''''
self.wait_until(lambda: self.is_node_stopped(expected_ret_code=expected_ret_code, **kwargs), timeout=timeout)
'''
Traceback (most recent call last):
File "/home/pablo/workspace/bitcoin/./test/functional/feature_assumeutxo.py", line 370, in <module>
AssumeutxoTest().main()
File "/home/pablo/workspace/bitcoin/test/functional/test_framework/test_framework.py", line 154, in main
exit_code = self.shutdown()
File "/home/pablo/workspace/bitcoin/test/functional/test_framework/test_framework.py", line 313, in shutdown
self.stop_nodes()
File "/home/pablo/workspace/bitcoin/test/functional/test_framework/test_framework.py", line 578, in stop_nodes
node.wait_until_stopped()
File "/home/pablo/workspace/bitcoin/test/functional/test_framework/test_node.py", line 425, in wait_until_stopped
self.wait_until(lambda: self.is_node_stopped(expected_ret_code=expected_ret_code, **kwargs), timeout=timeout)
File "/home/pablo/workspace/bitcoin/test/functional/test_framework/test_node.py", line 802, in wait_until
return wait_until_helper_internal(test_function, timeout=timeout, timeout_factor=self.timeout_factor)
File "/home/pablo/workspace/bitcoin/test/functional/test_framework/util.py", line 276, in wait_until_helper_internal
raise AssertionError("Predicate {} not true after {} seconds".format(predicate_source, timeout))
AssertionError: Predicate ''''
self.wait_until(lambda: self.is_node_stopped(expected_ret_code=expected_ret_code, **kwargs), timeout=timeout)
''' not true after 60 seconds
[node 2] Cleaning up leftover process
[node 1] Cleaning up leftover process
lgtm |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
ACK 1ec6684
Looks good to me
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
ACK 1ec6684
block = n0.getblock(n0.getblockhash(i), 0) | ||
# make n1 and n2 aware of the new header, but don't give them the | ||
# block. | ||
n1.submitheader(block) | ||
n2.submitheader(block) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
nit: only fetching the headers rather than the full blocks seems to be sufficient here:
block = n0.getblock(n0.getblockhash(i), 0) | |
# make n1 and n2 aware of the new header, but don't give them the | |
# block. | |
n1.submitheader(block) | |
n2.submitheader(block) | |
block_header = n0.getblockheader(n0.getblockhash(i), verbose=False) | |
# make n1 and n2 aware of the new header, but don't give them the | |
# block. | |
n1.submitheader(block_header) | |
n2.submitheader(block_header) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I think that is already the case. Afaict getblock
with verbosity 0
returns the same result as getblockheader
with false
. Inspired me to suggest this: #29646.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I will look into this as a follow-up, potentially improving getblockheader too since it's confusing that this works
ACK 1ec6684 |
It adds a test for the change to
loadtxoutset
made in #29345. Before that change the test doesn't fail right away but times out after 10 minutes.Also removes a
sync_blocks
call that didn't seem to do anything valuable.