Page MenuHomePhabricator

add loadtxoutset & getchainstates RPCs, add functional tests
ClosedPublic

Authored by PiRK on Mon, Apr 14, 19:11.

Details

Summary

This is a partial backport of core#27596, core#28652, core#29345, core#28589, core#28590, core#28625, core#28639, core#28647, core#28562, core#28666, core#28669, core#28685, core#29215, core#29726, core#29354, core#29394, core#29478, core#29370, core#29617, core#28685, core#30053, core#29973, core#28838, core#29354, core#29478, core#30678, core#31556 and core#30909

Depends on D17945


rpc: add loadtxoutset

Co-authored-by: Sebastian Falbesoner <sebastian.falbesoner@gmail.com>

https://github.com/bitcoin/bitcoin/pull/27596/commits/ce585a9a158476b0ad3296477b922e79f308e795
core#28652
core#29345


rpc: add getchainstates

Co-authored-by: Ryan Ofsky <ryan@ofsky.org>

https://github.com/bitcoin/bitcoin/pull/27596/commits/0f64bac6030334d798ae205cd7af4bf248feddd9
https://github.com/bitcoin/bitcoin/pull/28590/commits/a9ef702a877a964bac724a56e2c0b5bee4ea7586


test: add feature_assumeutxo functional test

Initial commit: https://github.com/bitcoin/bitcoin/pull/27596/commits/42cae39356fd20d521aaf99aff1ed85856f3c9f3

core#28589 (race fixes)
core#28590 (getchainstates return a list of chainstates)
core#28625 ( check that loading snapshot not matching AssumeUTXO parameters fails)
https://github.com/bitcoin/bitcoin/pull/28639/commits/fafde92f84fb7c245bc3c1cd946a32c891861e5e
core#28647 (Add assumeutxo test for wrong hash)
core#28652 (fail early if snapshot block hash doesn't match AssumeUTXO parameters)
core#28562 (self.no_op, self.wait_until)
core#28666 (assumeutxo file with unknown block hash)
core#28669 (check au file with changed outpoint index)
core#28685 (add tests for coin maleation)
core#29215 (spend coin from snapshot chainstate after loading)
https://github.com/bitcoin/bitcoin/pull/29726/commits/b7ba60f81a33db876f88b5f9af1e5025d679b5be (add coverage for -reindex and assumeutxo)
core#29354 (Assumeutxo with more than just coinbase transactions)
core#29394 (Add test to ensure failure when mempool not empty)
https://github.com/bitcoin/bitcoin/pull/29478/commits/2bc1ecfaa9b69a20388e913ec64967de2f506cd3 (Remove unnecessary sync_blocks in assumeutxo tests)
core#29478 (Add test for loadtxoutset when headers are not synced)
core#29370 (RPC test for fake nTx and nChainTX values, stale block CheckBlockIndex crash test & assumeutxo snapshot block CheckBlockIndex crash test)
core#29617 (test for coin_height > base_height & amount > money_supply)
https://github.com/bitcoin/bitcoin/pull/28685/commits/f6213929c519d0e615cacd3d6f479f1517be1662 (Check deserialized coins for out of range values)
core#30053 (coverage for "Couldn't open file..." error)
core#29973 (ensure failure when importing a snapshot twice)


test: add assumeutxo wallet test

initial commit: core#28838
https://github.com/bitcoin/bitcoin/pull/29354/commits/fa5cd66f0a47d1b759c93d01524ee4558432c0cc (Assumeutxo with more than just coinbase transactions)
https://github.com/bitcoin/bitcoin/pull/29478/commits/2bc1ecfaa9b69a20388e913ec64967de2f506cd3 (Remove unnecessary sync_blocks in assumeutxo tests)
https://github.com/bitcoin/bitcoin/pull/30678/commits/7e3dbe4180cbeb65e59b53d9fa98509e9189549d (functional test only)
https://github.com/bitcoin/bitcoin/pull/30678/commits/f20fe33e94c6752e5d2ed92511c0bf51a10716ee (Add basic balance coverage)
https://github.com/bitcoin/bitcoin/pull/31556/commits/bc43ecaf6dc0830a27296d3a29428814fed07bb1 (test for balance after snapshot completion)
https://github.com/bitcoin/bitcoin/pull/30909/commits/595edee169045b6735b76ff9721677f0e43f13e5 (import descriptors during background sync)

Test Plan

ninja all check-all

Event Timeline

There are a very large number of changes, so older changes are hidden. Show Older Changes
PiRK requested review of this revision.Mon, Apr 14, 19:11

Failed tests logs:

====== Bitcoin ABC functional tests: feature_assumeutxo.py ======

------- Stdout: -------
2025-04-14T19:20:32.450000Z TestFramework (INFO): Initializing test directory /work/abc-ci-builds/build-debug/test/tmp/test_runner_₿₵_🏃_20250414_191514/feature_assumeutxo_285
2025-04-14T19:20:34.136000Z TestFramework (INFO): -- Testing assumeutxo + some indexes + pruning
2025-04-14T19:20:34.137000Z TestFramework (INFO): Creating a UTXO snapshot at height 299
2025-04-14T19:20:34.184000Z TestFramework (INFO): Test loading snapshot when headers are not synced
2025-04-14T19:20:35.919000Z TestFramework (INFO): Test bitcoind should fail when mempool not empty.
2025-04-14T19:20:37.126000Z TestFramework (INFO): Test different scenarios of loading invalid snapshot files
2025-04-14T19:20:37.126000Z TestFramework (INFO):   - snapshot file refering to a block that is not in the assumeutxo parameters
2025-04-14T19:20:37.128000Z TestFramework (INFO):   - snapshot file with wrong number of coins
2025-04-14T19:20:37.423000Z TestFramework (INFO):   - snapshot file with alternated UTXO data
2025-04-14T19:20:38.134000Z TestFramework (INFO): Test bitcoind should fail when file path is invalid.
2025-04-14T19:20:38.135000Z TestFramework (INFO): Loading snapshot into second node from /work/abc-ci-builds/build-debug/test/tmp/test_runner_₿₵_🏃_20250414_191514/feature_assumeutxo_285/node0/regtest/utxos.dat
2025-04-14T19:20:38.484000Z TestFramework (INFO): Submit a stale block that forked off the chain before the snapshot
2025-04-14T19:20:38.492000Z TestFramework (INFO): Submit a spending transaction for a snapshot chainstate coin to the mempool
2025-04-14T19:20:38.503000Z TestFramework (INFO): Restarting node to stop at height 359
2025-04-14T19:20:40.410000Z TestFramework (INFO): Checking that blocks are segmented on disk
2025-04-14T19:20:40.410000Z TestFramework (INFO): Restarted node before snapshot validation completed, reloading...
2025-04-14T19:20:41.540000Z TestFramework (ERROR): Unexpected exception caught during testing
Traceback (most recent call last):
  File "/work/test/functional/test_framework/test_framework.py", line 152, in main
    self._run_test_internal()
  File "/work/test/functional/test_framework/test_framework.py", line 142, in _run_test_internal
    self.run_test()
  File "/work/test/functional/feature_assumeutxo.py", line 413, in run_test
    n1.submitblock(snapshot_block)
  File "/work/test/functional/test_framework/coverage.py", line 46, in __call__
    return_val = self.auth_service_proxy_instance.__call__(*args, **kwargs)
                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/authproxy.py", line 146, in __call__
    response, status = self._request(
                       ^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/authproxy.py", line 115, in _request
    return self._get_response()
           ^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/authproxy.py", line 187, in _get_response
    http_response = self.__conn.getresponse()
                    ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/http/client.py", line 1374, in getresponse
    response.begin()
  File "/usr/lib/python3.11/http/client.py", line 318, in begin
    version, status, reason = self._read_status()
                              ^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/http/client.py", line 287, in _read_status
    raise RemoteDisconnected("Remote end closed connection without"
http.client.RemoteDisconnected: Remote end closed connection without response
2025-04-14T19:20:41.592000Z TestFramework (INFO): Stopping nodes
[node 2] Cleaning up leftover process
[node 1] Cleaning up leftover process
[node 0] Cleaning up leftover process
------- Stderr: -------
Traceback (most recent call last):
  File "/work/test/functional/feature_assumeutxo.py", line 550, in <module>
    AssumeutxoTest().main()
  File "/work/test/functional/test_framework/test_framework.py", line 175, in main
    exit_code = self.shutdown()
                ^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/test_framework.py", line 404, in shutdown
    self.stop_nodes()
  File "/work/test/functional/test_framework/test_framework.py", line 659, in stop_nodes
    node.stop_node(wait=wait, wait_until_stopped=False)
  File "/work/test/functional/test_framework/test_node.py", line 532, in stop_node
    self.stop(wait=wait)
  File "/work/test/functional/test_framework/coverage.py", line 46, in __call__
    return_val = self.auth_service_proxy_instance.__call__(*args, **kwargs)
                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/authproxy.py", line 146, in __call__
    response, status = self._request(
                       ^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/authproxy.py", line 114, in _request
    self.__conn.request(method, path, postdata, headers)
  File "/usr/lib/python3.11/http/client.py", line 1282, in request
    self._send_request(method, url, body, headers, encode_chunked)
  File "/usr/lib/python3.11/http/client.py", line 1328, in _send_request
    self.endheaders(body, encode_chunked=encode_chunked)
  File "/usr/lib/python3.11/http/client.py", line 1277, in endheaders
    self._send_output(message_body, encode_chunked=encode_chunked)
  File "/usr/lib/python3.11/http/client.py", line 1037, in _send_output
    self.send(msg)
  File "/usr/lib/python3.11/http/client.py", line 975, in send
    self.connect()
  File "/usr/lib/python3.11/http/client.py", line 941, in connect
    self.sock = self._create_connection(
                ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/socket.py", line 851, in create_connection
    raise exceptions[0]
  File "/usr/lib/python3.11/socket.py", line 836, in create_connection
    sock.connect(sa)
ConnectionRefusedError: [Errno 111] Connection refused

Each failure log is accessible here:
Bitcoin ABC functional tests: feature_assumeutxo.py

Review suggestion:

check loadtxoutset against https://github.com/bitcoin/bitcoin/blob/faa30a4c566c5b720c7994c55f276352a119129f/src/rpc/blockchain.cpp

check feature_assumeutxo.py vs https://github.com/bitcoin/bitcoin/blob/b259b0e8d360726b062c4b0453d1cf5a68e1933f/test/functional/feature_assumeutxo.py

check wallet_assumeutxo.py vs https://github.com/bitcoin/bitcoin/blob/595edee169045b6735b76ff9721677f0e43f13e5/test/functional/wallet_assumeutxo.py

There are still additional tests and fixes to be included in the tests, but I wanted to limit the number of files changed in this diff. Following tests will depened on a change in format of the snapshot file after core#29612

PiRK planned changes to this revision.Mon, Apr 14, 19:23

fix release notes, investigate test failure on CI

PiRK edited the summary of this revision. (Show Details)

move release notes to proper file, split MiniWallet determinism into its own diff D17933, fix file permissions and shebangs for tests

Failed tests logs:

====== Bitcoin ABC functional tests: feature_assumeutxo.py ======

------- Stdout: -------
2025-04-15T07:12:41.104000Z TestFramework (INFO): Initializing test directory /work/abc-ci-builds/build-debug/test/tmp/test_runner_₿₵_🏃_20250415_070720/feature_assumeutxo_285
2025-04-15T07:12:42.980000Z TestFramework (INFO): -- Testing assumeutxo + some indexes + pruning
2025-04-15T07:12:42.981000Z TestFramework (INFO): Creating a UTXO snapshot at height 299
2025-04-15T07:12:43.017000Z TestFramework (INFO): Test loading snapshot when headers are not synced
2025-04-15T07:12:44.738000Z TestFramework (INFO): Test bitcoind should fail when mempool not empty.
2025-04-15T07:12:45.943000Z TestFramework (INFO): Test different scenarios of loading invalid snapshot files
2025-04-15T07:12:45.943000Z TestFramework (INFO):   - snapshot file refering to a block that is not in the assumeutxo parameters
2025-04-15T07:12:45.946000Z TestFramework (INFO):   - snapshot file with wrong number of coins
2025-04-15T07:12:46.239000Z TestFramework (INFO):   - snapshot file with alternated UTXO data
2025-04-15T07:12:46.956000Z TestFramework (INFO): Test bitcoind should fail when file path is invalid.
2025-04-15T07:12:46.957000Z TestFramework (INFO): Loading snapshot into second node from /work/abc-ci-builds/build-debug/test/tmp/test_runner_₿₵_🏃_20250415_070720/feature_assumeutxo_285/node0/regtest/utxos.dat
2025-04-15T07:12:47.219000Z TestFramework (INFO): Submit a stale block that forked off the chain before the snapshot
2025-04-15T07:12:47.228000Z TestFramework (INFO): Submit a spending transaction for a snapshot chainstate coin to the mempool
2025-04-15T07:12:47.239000Z TestFramework (INFO): Restarting node to stop at height 359
2025-04-15T07:12:49.348000Z TestFramework (INFO): Checking that blocks are segmented on disk
2025-04-15T07:12:49.348000Z TestFramework (INFO): Restarted node before snapshot validation completed, reloading...
2025-04-15T07:12:50.225000Z TestFramework (ERROR): Unexpected exception caught during testing
Traceback (most recent call last):
  File "/work/test/functional/test_framework/test_framework.py", line 152, in main
    self._run_test_internal()
  File "/work/test/functional/test_framework/test_framework.py", line 142, in _run_test_internal
    self.run_test()
  File "/work/test/functional/feature_assumeutxo.py", line 412, in run_test
    n1.submitblock(snapshot_block)
  File "/work/test/functional/test_framework/coverage.py", line 46, in __call__
    return_val = self.auth_service_proxy_instance.__call__(*args, **kwargs)
                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/authproxy.py", line 146, in __call__
    response, status = self._request(
                       ^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/authproxy.py", line 115, in _request
    return self._get_response()
           ^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/authproxy.py", line 187, in _get_response
    http_response = self.__conn.getresponse()
                    ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/http/client.py", line 1374, in getresponse
    response.begin()
  File "/usr/lib/python3.11/http/client.py", line 318, in begin
    version, status, reason = self._read_status()
                              ^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/http/client.py", line 287, in _read_status
    raise RemoteDisconnected("Remote end closed connection without"
http.client.RemoteDisconnected: Remote end closed connection without response
2025-04-15T07:12:50.276000Z TestFramework (INFO): Stopping nodes
[node 2] Cleaning up leftover process
[node 1] Cleaning up leftover process
[node 0] Cleaning up leftover process
------- Stderr: -------
Traceback (most recent call last):
  File "/work/test/functional/feature_assumeutxo.py", line 549, in <module>
    AssumeutxoTest().main()
  File "/work/test/functional/test_framework/test_framework.py", line 175, in main
    exit_code = self.shutdown()
                ^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/test_framework.py", line 404, in shutdown
    self.stop_nodes()
  File "/work/test/functional/test_framework/test_framework.py", line 659, in stop_nodes
    node.stop_node(wait=wait, wait_until_stopped=False)
  File "/work/test/functional/test_framework/test_node.py", line 532, in stop_node
    self.stop(wait=wait)
  File "/work/test/functional/test_framework/coverage.py", line 46, in __call__
    return_val = self.auth_service_proxy_instance.__call__(*args, **kwargs)
                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/authproxy.py", line 146, in __call__
    response, status = self._request(
                       ^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/authproxy.py", line 114, in _request
    self.__conn.request(method, path, postdata, headers)
  File "/usr/lib/python3.11/http/client.py", line 1282, in request
    self._send_request(method, url, body, headers, encode_chunked)
  File "/usr/lib/python3.11/http/client.py", line 1328, in _send_request
    self.endheaders(body, encode_chunked=encode_chunked)
  File "/usr/lib/python3.11/http/client.py", line 1277, in endheaders
    self._send_output(message_body, encode_chunked=encode_chunked)
  File "/usr/lib/python3.11/http/client.py", line 1037, in _send_output
    self.send(msg)
  File "/usr/lib/python3.11/http/client.py", line 975, in send
    self.connect()
  File "/usr/lib/python3.11/http/client.py", line 941, in connect
    self.sock = self._create_connection(
                ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/socket.py", line 851, in create_connection
    raise exceptions[0]
  File "/usr/lib/python3.11/socket.py", line 836, in create_connection
    sock.connect(sa)
ConnectionRefusedError: [Errno 111] Connection refused

Each failure log is accessible here:
Bitcoin ABC functional tests: feature_assumeutxo.py

test/functional/feature_assumeutxo.py
130 ↗(On Diff #53482)

Here and in the next case we differ from Core because for our utxo_snaphshot the first coin in the dump happens to be a coinbase coin, so "\x81" would be the correct value. "\x80" is the code for the same block height but no coinbase flag. "\x83" is the same coinbase flag but a different height (+1)

coin code = (height << 1) | is_coinbase

152 ↗(On Diff #53482)

Here the offset used by the original commit does not work for us, so I early backported a fix (offset = offset - 3) from https://github.com/bitcoin/bitcoin/pull/31907/commits/e5ff4e416ecc8a51367022eb8a7a291f8cbc0c65

See comment in the commit message:

In addition, the undocumented offset is set surprisingly high (39 bytes is well into the
serialization of the amount which starts at offset 36).

This would be after the core#29612 optimized the format of the snapshot, so for us it it offset 38 rather than 36

test/functional/wallet_assumeutxo.py
230–232 ↗(On Diff #53482)

This issue is likely caused by missing wallet backports, and has no direct influence on assumeutxo operations

PiRK planned changes to this revision.Tue, Apr 15, 07:21

still the debug failure to be investigated

Failed tests logs:

====== Bitcoin ABC functional tests: feature_assumeutxo.py ======

------- Stdout: -------
2025-04-16T12:06:01.745000Z TestFramework (INFO): Initializing test directory /work/abc-ci-builds/build-debug/test/tmp/test_runner_₿₵_🏃_20250416_120047/feature_assumeutxo_285
2025-04-16T12:06:03.439000Z TestFramework (INFO): -- Testing assumeutxo + some indexes + pruning
2025-04-16T12:06:03.440000Z TestFramework (INFO): Creating a UTXO snapshot at height 299
2025-04-16T12:06:03.473000Z TestFramework (INFO): Test loading snapshot when headers are not synced
2025-04-16T12:06:05.154000Z TestFramework (INFO): Test bitcoind should fail when mempool not empty.
2025-04-16T12:06:06.411000Z TestFramework (INFO): Test different scenarios of loading invalid snapshot files
2025-04-16T12:06:06.411000Z TestFramework (INFO):   - snapshot file refering to a block that is not in the assumeutxo parameters
2025-04-16T12:06:06.414000Z TestFramework (INFO):   - snapshot file with wrong number of coins
2025-04-16T12:06:06.708000Z TestFramework (INFO):   - snapshot file with alternated UTXO data
2025-04-16T12:06:07.485000Z TestFramework (INFO): Test bitcoind should fail when file path is invalid.
2025-04-16T12:06:07.486000Z TestFramework (INFO): Loading snapshot into second node from /work/abc-ci-builds/build-debug/test/tmp/test_runner_₿₵_🏃_20250416_120047/feature_assumeutxo_285/node0/regtest/utxos.dat
2025-04-16T12:06:07.762000Z TestFramework (INFO): Submit a stale block that forked off the chain before the snapshot
2025-04-16T12:06:07.770000Z TestFramework (INFO): Submit a spending transaction for a snapshot chainstate coin to the mempool
2025-04-16T12:06:07.781000Z TestFramework (INFO): Restarting node to stop at height 359
2025-04-16T12:06:10.039000Z TestFramework (INFO): Checking that blocks are segmented on disk
2025-04-16T12:06:10.039000Z TestFramework (INFO): Restarted node before snapshot validation completed, reloading...
2025-04-16T12:06:10.868000Z TestFramework (INFO): Ensuring snapshot chain syncs to tip. (399)
2025-04-16T12:06:11.301000Z TestFramework (INFO): Ensuring background validation completes
2025-04-16T12:07:07.745000Z TestFramework (INFO): Re-check nTx and nChainTx values
2025-04-16T12:07:07.867000Z TestFramework (INFO): Restarting node 0 to ensure (Check|Load)BlockIndex passes
2025-04-16T12:07:08.574000Z TestFramework (INFO): Restarting node 1 to ensure (Check|Load)BlockIndex passes
2025-04-16T12:07:09.737000Z TestFramework (INFO): -- Testing all indexes + reindex
2025-04-16T12:07:09.738000Z TestFramework (INFO): Loading snapshot into third node from /work/abc-ci-builds/build-debug/test/tmp/test_runner_₿₵_🏃_20250416_120047/feature_assumeutxo_285/node0/regtest/utxos.dat
2025-04-16T12:07:09.894000Z TestFramework (INFO): Check that restarting with -reindex=1 will delete the snapshot chainstate
2025-04-16T12:07:42.102000Z TestFramework (INFO): Check that restarting with -reindex-chainstate=1 will delete the snapshot chainstate
2025-04-16T12:07:46.651000Z TestFramework (INFO): Check that loading the snapshot again will fail because there is already an active snapshot.
2025-04-16T12:07:47.931000Z TestFramework (INFO): Ensuring background validation completes
2025-04-16T12:08:35.965000Z TestFramework (INFO): Restarting node 0 to ensure (Check|Load)BlockIndex passes
2025-04-16T12:08:36.884000Z TestFramework (INFO): Restarting node 2 to ensure (Check|Load)BlockIndex passes
2025-04-16T12:08:38.104000Z TestFramework (INFO): Test -reindex-chainstate of an assumeutxo-synced node
2025-04-16T12:08:40.168000Z TestFramework (INFO): Test -reindex of an assumeutxo-synced node
2025-04-16T12:09:41.133000Z TestFramework.utils (ERROR): wait_until() failed. Predicate: ''''
                    lambda: rpc.getmempoolinfo()["loaded"],
'''
2025-04-16T12:09:41.133000Z TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
  File "/work/test/functional/test_framework/test_framework.py", line 152, in main
    self._run_test_internal()
  File "/work/test/functional/test_framework/test_framework.py", line 142, in _run_test_internal
    self.run_test()
  File "/work/test/functional/feature_assumeutxo.py", line 536, in run_test
    self.restart_node(2, extra_args=["-reindex=1", *self.extra_args[2]])
  File "/work/test/functional/test_framework/test_framework.py", line 668, in restart_node
    self.start_node(i, extra_args)
  File "/work/test/functional/test_framework/test_framework.py", line 626, in start_node
    node.wait_for_rpc_connection()
  File "/work/test/functional/test_framework/test_node.py", line 386, in wait_for_rpc_connection
    wait_until_helper(
  File "/work/test/functional/test_framework/util.py", line 309, in wait_until_helper
    raise AssertionError(
AssertionError: Predicate ''''
                    lambda: rpc.getmempoolinfo()["loaded"],
''' not true after 60.0 seconds
2025-04-16T12:09:41.184000Z TestFramework (INFO): Stopping nodes
[node 2] Cleaning up leftover process
[node 1] Cleaning up leftover process
[node 0] Cleaning up leftover process
------- Stderr: -------
Traceback (most recent call last):
  File "/work/test/functional/feature_assumeutxo.py", line 549, in <module>
    AssumeutxoTest().main()
  File "/work/test/functional/test_framework/test_framework.py", line 175, in main
    exit_code = self.shutdown()
                ^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/test_framework.py", line 404, in shutdown
    self.stop_nodes()
  File "/work/test/functional/test_framework/test_framework.py", line 659, in stop_nodes
    node.stop_node(wait=wait, wait_until_stopped=False)
  File "/work/test/functional/test_framework/test_node.py", line 532, in stop_node
    self.stop(wait=wait)
    ^^^^^^^^^
  File "/work/test/functional/test_framework/test_node.py", line 287, in __getattr__
    assert self.rpc is not None, self._node_msg("Error: RPC not initialized")
           ^^^^^^^^^^^^^^^^^^^^
AssertionError: [node 2] Error: RPC not initialized

Each failure log is accessible here:
Bitcoin ABC functional tests: feature_assumeutxo.py

PiRK planned changes to this revision.Wed, Apr 16, 12:24

there is still something wrong. Either i didn't have Debug while testing, or Arcanist is confused by my rebasing

Failed tests logs:

====== Bitcoin ABC functional tests: feature_assumeutxo.py ======

------- Stdout: -------
2025-04-16T13:59:41.993000Z TestFramework (INFO): Initializing test directory /work/abc-ci-builds/build-debug/test/tmp/test_runner_₿₵_🏃_20250416_135352/feature_assumeutxo_285
2025-04-16T13:59:44.007000Z TestFramework (INFO): -- Testing assumeutxo + some indexes + pruning
2025-04-16T13:59:44.008000Z TestFramework (INFO): Creating a UTXO snapshot at height 299
2025-04-16T13:59:44.078000Z TestFramework (INFO): Test loading snapshot when headers are not synced
2025-04-16T13:59:45.791000Z TestFramework (INFO): Test bitcoind should fail when mempool not empty.
2025-04-16T13:59:47.384000Z TestFramework (INFO): Test different scenarios of loading invalid snapshot files
2025-04-16T13:59:47.384000Z TestFramework (INFO):   - snapshot file refering to a block that is not in the assumeutxo parameters
2025-04-16T13:59:47.386000Z TestFramework (INFO):   - snapshot file with wrong number of coins
2025-04-16T13:59:47.872000Z TestFramework (INFO):   - snapshot file with alternated UTXO data
2025-04-16T13:59:49.009000Z TestFramework (INFO): Test bitcoind should fail when file path is invalid.
2025-04-16T13:59:49.010000Z TestFramework (INFO): Loading snapshot into second node from /work/abc-ci-builds/build-debug/test/tmp/test_runner_₿₵_🏃_20250416_135352/feature_assumeutxo_285/node0/regtest/utxos.dat
2025-04-16T13:59:49.473000Z TestFramework (INFO): Submit a stale block that forked off the chain before the snapshot
2025-04-16T13:59:49.484000Z TestFramework (INFO): Submit a spending transaction for a snapshot chainstate coin to the mempool
2025-04-16T13:59:49.494000Z TestFramework (INFO): Restarting node to stop at height 359
2025-04-16T13:59:51.852000Z TestFramework (INFO): Checking that blocks are segmented on disk
2025-04-16T13:59:51.852000Z TestFramework (INFO): Restarted node before snapshot validation completed, reloading...
2025-04-16T13:59:53.183000Z TestFramework (INFO): Ensuring snapshot chain syncs to tip. (399)
2025-04-16T13:59:53.608000Z TestFramework (INFO): Ensuring background validation completes
2025-04-16T14:00:48.772000Z TestFramework (INFO): Re-check nTx and nChainTx values
2025-04-16T14:00:49.156000Z TestFramework (INFO): Restarting node 0 to ensure (Check|Load)BlockIndex passes
2025-04-16T14:00:50.128000Z TestFramework (INFO): Restarting node 1 to ensure (Check|Load)BlockIndex passes
2025-04-16T14:00:51.605000Z TestFramework (INFO): -- Testing all indexes + reindex
2025-04-16T14:00:51.608000Z TestFramework (INFO): Loading snapshot into third node from /work/abc-ci-builds/build-debug/test/tmp/test_runner_₿₵_🏃_20250416_135352/feature_assumeutxo_285/node0/regtest/utxos.dat
2025-04-16T14:00:51.847000Z TestFramework (INFO): Check that restarting with -reindex=1 will delete the snapshot chainstate
2025-04-16T14:01:24.215000Z TestFramework (INFO): Check that restarting with -reindex-chainstate=1 will delete the snapshot chainstate
2025-04-16T14:01:27.203000Z TestFramework (INFO): Check that loading the snapshot again will fail because there is already an active snapshot.
2025-04-16T14:01:28.341000Z TestFramework (INFO): Ensuring background validation completes
2025-04-16T14:02:16.218000Z TestFramework (INFO): Restarting node 0 to ensure (Check|Load)BlockIndex passes
2025-04-16T14:02:17.186000Z TestFramework (INFO): Restarting node 2 to ensure (Check|Load)BlockIndex passes
2025-04-16T14:02:18.613000Z TestFramework (INFO): Test -reindex-chainstate of an assumeutxo-synced node
2025-04-16T14:02:20.604000Z TestFramework (INFO): Test -reindex of an assumeutxo-synced node
2025-04-16T14:03:22.125000Z TestFramework.utils (ERROR): wait_until() failed. Predicate: ''''
                    lambda: rpc.getmempoolinfo()["loaded"],
'''
2025-04-16T14:03:22.125000Z TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
  File "/work/test/functional/test_framework/test_framework.py", line 152, in main
    self._run_test_internal()
  File "/work/test/functional/test_framework/test_framework.py", line 142, in _run_test_internal
    self.run_test()
  File "/work/test/functional/feature_assumeutxo.py", line 536, in run_test
    self.restart_node(2, extra_args=["-reindex=1", *self.extra_args[2]])
  File "/work/test/functional/test_framework/test_framework.py", line 668, in restart_node
    self.start_node(i, extra_args)
  File "/work/test/functional/test_framework/test_framework.py", line 626, in start_node
    node.wait_for_rpc_connection()
  File "/work/test/functional/test_framework/test_node.py", line 386, in wait_for_rpc_connection
    wait_until_helper(
  File "/work/test/functional/test_framework/util.py", line 309, in wait_until_helper
    raise AssertionError(
AssertionError: Predicate ''''
                    lambda: rpc.getmempoolinfo()["loaded"],
''' not true after 60.0 seconds
2025-04-16T14:03:22.188000Z TestFramework (INFO): Stopping nodes
[node 2] Cleaning up leftover process
[node 1] Cleaning up leftover process
[node 0] Cleaning up leftover process
------- Stderr: -------
Traceback (most recent call last):
  File "/work/test/functional/feature_assumeutxo.py", line 549, in <module>
    AssumeutxoTest().main()
  File "/work/test/functional/test_framework/test_framework.py", line 175, in main
    exit_code = self.shutdown()
                ^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/test_framework.py", line 404, in shutdown
    self.stop_nodes()
  File "/work/test/functional/test_framework/test_framework.py", line 659, in stop_nodes
    node.stop_node(wait=wait, wait_until_stopped=False)
  File "/work/test/functional/test_framework/test_node.py", line 532, in stop_node
    self.stop(wait=wait)
    ^^^^^^^^^
  File "/work/test/functional/test_framework/test_node.py", line 287, in __getattr__
    assert self.rpc is not None, self._node_msg("Error: RPC not initialized")
           ^^^^^^^^^^^^^^^^^^^^
AssertionError: [node 2] Error: RPC not initialized

Each failure log is accessible here:
Bitcoin ABC functional tests: feature_assumeutxo.py

let's try a larger timeout factor for the Debug build.
The test fails because the node restart with -reindex=1 is not done loading blocks after 60 s which triggers the assertions in test_node.py line 386

PiRK edited the summary of this revision. (Show Details)

rebase onto D17945

Fabien requested changes to this revision.Thu, Apr 17, 12:12
Fabien added a subscriber: Fabien.
Fabien added inline comments.
doc/release-notes.md
7 ↗(On Diff #53528)

This is not ready to be announced publicly until it's ready to be used by the node operators, aka when we have a snapshot hash in the codebase and a snapshot available for download, plus documentation.

24 ↗(On Diff #53528)

shouldn't we backport this doc as well ?

src/rpc/blockchain.cpp
2776 ↗(On Diff #53528)

same

2835 ↗(On Diff #53528)
2903 ↗(On Diff #53528)

can we call it chainstate ? cs looks like it's a lock (critical section)

test/functional/feature_assumeutxo.py
63 ↗(On Diff #53528)

that's the default

200 ↗(On Diff #53528)

ditto

403 ↗(On Diff #53528)

ditto

519 ↗(On Diff #53528)

ditto

test/functional/wallet_assumeutxo.py
208 ↗(On Diff #53528)

Let's avoid the low timeouts if possible, they tend to trigger random failures on CI

213 ↗(On Diff #53528)

ditto

This revision now requires changes to proceed.Thu, Apr 17, 12:12
doc/release-notes.md
24 ↗(On Diff #53528)

we have it, i just need to check if it is up to date

use bitcoinabc.org url for doc, don't set a short timeout in wait_until_stopped remove release notes, rename cs -> chainstate

fix placeholder text for relmease notes

src/rpc/blockchain.cpp
2776 ↗(On Diff #53534)

we need to remember to update this when this doc will be moved to doc/design

update syncing -> synced also in test

Failed tests logs:

====== Bitcoin ABC functional tests: feature_assumeutxo.py ======

------- Stdout: -------
2025-04-17T14:31:30.530000Z TestFramework (INFO): Initializing test directory /work/abc-ci-builds/build-without-wallet/test/tmp/test_runner_₿₵_🏃_20250417_142955/feature_assumeutxo_285
2025-04-17T14:31:31.368000Z TestFramework (INFO): -- Testing assumeutxo + some indexes + pruning
2025-04-17T14:31:31.369000Z TestFramework (INFO): Creating a UTXO snapshot at height 299
2025-04-17T14:31:31.390000Z TestFramework (INFO): Test loading snapshot when headers are not synced
2025-04-17T14:31:31.391000Z TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
  File "/work/test/functional/test_framework/util.py", line 146, in try_rpc
    fun(*args, **kwds)
  File "/work/test/functional/test_framework/coverage.py", line 46, in __call__
    return_val = self.auth_service_proxy_instance.__call__(*args, **kwargs)
                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/authproxy.py", line 150, in __call__
    raise JSONRPCException(response["error"], status)
test_framework.authproxy.JSONRPCException: The base block header (118a7d5473bccce9b314789e14ce426fc65fb09dfeda0131032bb6d86ed2fd0b) must appear in the headers chain. Make sure all headers are synced, and call this RPC again. (-32603)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/work/test/functional/test_framework/test_framework.py", line 152, in main
    self._run_test_internal()
  File "/work/test/functional/test_framework/test_framework.py", line 142, in _run_test_internal
    self.run_test()
  File "/work/test/functional/feature_assumeutxo.py", line 266, in run_test
    self.test_headers_not_synced(dump_output["path"])
  File "/work/test/functional/feature_assumeutxo.py", line 173, in test_headers_not_synced
    assert_raises_rpc_error(
  File "/work/test/functional/test_framework/util.py", line 137, in assert_raises_rpc_error
    assert try_rpc(code, message, fun, *args, **kwds), "No exception raised"
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/util.py", line 153, in try_rpc
    raise AssertionError(
AssertionError: Expected substring not found in error message:
substring: 'The base block header (118a7d5473bccce9b314789e14ce426fc65fb09dfeda0131032bb6d86ed2fd0b) must appear in the headers chain. Make sure all headers are syncing, and call this RPC again.'
error message: 'The base block header (118a7d5473bccce9b314789e14ce426fc65fb09dfeda0131032bb6d86ed2fd0b) must appear in the headers chain. Make sure all headers are synced, and call this RPC again.'.
2025-04-17T14:31:31.442000Z TestFramework (INFO): Stopping nodes
2025-04-17T14:31:31.644000Z TestFramework (WARNING): Not cleaning up dir /work/abc-ci-builds/build-without-wallet/test/tmp/test_runner_₿₵_🏃_20250417_142955/feature_assumeutxo_285
2025-04-17T14:31:31.644000Z TestFramework (ERROR): Test failed. Test logging available at /work/abc-ci-builds/build-without-wallet/test/tmp/test_runner_₿₵_🏃_20250417_142955/feature_assumeutxo_285/test_framework.log
2025-04-17T14:31:31.645000Z TestFramework (ERROR): 
2025-04-17T14:31:31.645000Z TestFramework (ERROR): Hint: Call /work/test/functional/combine_logs.py '/work/abc-ci-builds/build-without-wallet/test/tmp/test_runner_₿₵_🏃_20250417_142955/feature_assumeutxo_285' to consolidate all logs
2025-04-17T14:31:31.645000Z TestFramework (ERROR): 
2025-04-17T14:31:31.645000Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log.
2025-04-17T14:31:31.645000Z TestFramework (ERROR): https://github.com/Bitcoin-ABC/bitcoin-abc/issues
2025-04-17T14:31:31.645000Z TestFramework (ERROR):

Each failure log is accessible here:
Bitcoin ABC functional tests: feature_assumeutxo.py

Failed tests logs:

====== Bitcoin ABC functional tests: feature_assumeutxo.py ======

------- Stdout: -------
2025-04-17T14:31:09.148000Z TestFramework (INFO): Initializing test directory /work/abc-ci-builds/build-debug/test/tmp/test_runner_₿₵_🏃_20250417_142559/feature_assumeutxo_285
2025-04-17T14:31:10.882000Z TestFramework (INFO): -- Testing assumeutxo + some indexes + pruning
2025-04-17T14:31:10.883000Z TestFramework (INFO): Creating a UTXO snapshot at height 299
2025-04-17T14:31:10.916000Z TestFramework (INFO): Test loading snapshot when headers are not synced
2025-04-17T14:31:10.917000Z TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
  File "/work/test/functional/test_framework/util.py", line 146, in try_rpc
    fun(*args, **kwds)
  File "/work/test/functional/test_framework/coverage.py", line 46, in __call__
    return_val = self.auth_service_proxy_instance.__call__(*args, **kwargs)
                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/authproxy.py", line 150, in __call__
    raise JSONRPCException(response["error"], status)
test_framework.authproxy.JSONRPCException: The base block header (118a7d5473bccce9b314789e14ce426fc65fb09dfeda0131032bb6d86ed2fd0b) must appear in the headers chain. Make sure all headers are synced, and call this RPC again. (-32603)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/work/test/functional/test_framework/test_framework.py", line 152, in main
    self._run_test_internal()
  File "/work/test/functional/test_framework/test_framework.py", line 142, in _run_test_internal
    self.run_test()
  File "/work/test/functional/feature_assumeutxo.py", line 266, in run_test
    self.test_headers_not_synced(dump_output["path"])
  File "/work/test/functional/feature_assumeutxo.py", line 173, in test_headers_not_synced
    assert_raises_rpc_error(
  File "/work/test/functional/test_framework/util.py", line 137, in assert_raises_rpc_error
    assert try_rpc(code, message, fun, *args, **kwds), "No exception raised"
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/util.py", line 153, in try_rpc
    raise AssertionError(
AssertionError: Expected substring not found in error message:
substring: 'The base block header (118a7d5473bccce9b314789e14ce426fc65fb09dfeda0131032bb6d86ed2fd0b) must appear in the headers chain. Make sure all headers are syncing, and call this RPC again.'
error message: 'The base block header (118a7d5473bccce9b314789e14ce426fc65fb09dfeda0131032bb6d86ed2fd0b) must appear in the headers chain. Make sure all headers are synced, and call this RPC again.'.
2025-04-17T14:31:10.968000Z TestFramework (INFO): Stopping nodes
2025-04-17T14:31:11.221000Z TestFramework (WARNING): Not cleaning up dir /work/abc-ci-builds/build-debug/test/tmp/test_runner_₿₵_🏃_20250417_142559/feature_assumeutxo_285
2025-04-17T14:31:11.222000Z TestFramework (ERROR): Test failed. Test logging available at /work/abc-ci-builds/build-debug/test/tmp/test_runner_₿₵_🏃_20250417_142559/feature_assumeutxo_285/test_framework.log
2025-04-17T14:31:11.222000Z TestFramework (ERROR): 
2025-04-17T14:31:11.222000Z TestFramework (ERROR): Hint: Call /work/test/functional/combine_logs.py '/work/abc-ci-builds/build-debug/test/tmp/test_runner_₿₵_🏃_20250417_142559/feature_assumeutxo_285' to consolidate all logs
2025-04-17T14:31:11.222000Z TestFramework (ERROR): 
2025-04-17T14:31:11.222000Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log.
2025-04-17T14:31:11.222000Z TestFramework (ERROR): https://github.com/Bitcoin-ABC/bitcoin-abc/issues
2025-04-17T14:31:11.222000Z TestFramework (ERROR):

Each failure log is accessible here:
Bitcoin ABC functional tests: feature_assumeutxo.py

Failed tests logs:

====== Bitcoin ABC functional tests: feature_assumeutxo.py ======

------- Stdout: -------
2025-04-17T14:32:45.592000Z TestFramework (INFO): Initializing test directory /work/abc-ci-builds/build-diff/test/tmp/test_runner_₿₵_🏃_20250417_143017/feature_assumeutxo_285
2025-04-17T14:32:46.286000Z TestFramework (INFO): -- Testing assumeutxo + some indexes + pruning
2025-04-17T14:32:46.287000Z TestFramework (INFO): Creating a UTXO snapshot at height 299
2025-04-17T14:32:46.303000Z TestFramework (INFO): Test loading snapshot when headers are not synced
2025-04-17T14:32:46.304000Z TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
  File "/work/test/functional/test_framework/util.py", line 146, in try_rpc
    fun(*args, **kwds)
  File "/work/test/functional/test_framework/coverage.py", line 46, in __call__
    return_val = self.auth_service_proxy_instance.__call__(*args, **kwargs)
                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/authproxy.py", line 150, in __call__
    raise JSONRPCException(response["error"], status)
test_framework.authproxy.JSONRPCException: The base block header (118a7d5473bccce9b314789e14ce426fc65fb09dfeda0131032bb6d86ed2fd0b) must appear in the headers chain. Make sure all headers are synced, and call this RPC again. (-32603)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/work/test/functional/test_framework/test_framework.py", line 152, in main
    self._run_test_internal()
  File "/work/test/functional/test_framework/test_framework.py", line 142, in _run_test_internal
    self.run_test()
  File "/work/test/functional/feature_assumeutxo.py", line 266, in run_test
    self.test_headers_not_synced(dump_output["path"])
  File "/work/test/functional/feature_assumeutxo.py", line 173, in test_headers_not_synced
    assert_raises_rpc_error(
  File "/work/test/functional/test_framework/util.py", line 137, in assert_raises_rpc_error
    assert try_rpc(code, message, fun, *args, **kwds), "No exception raised"
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/util.py", line 153, in try_rpc
    raise AssertionError(
AssertionError: Expected substring not found in error message:
substring: 'The base block header (118a7d5473bccce9b314789e14ce426fc65fb09dfeda0131032bb6d86ed2fd0b) must appear in the headers chain. Make sure all headers are syncing, and call this RPC again.'
error message: 'The base block header (118a7d5473bccce9b314789e14ce426fc65fb09dfeda0131032bb6d86ed2fd0b) must appear in the headers chain. Make sure all headers are synced, and call this RPC again.'.
2025-04-17T14:32:46.355000Z TestFramework (INFO): Stopping nodes
2025-04-17T14:32:46.810000Z TestFramework (WARNING): Not cleaning up dir /work/abc-ci-builds/build-diff/test/tmp/test_runner_₿₵_🏃_20250417_143017/feature_assumeutxo_285
2025-04-17T14:32:46.810000Z TestFramework (ERROR): Test failed. Test logging available at /work/abc-ci-builds/build-diff/test/tmp/test_runner_₿₵_🏃_20250417_143017/feature_assumeutxo_285/test_framework.log
2025-04-17T14:32:46.810000Z TestFramework (ERROR): 
2025-04-17T14:32:46.811000Z TestFramework (ERROR): Hint: Call /work/test/functional/combine_logs.py '/work/abc-ci-builds/build-diff/test/tmp/test_runner_₿₵_🏃_20250417_143017/feature_assumeutxo_285' to consolidate all logs
2025-04-17T14:32:46.811000Z TestFramework (ERROR): 
2025-04-17T14:32:46.811000Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log.
2025-04-17T14:32:46.811000Z TestFramework (ERROR): https://github.com/Bitcoin-ABC/bitcoin-abc/issues
2025-04-17T14:32:46.811000Z TestFramework (ERROR):
====== Bitcoin ABC functional tests with the next upgrade activated: feature_assumeutxo.py ======

------- Stdout: -------
2025-04-17T14:34:42.975000Z TestFramework (INFO): Initializing test directory /work/abc-ci-builds/build-diff/test/tmp/test_runner_₿₵_🏃_20250417_143251/feature_assumeutxo_285
2025-04-17T14:34:43.684000Z TestFramework (INFO): -- Testing assumeutxo + some indexes + pruning
2025-04-17T14:34:43.685000Z TestFramework (INFO): Creating a UTXO snapshot at height 299
2025-04-17T14:34:43.790000Z TestFramework (INFO): Test loading snapshot when headers are not synced
2025-04-17T14:34:43.793000Z TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
  File "/work/test/functional/test_framework/util.py", line 146, in try_rpc
    fun(*args, **kwds)
  File "/work/test/functional/test_framework/coverage.py", line 46, in __call__
    return_val = self.auth_service_proxy_instance.__call__(*args, **kwargs)
                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/authproxy.py", line 150, in __call__
    raise JSONRPCException(response["error"], status)
test_framework.authproxy.JSONRPCException: The base block header (118a7d5473bccce9b314789e14ce426fc65fb09dfeda0131032bb6d86ed2fd0b) must appear in the headers chain. Make sure all headers are synced, and call this RPC again. (-32603)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/work/test/functional/test_framework/test_framework.py", line 152, in main
    self._run_test_internal()
  File "/work/test/functional/test_framework/test_framework.py", line 142, in _run_test_internal
    self.run_test()
  File "/work/test/functional/feature_assumeutxo.py", line 266, in run_test
    self.test_headers_not_synced(dump_output["path"])
  File "/work/test/functional/feature_assumeutxo.py", line 173, in test_headers_not_synced
    assert_raises_rpc_error(
  File "/work/test/functional/test_framework/util.py", line 137, in assert_raises_rpc_error
    assert try_rpc(code, message, fun, *args, **kwds), "No exception raised"
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/util.py", line 153, in try_rpc
    raise AssertionError(
AssertionError: Expected substring not found in error message:
substring: 'The base block header (118a7d5473bccce9b314789e14ce426fc65fb09dfeda0131032bb6d86ed2fd0b) must appear in the headers chain. Make sure all headers are syncing, and call this RPC again.'
error message: 'The base block header (118a7d5473bccce9b314789e14ce426fc65fb09dfeda0131032bb6d86ed2fd0b) must appear in the headers chain. Make sure all headers are synced, and call this RPC again.'.
2025-04-17T14:34:43.850000Z TestFramework (INFO): Stopping nodes
2025-04-17T14:34:44.010000Z TestFramework (WARNING): Not cleaning up dir /work/abc-ci-builds/build-diff/test/tmp/test_runner_₿₵_🏃_20250417_143251/feature_assumeutxo_285
2025-04-17T14:34:44.010000Z TestFramework (ERROR): Test failed. Test logging available at /work/abc-ci-builds/build-diff/test/tmp/test_runner_₿₵_🏃_20250417_143251/feature_assumeutxo_285/test_framework.log
2025-04-17T14:34:44.010000Z TestFramework (ERROR): 
2025-04-17T14:34:44.011000Z TestFramework (ERROR): Hint: Call /work/test/functional/combine_logs.py '/work/abc-ci-builds/build-diff/test/tmp/test_runner_₿₵_🏃_20250417_143251/feature_assumeutxo_285' to consolidate all logs
2025-04-17T14:34:44.011000Z TestFramework (ERROR): 
2025-04-17T14:34:44.011000Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log.
2025-04-17T14:34:44.011000Z TestFramework (ERROR): https://github.com/Bitcoin-ABC/bitcoin-abc/issues
2025-04-17T14:34:44.011000Z TestFramework (ERROR):

Each failure log is accessible here:
Bitcoin ABC functional tests: feature_assumeutxo.py
Bitcoin ABC functional tests with the next upgrade activated: feature_assumeutxo.py

Failed tests logs:

====== Bitcoin ABC functional tests: feature_assumeutxo.py ======

------- Stdout: -------
2025-04-17T14:40:23.542000Z TestFramework (INFO): Initializing test directory /work/abc-ci-builds/build-without-wallet/test/tmp/test_runner_₿₵_🏃_20250417_143856/feature_assumeutxo_285
2025-04-17T14:40:24.400000Z TestFramework (INFO): -- Testing assumeutxo + some indexes + pruning
2025-04-17T14:40:24.401000Z TestFramework (INFO): Creating a UTXO snapshot at height 299
2025-04-17T14:40:24.433000Z TestFramework (INFO): Test loading snapshot when headers are not synced
2025-04-17T14:40:24.433000Z TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
  File "/work/test/functional/test_framework/util.py", line 146, in try_rpc
    fun(*args, **kwds)
  File "/work/test/functional/test_framework/coverage.py", line 46, in __call__
    return_val = self.auth_service_proxy_instance.__call__(*args, **kwargs)
                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/authproxy.py", line 150, in __call__
    raise JSONRPCException(response["error"], status)
test_framework.authproxy.JSONRPCException: The base block header (118a7d5473bccce9b314789e14ce426fc65fb09dfeda0131032bb6d86ed2fd0b) must appear in the headers chain. Make sure all headers are synced, and call this RPC again. (-32603)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/work/test/functional/test_framework/test_framework.py", line 152, in main
    self._run_test_internal()
  File "/work/test/functional/test_framework/test_framework.py", line 142, in _run_test_internal
    self.run_test()
  File "/work/test/functional/feature_assumeutxo.py", line 266, in run_test
    self.test_headers_not_synced(dump_output["path"])
  File "/work/test/functional/feature_assumeutxo.py", line 173, in test_headers_not_synced
    assert_raises_rpc_error(
  File "/work/test/functional/test_framework/util.py", line 137, in assert_raises_rpc_error
    assert try_rpc(code, message, fun, *args, **kwds), "No exception raised"
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/util.py", line 153, in try_rpc
    raise AssertionError(
AssertionError: Expected substring not found in error message:
substring: 'The base block header (118a7d5473bccce9b314789e14ce426fc65fb09dfeda0131032bb6d86ed2fd0b) must appear in the headers chain. Make sure all headers are syncing, and call this RPC again.'
error message: 'The base block header (118a7d5473bccce9b314789e14ce426fc65fb09dfeda0131032bb6d86ed2fd0b) must appear in the headers chain. Make sure all headers are synced, and call this RPC again.'.
2025-04-17T14:40:24.485000Z TestFramework (INFO): Stopping nodes
2025-04-17T14:40:24.688000Z TestFramework (WARNING): Not cleaning up dir /work/abc-ci-builds/build-without-wallet/test/tmp/test_runner_₿₵_🏃_20250417_143856/feature_assumeutxo_285
2025-04-17T14:40:24.688000Z TestFramework (ERROR): Test failed. Test logging available at /work/abc-ci-builds/build-without-wallet/test/tmp/test_runner_₿₵_🏃_20250417_143856/feature_assumeutxo_285/test_framework.log
2025-04-17T14:40:24.688000Z TestFramework (ERROR): 
2025-04-17T14:40:24.689000Z TestFramework (ERROR): Hint: Call /work/test/functional/combine_logs.py '/work/abc-ci-builds/build-without-wallet/test/tmp/test_runner_₿₵_🏃_20250417_143856/feature_assumeutxo_285' to consolidate all logs
2025-04-17T14:40:24.689000Z TestFramework (ERROR): 
2025-04-17T14:40:24.689000Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log.
2025-04-17T14:40:24.689000Z TestFramework (ERROR): https://github.com/Bitcoin-ABC/bitcoin-abc/issues
2025-04-17T14:40:24.690000Z TestFramework (ERROR):

Each failure log is accessible here:
Bitcoin ABC functional tests: feature_assumeutxo.py

Fabien requested changes to this revision.Thu, Apr 17, 14:42
Fabien added inline comments.
src/rpc/blockchain.cpp
2776 ↗(On Diff #53535)
This revision now requires changes to proceed.Thu, Apr 17, 14:42

Failed tests logs:

====== Bitcoin ABC functional tests: feature_assumeutxo.py ======

------- Stdout: -------
2025-04-17T14:43:45.081000Z TestFramework (INFO): Initializing test directory /work/abc-ci-builds/build-debug/test/tmp/test_runner_₿₵_🏃_20250417_143816/feature_assumeutxo_285
2025-04-17T14:43:47.004000Z TestFramework (INFO): -- Testing assumeutxo + some indexes + pruning
2025-04-17T14:43:47.005000Z TestFramework (INFO): Creating a UTXO snapshot at height 299
2025-04-17T14:43:47.040000Z TestFramework (INFO): Test loading snapshot when headers are not synced
2025-04-17T14:43:47.041000Z TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
  File "/work/test/functional/test_framework/util.py", line 146, in try_rpc
    fun(*args, **kwds)
  File "/work/test/functional/test_framework/coverage.py", line 46, in __call__
    return_val = self.auth_service_proxy_instance.__call__(*args, **kwargs)
                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/authproxy.py", line 150, in __call__
    raise JSONRPCException(response["error"], status)
test_framework.authproxy.JSONRPCException: The base block header (118a7d5473bccce9b314789e14ce426fc65fb09dfeda0131032bb6d86ed2fd0b) must appear in the headers chain. Make sure all headers are synced, and call this RPC again. (-32603)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/work/test/functional/test_framework/test_framework.py", line 152, in main
    self._run_test_internal()
  File "/work/test/functional/test_framework/test_framework.py", line 142, in _run_test_internal
    self.run_test()
  File "/work/test/functional/feature_assumeutxo.py", line 266, in run_test
    self.test_headers_not_synced(dump_output["path"])
  File "/work/test/functional/feature_assumeutxo.py", line 173, in test_headers_not_synced
    assert_raises_rpc_error(
  File "/work/test/functional/test_framework/util.py", line 137, in assert_raises_rpc_error
    assert try_rpc(code, message, fun, *args, **kwds), "No exception raised"
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/util.py", line 153, in try_rpc
    raise AssertionError(
AssertionError: Expected substring not found in error message:
substring: 'The base block header (118a7d5473bccce9b314789e14ce426fc65fb09dfeda0131032bb6d86ed2fd0b) must appear in the headers chain. Make sure all headers are syncing, and call this RPC again.'
error message: 'The base block header (118a7d5473bccce9b314789e14ce426fc65fb09dfeda0131032bb6d86ed2fd0b) must appear in the headers chain. Make sure all headers are synced, and call this RPC again.'.
2025-04-17T14:43:47.092000Z TestFramework (INFO): Stopping nodes
2025-04-17T14:43:47.295000Z TestFramework (WARNING): Not cleaning up dir /work/abc-ci-builds/build-debug/test/tmp/test_runner_₿₵_🏃_20250417_143816/feature_assumeutxo_285
2025-04-17T14:43:47.295000Z TestFramework (ERROR): Test failed. Test logging available at /work/abc-ci-builds/build-debug/test/tmp/test_runner_₿₵_🏃_20250417_143816/feature_assumeutxo_285/test_framework.log
2025-04-17T14:43:47.295000Z TestFramework (ERROR): 
2025-04-17T14:43:47.295000Z TestFramework (ERROR): Hint: Call /work/test/functional/combine_logs.py '/work/abc-ci-builds/build-debug/test/tmp/test_runner_₿₵_🏃_20250417_143816/feature_assumeutxo_285' to consolidate all logs
2025-04-17T14:43:47.296000Z TestFramework (ERROR): 
2025-04-17T14:43:47.296000Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log.
2025-04-17T14:43:47.296000Z TestFramework (ERROR): https://github.com/Bitcoin-ABC/bitcoin-abc/issues
2025-04-17T14:43:47.296000Z TestFramework (ERROR):

Each failure log is accessible here:
Bitcoin ABC functional tests: feature_assumeutxo.py

Failed tests logs:

====== Bitcoin ABC functional tests: feature_assumeutxo.py ======

------- Stdout: -------
2025-04-17T14:41:07.178000Z TestFramework (INFO): Initializing test directory /work/abc-ci-builds/build-diff/test/tmp/test_runner_₿₵_🏃_20250417_143841/feature_assumeutxo_285
2025-04-17T14:41:07.951000Z TestFramework (INFO): -- Testing assumeutxo + some indexes + pruning
2025-04-17T14:41:07.955000Z TestFramework (INFO): Creating a UTXO snapshot at height 299
2025-04-17T14:41:07.969000Z TestFramework (INFO): Test loading snapshot when headers are not synced
2025-04-17T14:41:07.972000Z TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
  File "/work/test/functional/test_framework/util.py", line 146, in try_rpc
    fun(*args, **kwds)
  File "/work/test/functional/test_framework/coverage.py", line 46, in __call__
    return_val = self.auth_service_proxy_instance.__call__(*args, **kwargs)
                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/authproxy.py", line 150, in __call__
    raise JSONRPCException(response["error"], status)
test_framework.authproxy.JSONRPCException: The base block header (118a7d5473bccce9b314789e14ce426fc65fb09dfeda0131032bb6d86ed2fd0b) must appear in the headers chain. Make sure all headers are synced, and call this RPC again. (-32603)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/work/test/functional/test_framework/test_framework.py", line 152, in main
    self._run_test_internal()
  File "/work/test/functional/test_framework/test_framework.py", line 142, in _run_test_internal
    self.run_test()
  File "/work/test/functional/feature_assumeutxo.py", line 266, in run_test
    self.test_headers_not_synced(dump_output["path"])
  File "/work/test/functional/feature_assumeutxo.py", line 173, in test_headers_not_synced
    assert_raises_rpc_error(
  File "/work/test/functional/test_framework/util.py", line 137, in assert_raises_rpc_error
    assert try_rpc(code, message, fun, *args, **kwds), "No exception raised"
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/util.py", line 153, in try_rpc
    raise AssertionError(
AssertionError: Expected substring not found in error message:
substring: 'The base block header (118a7d5473bccce9b314789e14ce426fc65fb09dfeda0131032bb6d86ed2fd0b) must appear in the headers chain. Make sure all headers are syncing, and call this RPC again.'
error message: 'The base block header (118a7d5473bccce9b314789e14ce426fc65fb09dfeda0131032bb6d86ed2fd0b) must appear in the headers chain. Make sure all headers are synced, and call this RPC again.'.
2025-04-17T14:41:08.028000Z TestFramework (INFO): Stopping nodes
2025-04-17T14:41:08.233000Z TestFramework (WARNING): Not cleaning up dir /work/abc-ci-builds/build-diff/test/tmp/test_runner_₿₵_🏃_20250417_143841/feature_assumeutxo_285
2025-04-17T14:41:08.234000Z TestFramework (ERROR): Test failed. Test logging available at /work/abc-ci-builds/build-diff/test/tmp/test_runner_₿₵_🏃_20250417_143841/feature_assumeutxo_285/test_framework.log
2025-04-17T14:41:08.234000Z TestFramework (ERROR): 
2025-04-17T14:41:08.235000Z TestFramework (ERROR): Hint: Call /work/test/functional/combine_logs.py '/work/abc-ci-builds/build-diff/test/tmp/test_runner_₿₵_🏃_20250417_143841/feature_assumeutxo_285' to consolidate all logs
2025-04-17T14:41:08.235000Z TestFramework (ERROR): 
2025-04-17T14:41:08.235000Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log.
2025-04-17T14:41:08.235000Z TestFramework (ERROR): https://github.com/Bitcoin-ABC/bitcoin-abc/issues
2025-04-17T14:41:08.235000Z TestFramework (ERROR):
====== Bitcoin ABC functional tests with the next upgrade activated: feature_assumeutxo.py ======

------- Stdout: -------
2025-04-17T14:43:04.167000Z TestFramework (INFO): Initializing test directory /work/abc-ci-builds/build-diff/test/tmp/test_runner_₿₵_🏃_20250417_144112/feature_assumeutxo_285
2025-04-17T14:43:04.831000Z TestFramework (INFO): -- Testing assumeutxo + some indexes + pruning
2025-04-17T14:43:04.832000Z TestFramework (INFO): Creating a UTXO snapshot at height 299
2025-04-17T14:43:04.872000Z TestFramework (INFO): Test loading snapshot when headers are not synced
2025-04-17T14:43:04.873000Z TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
  File "/work/test/functional/test_framework/util.py", line 146, in try_rpc
    fun(*args, **kwds)
  File "/work/test/functional/test_framework/coverage.py", line 46, in __call__
    return_val = self.auth_service_proxy_instance.__call__(*args, **kwargs)
                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/authproxy.py", line 150, in __call__
    raise JSONRPCException(response["error"], status)
test_framework.authproxy.JSONRPCException: The base block header (118a7d5473bccce9b314789e14ce426fc65fb09dfeda0131032bb6d86ed2fd0b) must appear in the headers chain. Make sure all headers are synced, and call this RPC again. (-32603)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/work/test/functional/test_framework/test_framework.py", line 152, in main
    self._run_test_internal()
  File "/work/test/functional/test_framework/test_framework.py", line 142, in _run_test_internal
    self.run_test()
  File "/work/test/functional/feature_assumeutxo.py", line 266, in run_test
    self.test_headers_not_synced(dump_output["path"])
  File "/work/test/functional/feature_assumeutxo.py", line 173, in test_headers_not_synced
    assert_raises_rpc_error(
  File "/work/test/functional/test_framework/util.py", line 137, in assert_raises_rpc_error
    assert try_rpc(code, message, fun, *args, **kwds), "No exception raised"
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/util.py", line 153, in try_rpc
    raise AssertionError(
AssertionError: Expected substring not found in error message:
substring: 'The base block header (118a7d5473bccce9b314789e14ce426fc65fb09dfeda0131032bb6d86ed2fd0b) must appear in the headers chain. Make sure all headers are syncing, and call this RPC again.'
error message: 'The base block header (118a7d5473bccce9b314789e14ce426fc65fb09dfeda0131032bb6d86ed2fd0b) must appear in the headers chain. Make sure all headers are synced, and call this RPC again.'.
2025-04-17T14:43:04.924000Z TestFramework (INFO): Stopping nodes
2025-04-17T14:43:05.127000Z TestFramework (WARNING): Not cleaning up dir /work/abc-ci-builds/build-diff/test/tmp/test_runner_₿₵_🏃_20250417_144112/feature_assumeutxo_285
2025-04-17T14:43:05.127000Z TestFramework (ERROR): Test failed. Test logging available at /work/abc-ci-builds/build-diff/test/tmp/test_runner_₿₵_🏃_20250417_144112/feature_assumeutxo_285/test_framework.log
2025-04-17T14:43:05.127000Z TestFramework (ERROR): 
2025-04-17T14:43:05.127000Z TestFramework (ERROR): Hint: Call /work/test/functional/combine_logs.py '/work/abc-ci-builds/build-diff/test/tmp/test_runner_₿₵_🏃_20250417_144112/feature_assumeutxo_285' to consolidate all logs
2025-04-17T14:43:05.127000Z TestFramework (ERROR): 
2025-04-17T14:43:05.127000Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log.
2025-04-17T14:43:05.127000Z TestFramework (ERROR): https://github.com/Bitcoin-ABC/bitcoin-abc/issues
2025-04-17T14:43:05.127000Z TestFramework (ERROR):

Each failure log is accessible here:
Bitcoin ABC functional tests: feature_assumeutxo.py
Bitcoin ABC functional tests with the next upgrade activated: feature_assumeutxo.py

This revision is now accepted and ready to land.Thu, Apr 17, 18:25

rebase so i can do arc land --revision D17931 (apparently to force a revision the commit must match )

This revision was landed with ongoing or failed builds.Thu, Apr 17, 20:32
This revision was automatically updated to reflect the committed changes.