Saw 2 CI failures today with feature_blockfilterindex_prune.py at line 21 (the first assertion):
assert len(self.nodes[1].getblockfilter(self.nodes[1].getbestblockhash())['filter']) > 0
with
Filter not found. Block filters are still in the process of being indexed. (-1)
<details><summary>Full test log here.</summary><p>
199/201 - feature_blockfilterindex_prune.py failed, Duration: 3 s
stdout:
2021-02-24T18:28:47.665000Z TestFramework (INFO): Initializing test directory /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0
2021-02-24T18:28:49.005000Z TestFramework (INFO): check if we can access a blockfilter when pruning is enabled but no blocks are actually pruned
2021-02-24T18:28:49.026000Z TestFramework (ERROR): JSONRPC error
Traceback (most recent call last):
File "/tmp/cirrus-ci-build/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/test_framework/test_framework.py", line 127, in main
self.run_test()
File "/tmp/cirrus-ci-build/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/feature_blockfilterindex_prune.py", line 21, in run_test
assert len(self.nodes[1].getblockfilter(self.nodes[1].getbestblockhash())['filter']) > 0
File "/tmp/cirrus-ci-build/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/test_framework/coverage.py", line 47, in __call__
return_val = self.auth_service_proxy_instance.__call__(*args, **kwargs)
File "/tmp/cirrus-ci-build/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/test_framework/authproxy.py", line 146, in __call__
raise JSONRPCException(response['error'], status)
test_framework.authproxy.JSONRPCException: Filter not found. Block filters are still in the process of being indexed. (-1)
2021-02-24T18:28:49.039000Z TestFramework (INFO): Stopping nodes
2021-02-24T18:28:49.356000Z TestFramework (WARNING): Not cleaning up dir /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0
2021-02-24T18:28:49.356000Z TestFramework (ERROR): Test failed. Test logging available at /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/test_framework.log
2021-02-24T18:28:49.356000Z TestFramework (ERROR):
2021-02-24T18:28:49.356000Z TestFramework (ERROR): Hint: Call /tmp/cirrus-ci-build/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/combine_logs.py '/tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0' to consolidate all logs
2021-02-24T18:28:49.356000Z TestFramework (ERROR):
2021-02-24T18:28:49.357000Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log.
2021-02-24T18:28:49.357000Z TestFramework (ERROR): https://github.com/bitcoin/bitcoin/issues
2021-02-24T18:28:49.357000Z TestFramework (ERROR):
stderr:
Combine the logs and print the last 4000 lines ...
============
Combined log for /tmp/cirrus-ci-build/ci/scratch/test_runner//test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0:
============
test 2021-02-24T18:28:47.657000Z TestFramework (DEBUG): PRNG seed is: 5963659029097842856
test 2021-02-24T18:28:47.657000Z TestFramework (DEBUG): Setting up network thread
test 2021-02-24T18:28:47.665000Z TestFramework (INFO): Initializing test directory /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0
test 2021-02-24T18:28:47.666000Z TestFramework (DEBUG): Copy cache directory /tmp/cirrus-ci-build/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/cache/node0 to node 0
test 2021-02-24T18:28:47.709000Z TestFramework (DEBUG): Copy cache directory /tmp/cirrus-ci-build/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/cache/node0 to node 1
test 2021-02-24T18:28:47.789000Z TestFramework.node0 (DEBUG): bitcoind started, waiting for RPC to come up
test 2021-02-24T18:28:47.802000Z TestFramework.node1 (DEBUG): bitcoind started, waiting for RPC to come up
node0 2021-02-24T18:28:48.046999Z [init] [init.cpp:897] [InitLogging] Bitcoin Core version v21.99.0-a78c37d3c327 (release build)
node0 2021-02-24T18:28:48.047294Z [init] [init.cpp:808] [InitParameterInteraction] InitParameterInteraction: parameter interaction: -bind set -> setting -listen=1
node0 2021-02-24T18:28:48.053697Z [init] [init.cpp:1093] [AppInitParameterInteraction] Validating signatures for all blocks.
node0 2021-02-24T18:28:48.054248Z [init] [init.cpp:1104] [AppInitParameterInteraction] Setting nMinimumChainWork=0000000000000000000000000000000000000000000000000000000000000000
node0 2021-02-24T18:28:48.054405Z [init] [init.cpp:1130] [AppInitParameterInteraction] Block pruning enabled. Use RPC call pruneblockchain(height) to manually prune block and undo files.
node0 2021-02-24T18:28:48.054954Z [init] [init.cpp:1233] [AppInitSanityChecks] Using the 'sse4(1way),sse41(4way),avx2(8way)' SHA256 implementation
node0 2021-02-24T18:28:48.055050Z [init] [random.cpp:103] [ReportHardwareRand] Using RdRand as an additional entropy source
node1 2021-02-24T18:28:48.088807Z [init] [init.cpp:897] [InitLogging] Bitcoin Core version v21.99.0-a78c37d3c327 (release build)
node1 2021-02-24T18:28:48.089029Z [init] [init.cpp:808] [InitParameterInteraction] InitParameterInteraction: parameter interaction: -bind set -> setting -listen=1
node0 2021-02-24T18:28:48.094032Z [init] [init.cpp:1294] [AppInitMain] Default data directory /root/.bitcoin
node0 2021-02-24T18:28:48.094146Z [init] [init.cpp:1295] [AppInitMain] Using data directory /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node0/regtest
node0 2021-02-24T18:28:48.094255Z [init] [init.cpp:1300] [AppInitMain] Config file: /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node0/bitcoin.conf
node0 2021-02-24T18:28:48.094387Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: regtest="1"
node0 2021-02-24T18:28:48.094486Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] bind="127.0.0.1"
node0 2021-02-24T18:28:48.094539Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] discover="0"
node0 2021-02-24T18:28:48.094590Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] dnsseed="0"
node0 2021-02-24T18:28:48.094640Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] fallbackfee="0.0002"
node0 2021-02-24T18:28:48.094691Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] keypool="1"
node0 2021-02-24T18:28:48.094748Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] listenonion="0"
node0 2021-02-24T18:28:48.094813Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] natpmp="0"
node0 2021-02-24T18:28:48.094859Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] port="14000"
node0 2021-02-24T18:28:48.094921Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] printtoconsole="0"
node0 2021-02-24T18:28:48.094983Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] rpcport="19000"
node0 2021-02-24T18:28:48.095041Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] server="1"
node0 2021-02-24T18:28:48.095095Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] shrinkdebugfile="0"
node0 2021-02-24T18:28:48.095147Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] upnp="0"
node0 2021-02-24T18:28:48.095214Z [init] [util/system.cpp:1040] [logArgsPrefix] Command-line arg: datadir="/tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node0"
node0 2021-02-24T18:28:48.095271Z [init] [util/system.cpp:1040] [logArgsPrefix] Command-line arg: debug=""
node0 2021-02-24T18:28:48.095314Z [init] [util/system.cpp:1040] [logArgsPrefix] Command-line arg: debugexclude="libevent"
node0 2021-02-24T18:28:48.095380Z [init] [util/system.cpp:1040] [logArgsPrefix] Command-line arg: debugexclude="leveldb"
node0 2021-02-24T18:28:48.095435Z [init] [util/system.cpp:1040] [logArgsPrefix] Command-line arg: fastprune=""
node0 2021-02-24T18:28:48.095486Z [init] [util/system.cpp:1040] [logArgsPrefix] Command-line arg: logsourcelocations=""
node0 2021-02-24T18:28:48.095559Z [init] [util/system.cpp:1040] [logArgsPrefix] Command-line arg: logthreadnames=""
node0 2021-02-24T18:28:48.095618Z [init] [util/system.cpp:1040] [logArgsPrefix] Command-line arg: logtimemicros=""
node0 2021-02-24T18:28:48.095692Z [init] [util/system.cpp:1040] [logArgsPrefix] Command-line arg: prune="1"
node0 2021-02-24T18:28:48.095747Z [init] [util/system.cpp:1040] [logArgsPrefix] Command-line arg: uacomment="testnode0"
node0 2021-02-24T18:28:48.095829Z [init] [init.cpp:1312] [AppInitMain] Using at most 125 automatic connections (1048576 file descriptors available)
node1 2021-02-24T18:28:48.098383Z [init] [init.cpp:1093] [AppInitParameterInteraction] Validating signatures for all blocks.
node1 2021-02-24T18:28:48.098515Z [init] [init.cpp:1104] [AppInitParameterInteraction] Setting nMinimumChainWork=0000000000000000000000000000000000000000000000000000000000000000
node1 2021-02-24T18:28:48.098682Z [init] [init.cpp:1130] [AppInitParameterInteraction] Block pruning enabled. Use RPC call pruneblockchain(height) to manually prune block and undo files.
node1 2021-02-24T18:28:48.099240Z [init] [init.cpp:1233] [AppInitSanityChecks] Using the 'sse4(1way),sse41(4way),avx2(8way)' SHA256 implementation
node1 2021-02-24T18:28:48.099380Z [init] [random.cpp:103] [ReportHardwareRand] Using RdRand as an additional entropy source
node1 2021-02-24T18:28:48.131474Z [init] [init.cpp:1294] [AppInitMain] Default data directory /root/.bitcoin
node1 2021-02-24T18:28:48.131566Z [init] [init.cpp:1295] [AppInitMain] Using data directory /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node1/regtest
node1 2021-02-24T18:28:48.131664Z [init] [init.cpp:1300] [AppInitMain] Config file: /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node1/bitcoin.conf
node1 2021-02-24T18:28:48.131820Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: regtest="1"
node1 2021-02-24T18:28:48.131934Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] bind="127.0.0.1"
node1 2021-02-24T18:28:48.131993Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] discover="0"
node1 2021-02-24T18:28:48.132057Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] dnsseed="0"
node1 2021-02-24T18:28:48.132105Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] fallbackfee="0.0002"
node1 2021-02-24T18:28:48.132148Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] keypool="1"
node1 2021-02-24T18:28:48.132202Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] listenonion="0"
node1 2021-02-24T18:28:48.132259Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] natpmp="0"
node1 2021-02-24T18:28:48.132305Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] port="14001"
node1 2021-02-24T18:28:48.132371Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] printtoconsole="0"
node1 2021-02-24T18:28:48.132444Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] rpcport="19001"
node1 2021-02-24T18:28:48.132509Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] server="1"
node1 2021-02-24T18:28:48.132558Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] shrinkdebugfile="0"
node1 2021-02-24T18:28:48.132614Z [init] [util/system.cpp:1040] [logArgsPrefix] Config file arg: [regtest] upnp="0"
node1 2021-02-24T18:28:48.132672Z [init] [util/system.cpp:1040] [logArgsPrefix] Command-line arg: blockfilterindex="1"
node1 2021-02-24T18:28:48.132766Z [init] [util/system.cpp:1040] [logArgsPrefix] Command-line arg: datadir="/tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node1"
node1 2021-02-24T18:28:48.132828Z [init] [util/system.cpp:1040] [logArgsPrefix] Command-line arg: debug=""
node1 2021-02-24T18:28:48.132892Z [init] [util/system.cpp:1040] [logArgsPrefix] Command-line arg: debugexclude="libevent"
node1 2021-02-24T18:28:48.132949Z [init] [util/system.cpp:1040] [logArgsPrefix] Command-line arg: debugexclude="leveldb"
node1 2021-02-24T18:28:48.133014Z [init] [util/system.cpp:1040] [logArgsPrefix] Command-line arg: fastprune=""
node1 2021-02-24T18:28:48.133085Z [init] [util/system.cpp:1040] [logArgsPrefix] Command-line arg: logsourcelocations=""
node1 2021-02-24T18:28:48.133131Z [init] [util/system.cpp:1040] [logArgsPrefix] Command-line arg: logthreadnames=""
node1 2021-02-24T18:28:48.133222Z [init] [util/system.cpp:1040] [logArgsPrefix] Command-line arg: logtimemicros=""
node1 2021-02-24T18:28:48.133271Z [init] [util/system.cpp:1040] [logArgsPrefix] Command-line arg: prune="1"
node1 2021-02-24T18:28:48.141395Z [init] [util/system.cpp:1040] [logArgsPrefix] Command-line arg: uacomment="testnode1"
node1 2021-02-24T18:28:48.141548Z [init] [init.cpp:1312] [AppInitMain] Using at most 125 automatic connections (1048576 file descriptors available)
node0 2021-02-24T18:28:48.172331Z [init] [script/sigcache.cpp:102] [InitSignatureCache] Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
node1 2021-02-24T18:28:48.212897Z [init] [script/sigcache.cpp:102] [InitSignatureCache] Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
node0 2021-02-24T18:28:48.224590Z [init] [validation.cpp:1466] [InitScriptExecutionCache] Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
node0 2021-02-24T18:28:48.224750Z [init] [init.cpp:1339] [AppInitMain] Script verification uses 1 additional threads
node0 2021-02-24T18:28:48.236925Z [scheduler] [util/system.h:469] [TraceThread] scheduler thread start
node1 2021-02-24T18:28:48.305226Z [init] [validation.cpp:1466] [InitScriptExecutionCache] Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
node1 2021-02-24T18:28:48.305409Z [init] [init.cpp:1339] [AppInitMain] Script verification uses 1 additional threads
node1 2021-02-24T18:28:48.325779Z [scheduler] [util/system.h:469] [TraceThread] scheduler thread start
node0 2021-02-24T18:28:48.439618Z [init] [httpserver.cpp:181] [InitHTTPAllowList] Allowing HTTP connections from: 127.0.0.0/8 ::1/128
node0 2021-02-24T18:28:48.439871Z [init] [httpserver.cpp:317] [HTTPBindAddresses] Binding RPC on address ::1 port 19000
node0 2021-02-24T18:28:48.440112Z [init] [httpserver.cpp:317] [HTTPBindAddresses] Binding RPC on address 127.0.0.1 port 19000
node0 2021-02-24T18:28:48.440241Z [init] [httpserver.cpp:392] [InitHTTPServer] Initialized HTTP server
node0 2021-02-24T18:28:48.440318Z [init] [httpserver.cpp:394] [InitHTTPServer] HTTP: creating work queue of depth 16
node0 2021-02-24T18:28:48.440365Z [init] [rpc/server.cpp:291] [StartRPC] Starting RPC
node0 2021-02-24T18:28:48.440556Z [init] [httprpc.cpp:293] [StartHTTPRPC] Starting HTTP RPC server
node0 2021-02-24T18:28:48.440626Z [init] [httprpc.cpp:245] [InitRPCAuthentication] Using random cookie authentication.
node0 2021-02-24T18:28:48.440946Z [init] [rpc/request.cpp:101] [GenerateAuthCookie] Generated RPC authentication cookie /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node0/regtest/.cookie
node0 2021-02-24T18:28:48.441061Z [init] [httpserver.cpp:636] [RegisterHTTPHandler] Registering HTTP handler for / (exactmatch 1)
node0 2021-02-24T18:28:48.441120Z [init] [httpserver.cpp:636] [RegisterHTTPHandler] Registering HTTP handler for /wallet/ (exactmatch 0)
node0 2021-02-24T18:28:48.441188Z [init] [httpserver.cpp:422] [StartHTTPServer] Starting HTTP server
node0 2021-02-24T18:28:48.441236Z [init] [httpserver.cpp:424] [StartHTTPServer] HTTP: starting 4 worker threads
node0 2021-02-24T18:28:48.451731Z [http] [httpserver.cpp:283] [ThreadHTTP] Entering http event loop
node0 2021-02-24T18:28:48.468907Z [init] [wallet/load.cpp:40] [VerifyWallets] Using wallet directory /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node0/regtest
node0 2021-02-24T18:28:48.469012Z [init] [noui.cpp:56] [noui_InitMessage] init message: Verifying wallet(s)...
node0 2021-02-24T18:28:48.470325Z [init] [noui.cpp:56] [noui_InitMessage] init message: Loading banlist...
node0 2021-02-24T18:28:48.470478Z [init] [addrdb.cpp:115] [DeserializeFileDB] Missing or invalid file /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node0/regtest/banlist.dat
node0 2021-02-24T18:28:48.470520Z [init] [banman.cpp:31] [BanMan] Recreating banlist.dat
node0 2021-02-24T18:28:48.476495Z [init] [banman.cpp:57] [DumpBanlist] Flushed 0 banned node ips/subnets to banlist.dat 6ms
node0 2021-02-24T18:28:48.477399Z [init] [net.cpp:1690] [SetTryNewOutboundPeer] net: setting try another outbound peer=false
node0 2021-02-24T18:28:48.477506Z [init] [net.cpp:2292] [SetNetworkActive] SetNetworkActive: true
node0 2021-02-24T18:28:48.480739Z [init] [policy/fees.cpp:510] [CBlockPolicyEstimator] Failed to read fee estimates from /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node0/regtest/fee_estimates.dat. Continue anyway.
node1 2021-02-24T18:28:48.487186Z [init] [httpserver.cpp:181] [InitHTTPAllowList] Allowing HTTP connections from: 127.0.0.0/8 ::1/128
node1 2021-02-24T18:28:48.487432Z [init] [httpserver.cpp:317] [HTTPBindAddresses] Binding RPC on address ::1 port 19001
node1 2021-02-24T18:28:48.487663Z [init] [httpserver.cpp:317] [HTTPBindAddresses] Binding RPC on address 127.0.0.1 port 19001
node1 2021-02-24T18:28:48.487779Z [init] [httpserver.cpp:392] [InitHTTPServer] Initialized HTTP server
node1 2021-02-24T18:28:48.487855Z [init] [httpserver.cpp:394] [InitHTTPServer] HTTP: creating work queue of depth 16
node1 2021-02-24T18:28:48.487901Z [init] [rpc/server.cpp:291] [StartRPC] Starting RPC
node1 2021-02-24T18:28:48.488089Z [init] [httprpc.cpp:293] [StartHTTPRPC] Starting HTTP RPC server
node1 2021-02-24T18:28:48.488169Z [init] [httprpc.cpp:245] [InitRPCAuthentication] Using random cookie authentication.
node1 2021-02-24T18:28:48.488455Z [init] [rpc/request.cpp:101] [GenerateAuthCookie] Generated RPC authentication cookie /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node1/regtest/.cookie
node1 2021-02-24T18:28:48.488565Z [init] [httpserver.cpp:636] [RegisterHTTPHandler] Registering HTTP handler for / (exactmatch 1)
node1 2021-02-24T18:28:48.488622Z [init] [httpserver.cpp:636] [RegisterHTTPHandler] Registering HTTP handler for /wallet/ (exactmatch 0)
node1 2021-02-24T18:28:48.488679Z [init] [httpserver.cpp:422] [StartHTTPServer] Starting HTTP server
node1 2021-02-24T18:28:48.488736Z [init] [httpserver.cpp:424] [StartHTTPServer] HTTP: starting 4 worker threads
node0 2021-02-24T18:28:48.489626Z [init] [init.cpp:1523] [AppInitMain] Using /16 prefix for IP bucketing
node0 2021-02-24T18:28:48.489811Z [init] [init.cpp:1559] [AppInitMain] Cache configuration:
node0 2021-02-24T18:28:48.489928Z [init] [init.cpp:1560] [AppInitMain] * Using 2.0 MiB for block index database
node0 2021-02-24T18:28:48.489993Z [init] [init.cpp:1568] [AppInitMain] * Using 8.0 MiB for chain state database
node0 2021-02-24T18:28:48.490043Z [init] [init.cpp:1569] [AppInitMain] * Using 440.0 MiB for in-memory UTXO set (plus up to 286.1 MiB of unused mempool space)
node0 2021-02-24T18:28:48.490138Z [init] [noui.cpp:56] [noui_InitMessage] init message: Loading block index...
node0 2021-02-24T18:28:48.490256Z [init] [validation.cpp:5236] [InitializeChainstate] Switching active chainstate to Chainstate [ibd] @ height -1 (null)
node0 2021-02-24T18:28:48.490545Z [init] [dbwrapper.cpp:137] [CDBWrapper] Opening LevelDB in /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node0/regtest/blocks/index
node1 2021-02-24T18:28:48.495291Z [http] [httpserver.cpp:283] [ThreadHTTP] Entering http event loop
node0 2021-02-24T18:28:48.514622Z [init] [dbwrapper.cpp:141] [CDBWrapper] Opened LevelDB successfully
node0 2021-02-24T18:28:48.514816Z [init] [dbwrapper.cpp:166] [CDBWrapper] Using obfuscation key for /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node0/regtest/blocks/index: 0000000000000000
node0 2021-02-24T18:28:48.522028Z [init] [validation.cpp:4154] [LoadBlockIndexDB] LoadBlockIndexDB: last block file = 0
node0 2021-02-24T18:28:48.522207Z [init] [validation.cpp:4158] [LoadBlockIndexDB] LoadBlockIndexDB: last block file info: CBlockFileInfo(blocks=200, size=52288, heights=0...199, time=2011-02-02...2011-02-02)
node0 2021-02-24T18:28:48.522270Z [init] [validation.cpp:4169] [LoadBlockIndexDB] Checking all blk files are present...
node0 2021-02-24T18:28:48.522612Z [init] [dbwrapper.cpp:137] [CDBWrapper] Opening LevelDB in /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node0/regtest/chainstate
node1 2021-02-24T18:28:48.529539Z [init] [wallet/load.cpp:40] [VerifyWallets] Using wallet directory /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node1/regtest
node1 2021-02-24T18:28:48.529644Z [init] [noui.cpp:56] [noui_InitMessage] init message: Verifying wallet(s)...
node1 2021-02-24T18:28:48.530823Z [init] [noui.cpp:56] [noui_InitMessage] init message: Loading banlist...
node1 2021-02-24T18:28:48.530931Z [init] [addrdb.cpp:115] [DeserializeFileDB] Missing or invalid file /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node1/regtest/banlist.dat
node1 2021-02-24T18:28:48.530970Z [init] [banman.cpp:31] [BanMan] Recreating banlist.dat
node1 2021-02-24T18:28:48.533155Z [init] [banman.cpp:57] [DumpBanlist] Flushed 0 banned node ips/subnets to banlist.dat 2ms
node1 2021-02-24T18:28:48.534055Z [init] [net.cpp:1690] [SetTryNewOutboundPeer] net: setting try another outbound peer=false
node1 2021-02-24T18:28:48.534137Z [init] [net.cpp:2292] [SetNetworkActive] SetNetworkActive: true
node1 2021-02-24T18:28:48.537024Z [init] [policy/fees.cpp:510] [CBlockPolicyEstimator] Failed to read fee estimates from /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node1/regtest/fee_estimates.dat. Continue anyway.
node1 2021-02-24T18:28:48.540250Z [init] [init.cpp:1523] [AppInitMain] Using /16 prefix for IP bucketing
node1 2021-02-24T18:28:48.540453Z [init] [init.cpp:1559] [AppInitMain] Cache configuration:
node1 2021-02-24T18:28:48.540524Z [init] [init.cpp:1560] [AppInitMain] * Using 2.0 MiB for block index database
node1 2021-02-24T18:28:48.540594Z [init] [init.cpp:1566] [AppInitMain] * Using 56.0 MiB for basic block filter index database
node1 2021-02-24T18:28:48.540645Z [init] [init.cpp:1568] [AppInitMain] * Using 8.0 MiB for chain state database
node1 2021-02-24T18:28:48.540690Z [init] [init.cpp:1569] [AppInitMain] * Using 384.0 MiB for in-memory UTXO set (plus up to 286.1 MiB of unused mempool space)
node1 2021-02-24T18:28:48.540757Z [init] [noui.cpp:56] [noui_InitMessage] init message: Loading block index...
node1 2021-02-24T18:28:48.540860Z [init] [validation.cpp:5236] [InitializeChainstate] Switching active chainstate to Chainstate [ibd] @ height -1 (null)
node1 2021-02-24T18:28:48.541123Z [init] [dbwrapper.cpp:137] [CDBWrapper] Opening LevelDB in /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node1/regtest/blocks/index
node0 2021-02-24T18:28:48.548152Z [init] [dbwrapper.cpp:141] [CDBWrapper] Opened LevelDB successfully
node0 2021-02-24T18:28:48.548383Z [init] [dbwrapper.cpp:166] [CDBWrapper] Using obfuscation key for /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node0/regtest/chainstate: 714ee4f13ab12c72
node0 2021-02-24T18:28:48.549167Z [init] [validation.cpp:4231] [LoadChainTip] Loaded best chain: hashBestChain=7bdb817a7584c107fca42ca79286fa34a84cc3e9e930cbad38f7d4e3a0c56ca2 height=199 date=2011-02-02T23:17:17Z progress=1.000000
node0 2021-02-24T18:28:48.549295Z [init] [noui.cpp:56] [noui_InitMessage] init message: Rewinding blocks...
node0 2021-02-24T18:28:48.550252Z [init] [logging/timer.h:50] [Log] FlushStateToDisk: write block and undo data to disk started
node0 2021-02-24T18:28:48.570275Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:43840
node0 2021-02-24T18:28:48.570733Z [httpworker.0] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockcount user=__cookie__
node0 2021-02-24T18:28:48.581520Z [init] [logging/timer.h:50] [Log] FlushStateToDisk: write block and undo data to disk completed (31.17ms)
node0 2021-02-24T18:28:48.581665Z [init] [logging/timer.h:50] [Log] FlushStateToDisk: write block index to disk started
node0 2021-02-24T18:28:48.583836Z [init] [logging/timer.h:50] [Log] FlushStateToDisk: write block index to disk completed (2.09ms)
node0 2021-02-24T18:28:48.583924Z [init] [logging/timer.h:48] [Log] FlushStateToDisk: write coins cache to disk (0 coins, 0kB) started
node0 2021-02-24T18:28:48.584162Z [init] [txdb.cpp:139] [BatchWrite] Writing final batch of 0.00 MiB
node0 2021-02-24T18:28:48.584485Z [init] [txdb.cpp:141] [BatchWrite] Committed 0 changed transaction outputs (out of 0) to coin database...
node0 2021-02-24T18:28:48.584558Z [init] [logging/timer.h:48] [Log] FlushStateToDisk: write coins cache to disk (0 coins, 0kB) completed (0.00s)
node0 2021-02-24T18:28:48.584656Z [init] [validationinterface.cpp:244] [ChainStateFlushed] Enqueuing ChainStateFlushed: block hash=7bdb817a7584c107fca42ca79286fa34a84cc3e9e930cbad38f7d4e3a0c56ca2
node0 2021-02-24T18:28:48.584873Z [init] [noui.cpp:56] [noui_InitMessage] init message: Verifying blocks...
node0 2021-02-24T18:28:48.584994Z [scheduler] [validationinterface.cpp:244] [operator()] ChainStateFlushed: block hash=7bdb817a7584c107fca42ca79286fa34a84cc3e9e930cbad38f7d4e3a0c56ca2
node0 2021-02-24T18:28:48.585317Z [init] [validation.cpp:4255] [VerifyDB] Verifying last 6 blocks at level 3
node0 2021-02-24T18:28:48.585458Z [init] [validation.cpp:4262] [VerifyDB] [0%]...[16%]...[33%]...[50%]...[66%]...[83%]...[99%]...[DONE].
node0 2021-02-24T18:28:48.588419Z [init] [validation.cpp:4338] [VerifyDB] No coin database inconsistencies in last 6 blocks (6 transactions)
node0 2021-02-24T18:28:48.588509Z [init] [init.cpp:1762] [AppInitMain] block index 98ms
node0 2021-02-24T18:28:48.588608Z [init] [init.cpp:1817] [AppInitMain] Unsetting NODE_NETWORK on prune mode
node0 2021-02-24T18:28:48.588680Z [init] [noui.cpp:56] [noui_InitMessage] init message: Pruning blockstore...
node0 2021-02-24T18:28:48.588797Z [init] [logging/timer.h:50] [Log] FlushStateToDisk: find files to prune started
node0 2021-02-24T18:28:48.588892Z [init] [validation.cpp:4030] [FindFilesToPrune] Prune: target=17592186044415MiB actual=0MiB diff=0MiB max_prune_height=4294967207 removed 0 blk/rev pairs
node0 2021-02-24T18:28:48.588969Z [init] [logging/timer.h:50] [Log] FlushStateToDisk: find files to prune completed (0.11ms)
node1 2021-02-24T18:28:48.593257Z [init] [dbwrapper.cpp:141] [CDBWrapper] Opened LevelDB successfully
node1 2021-02-24T18:28:48.593474Z [init] [dbwrapper.cpp:166] [CDBWrapper] Using obfuscation key for /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node1/regtest/blocks/index: 0000000000000000
node1 2021-02-24T18:28:48.600743Z [init] [validation.cpp:4154] [LoadBlockIndexDB] LoadBlockIndexDB: last block file = 0
node1 2021-02-24T18:28:48.600930Z [init] [validation.cpp:4158] [LoadBlockIndexDB] LoadBlockIndexDB: last block file info: CBlockFileInfo(blocks=200, size=52288, heights=0...199, time=2011-02-02...2011-02-02)
node1 2021-02-24T18:28:48.600998Z [init] [validation.cpp:4169] [LoadBlockIndexDB] Checking all blk files are present...
node0 2021-02-24T18:28:48.602437Z [loadblk] [util/system.h:469] [TraceThread] loadblk thread start
node0 2021-02-24T18:28:48.602860Z [loadblk] [validation.cpp:5039] [LoadMempool] Failed to open mempool file from disk. Continuing anyway.
node0 2021-02-24T18:28:48.602953Z [loadblk] [util/system.h:471] [TraceThread] loadblk thread exit
node0 2021-02-24T18:28:48.605459Z [init] [init.cpp:1899] [AppInitMain] block tree size = 200
node0 2021-02-24T18:28:48.605532Z [init] [init.cpp:1911] [AppInitMain] nBestHeight = 199
node0 2021-02-24T18:28:48.605962Z [init] [net.cpp:2225] [BindListenPort] Bound to 127.0.0.1:14000
node0 2021-02-24T18:28:48.606057Z [init] [net.cpp:2225] [BindListenPort] Bound to 127.0.0.1:18445
node0 2021-02-24T18:28:48.606138Z [init] [noui.cpp:56] [noui_InitMessage] init message: Loading P2P addresses...
node0 2021-02-24T18:28:48.606264Z [init] [addrdb.cpp:115] [DeserializeFileDB] Missing or invalid file /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node0/regtest/peers.dat
node0 2021-02-24T18:28:48.606671Z [init] [net.cpp:2392] [Start] Recreating peers.dat
node1 2021-02-24T18:28:48.608756Z [init] [dbwrapper.cpp:137] [CDBWrapper] Opening LevelDB in /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node1/regtest/chainstate
node0 2021-02-24T18:28:48.611606Z [init] [net.cpp:1662] [DumpAddresses] Flushed 0 addresses to peers.dat 5ms
node0 2021-02-24T18:28:48.611724Z [init] [addrdb.cpp:115] [DeserializeFileDB] Missing or invalid file /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node0/regtest/anchors.dat
node0 2021-02-24T18:28:48.611776Z [init] [net.cpp:2403] [Start] 0 block-relay-only anchors will be tried for connections.
node0 2021-02-24T18:28:48.611841Z [init] [noui.cpp:56] [noui_InitMessage] init message: Starting network threads...
node0 2021-02-24T18:28:48.625644Z [init] [net.cpp:2436] [Start] DNS seeding disabled
node1 2021-02-24T18:28:48.627045Z [init] [dbwrapper.cpp:141] [CDBWrapper] Opened LevelDB successfully
node1 2021-02-24T18:28:48.627297Z [init] [dbwrapper.cpp:166] [CDBWrapper] Using obfuscation key for /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node1/regtest/chainstate: 714ee4f13ab12c72
node1 2021-02-24T18:28:48.628102Z [init] [validation.cpp:4231] [LoadChainTip] Loaded best chain: hashBestChain=7bdb817a7584c107fca42ca79286fa34a84cc3e9e930cbad38f7d4e3a0c56ca2 height=199 date=2011-02-02T23:17:17Z progress=1.000000
node1 2021-02-24T18:28:48.628219Z [init] [noui.cpp:56] [noui_InitMessage] init message: Rewinding blocks...
node1 2021-02-24T18:28:48.629173Z [init] [logging/timer.h:50] [Log] FlushStateToDisk: write block and undo data to disk started
node0 2021-02-24T18:28:48.629469Z [net] [util/system.h:469] [TraceThread] net thread start
node0 2021-02-24T18:28:48.639039Z [addcon] [util/system.h:469] [TraceThread] addcon thread start
node0 2021-02-24T18:28:48.645672Z [opencon] [util/system.h:469] [TraceThread] opencon thread start
node1 2021-02-24T18:28:48.654355Z [init] [logging/timer.h:50] [Log] FlushStateToDisk: write block and undo data to disk completed (25.08ms)
node1 2021-02-24T18:28:48.654456Z [init] [logging/timer.h:50] [Log] FlushStateToDisk: write block index to disk started
node1 2021-02-24T18:28:48.656667Z [init] [logging/timer.h:50] [Log] FlushStateToDisk: write block index to disk completed (2.11ms)
node1 2021-02-24T18:28:48.656760Z [init] [logging/timer.h:48] [Log] FlushStateToDisk: write coins cache to disk (0 coins, 0kB) started
node1 2021-02-24T18:28:48.657057Z [init] [txdb.cpp:139] [BatchWrite] Writing final batch of 0.00 MiB
node1 2021-02-24T18:28:48.657158Z [init] [txdb.cpp:141] [BatchWrite] Committed 0 changed transaction outputs (out of 0) to coin database...
node1 2021-02-24T18:28:48.657240Z [init] [logging/timer.h:48] [Log] FlushStateToDisk: write coins cache to disk (0 coins, 0kB) completed (0.00s)
node1 2021-02-24T18:28:48.657357Z [init] [validationinterface.cpp:244] [ChainStateFlushed] Enqueuing ChainStateFlushed: block hash=7bdb817a7584c107fca42ca79286fa34a84cc3e9e930cbad38f7d4e3a0c56ca2
node1 2021-02-24T18:28:48.657599Z [scheduler] [validationinterface.cpp:244] [operator()] ChainStateFlushed: block hash=7bdb817a7584c107fca42ca79286fa34a84cc3e9e930cbad38f7d4e3a0c56ca2
node1 2021-02-24T18:28:48.657862Z [init] [noui.cpp:56] [noui_InitMessage] init message: Verifying blocks...
node1 2021-02-24T18:28:48.658076Z [init] [validation.cpp:4255] [VerifyDB] Verifying last 6 blocks at level 3
node1 2021-02-24T18:28:48.658226Z [init] [validation.cpp:4262] [VerifyDB] [0%]...[16%]...[33%]...[50%]...[66%]...[83%]...[99%]...[DONE].
node1 2021-02-24T18:28:48.661140Z [init] [validation.cpp:4338] [VerifyDB] No coin database inconsistencies in last 6 blocks (6 transactions)
node1 2021-02-24T18:28:48.661211Z [init] [init.cpp:1762] [AppInitMain] block index 121ms
node1 2021-02-24T18:28:48.661667Z [init] [dbwrapper.cpp:137] [CDBWrapper] Opening LevelDB in /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node1/regtest/indexes/blockfilter/basic/db
node0 2021-02-24T18:28:48.661672Z [msghand] [util/system.h:469] [TraceThread] msghand thread start
node0 2021-02-24T18:28:48.662177Z [init] [noui.cpp:56] [noui_InitMessage] init message: Done loading
node1 2021-02-24T18:28:48.677948Z [init] [dbwrapper.cpp:141] [CDBWrapper] Opened LevelDB successfully
node1 2021-02-24T18:28:48.678102Z [init] [dbwrapper.cpp:166] [CDBWrapper] Using obfuscation key for /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node1/regtest/indexes/blockfilter/basic/db: 0000000000000000
node1 2021-02-24T18:28:48.688639Z [basic block filter index] [util/system.h:469] [TraceThread] basic block filter index thread start
node1 2021-02-24T18:28:48.688873Z [basic block filter index] [index/base.cpp:163] [ThreadSync] Syncing basic block filter index with block chain from height 0
node1 2021-02-24T18:28:48.689608Z [init] [init.cpp:1817] [AppInitMain] Unsetting NODE_NETWORK on prune mode
node1 2021-02-24T18:28:48.690366Z [init] [noui.cpp:56] [noui_InitMessage] init message: Pruning blockstore...
node1 2021-02-24T18:28:48.690531Z [init] [logging/timer.h:50] [Log] FlushStateToDisk: find files to prune started
node1 2021-02-24T18:28:48.690640Z [init] [validation.cpp:4030] [FindFilesToPrune] Prune: target=17592186044415MiB actual=0MiB diff=0MiB max_prune_height=4294967207 removed 0 blk/rev pairs
node1 2021-02-24T18:28:48.690722Z [init] [logging/timer.h:50] [Log] FlushStateToDisk: find files to prune completed (0.10ms)
node1 2021-02-24T18:28:48.694295Z [basic block filter index] [flatfile.cpp:69] [Allocate] Pre-allocating up to position 0x100000 in fltr00000.dat
node1 2021-02-24T18:28:48.705750Z [loadblk] [util/system.h:469] [TraceThread] loadblk thread start
node1 2021-02-24T18:28:48.720767Z [loadblk] [validation.cpp:5039] [LoadMempool] Failed to open mempool file from disk. Continuing anyway.
node1 2021-02-24T18:28:48.720879Z [loadblk] [util/system.h:471] [TraceThread] loadblk thread exit
node1 2021-02-24T18:28:48.721142Z [init] [init.cpp:1899] [AppInitMain] block tree size = 200
node1 2021-02-24T18:28:48.721204Z [init] [init.cpp:1911] [AppInitMain] nBestHeight = 199
node1 2021-02-24T18:28:48.721695Z [init] [net.cpp:2225] [BindListenPort] Bound to 127.0.0.1:14001
node1 2021-02-24T18:28:48.721841Z [init] [net.cpp:2222] [BindListenPort] Unable to bind to 127.0.0.1:18445 on this computer. Bitcoin Core is probably already running.
node1 2021-02-24T18:28:48.721934Z [init] [noui.cpp:56] [noui_InitMessage] init message: Loading P2P addresses...
node1 2021-02-24T18:28:48.722038Z [init] [addrdb.cpp:115] [DeserializeFileDB] Missing or invalid file /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node1/regtest/peers.dat
node1 2021-02-24T18:28:48.722452Z [init] [net.cpp:2392] [Start] Recreating peers.dat
node1 2021-02-24T18:28:48.727410Z [init] [net.cpp:1662] [DumpAddresses] Flushed 0 addresses to peers.dat 5ms
node1 2021-02-24T18:28:48.727517Z [init] [addrdb.cpp:115] [DeserializeFileDB] Missing or invalid file /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20210224_175402/feature_blockfilterindex_prune_0/node1/regtest/anchors.dat
node1 2021-02-24T18:28:48.727588Z [init] [net.cpp:2403] [Start] 0 block-relay-only anchors will be tried for connections.
node1 2021-02-24T18:28:48.727682Z [init] [noui.cpp:56] [noui_InitMessage] init message: Starting network threads...
node1 2021-02-24T18:28:48.743288Z [net] [util/system.h:469] [TraceThread] net thread start
node1 2021-02-24T18:28:48.743516Z [init] [net.cpp:2436] [Start] DNS seeding disabled
node1 2021-02-24T18:28:48.745965Z [addcon] [util/system.h:469] [TraceThread] addcon thread start
node1 2021-02-24T18:28:48.750912Z [opencon] [util/system.h:469] [TraceThread] opencon thread start
node1 2021-02-24T18:28:48.758601Z [msghand] [util/system.h:469] [TraceThread] msghand thread start
node1 2021-02-24T18:28:48.758867Z [init] [noui.cpp:56] [noui_InitMessage] init message: Done loading
node0 2021-02-24T18:28:48.824972Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:43842
node0 2021-02-24T18:28:48.825395Z [httpworker.1] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockcount user=__cookie__
node0 2021-02-24T18:28:48.826581Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:43842
node0 2021-02-24T18:28:48.826948Z [httpworker.2] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getmempoolinfo user=__cookie__
test 2021-02-24T18:28:48.828000Z TestFramework.node0 (DEBUG): RPC successfully started
node1 2021-02-24T18:28:48.829223Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:49454
node1 2021-02-24T18:28:48.829726Z [httpworker.0] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockcount user=__cookie__
node1 2021-02-24T18:28:48.830879Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:49454
node1 2021-02-24T18:28:48.831189Z [httpworker.1] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getmempoolinfo user=__cookie__
test 2021-02-24T18:28:48.832000Z TestFramework.node1 (DEBUG): RPC successfully started
node0 2021-02-24T18:28:48.832955Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:43842
node0 2021-02-24T18:28:48.833363Z [httpworker.3] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockchaininfo user=__cookie__
node1 2021-02-24T18:28:48.836225Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:49454
node1 2021-02-24T18:28:48.836584Z [httpworker.2] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockchaininfo user=__cookie__
test 2021-02-24T18:28:48.839000Z TestFramework (DEBUG): Generate a block with current time
test 2021-02-24T18:28:48.839000Z TestFramework.node0 (DEBUG): TestNode.generate() dispatches `generate` call to `generatetoaddress`
node0 2021-02-24T18:28:48.839979Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:43842
node0 2021-02-24T18:28:48.840271Z [httpworker.0] [rpc/request.cpp:174] [parse] ThreadRPCServer method=generatetoaddress user=__cookie__
node0 2021-02-24T18:28:48.841198Z [httpworker.0] [miner.cpp:169] [CreateNewBlock] CreateNewBlock(): block weight: 904 txs: 0 fees: 0 sigops 400
node0 2021-02-24T18:28:48.841621Z [httpworker.0] [validation.cpp:2003] [ConnectBlock] - Sanity checks: 0.06ms [0.00s (0.06ms/blk)]
node0 2021-02-24T18:28:48.841831Z [httpworker.0] [validation.cpp:2105] [ConnectBlock] - Fork checks: 0.22ms [0.00s (0.22ms/blk)]
node0 2021-02-24T18:28:48.841969Z [httpworker.0] [validation.cpp:2190] [ConnectBlock] - Connect 1 transactions: 0.13ms (0.133ms/tx, 0.000ms/txin) [0.00s (0.13ms/blk)]
node0 2021-02-24T18:28:48.842135Z [httpworker.0] [validation.cpp:2203] [ConnectBlock] - Verify 0 txins: 0.30ms (0.000ms/txin) [0.00s (0.30ms/blk)]
node0 2021-02-24T18:28:48.842220Z [httpworker.0] [miner.cpp:184] [CreateNewBlock] CreateNewBlock() packages: 0.09ms (0 packages, 0 updated descendants), validity: 1.18ms (total 1.28ms)
node0 2021-02-24T18:28:48.844709Z [httpworker.0] [validation.cpp:2603] [ConnectTip] - Load block from disk: 0.00ms [0.00s]
node0 2021-02-24T18:28:48.845307Z [httpworker.0] [validation.cpp:2003] [ConnectBlock] - Sanity checks: 0.01ms [0.00s (0.03ms/blk)]
node0 2021-02-24T18:28:48.845515Z [httpworker.0] [validation.cpp:2105] [ConnectBlock] - Fork checks: 0.65ms [0.00s (0.44ms/blk)]
node0 2021-02-24T18:28:48.845640Z [httpworker.0] [validation.cpp:2190] [ConnectBlock] - Connect 1 transactions: 0.12ms (0.118ms/tx, 0.000ms/txin) [0.00s (0.13ms/blk)]
node0 2021-02-24T18:28:48.845767Z [httpworker.0] [validation.cpp:2203] [ConnectBlock] - Verify 0 txins: 0.26ms (0.000ms/txin) [0.00s (0.28ms/blk)]
node0 2021-02-24T18:28:48.845971Z [httpworker.0] [validation.cpp:2221] [ConnectBlock] - Index writing: 0.21ms [0.00s (0.10ms/blk)]
node0 2021-02-24T18:28:48.846036Z [httpworker.0] [validation.cpp:2224] [ConnectBlock] - Callbacks: 0.07ms [0.00s (0.03ms/blk)]
node0 2021-02-24T18:28:48.846125Z [httpworker.0] [validationinterface.cpp:249] [BlockChecked] BlockChecked: block hash=2f83b334d15641317de1bde9ead383f5f5b24542935f7863af606344be20a36e state=Valid
node0 2021-02-24T18:28:48.846238Z [httpworker.0] [validation.cpp:2615] [ConnectTip] - Connect total: 1.55ms [0.00s (0.78ms/blk)]
node0 2021-02-24T18:28:48.846307Z [httpworker.0] [validation.cpp:2620] [ConnectTip] - Flush: 0.06ms [0.00s (0.03ms/blk)]
node0 2021-02-24T18:28:48.846388Z [httpworker.0] [validation.cpp:2625] [ConnectTip] - Writing chainstate: 0.09ms [0.00s (0.04ms/blk)]
node0 2021-02-24T18:28:48.847778Z [httpworker.0] [policy/fees.cpp:627] [processBlock] Blockpolicy estimates updated by 0 of 0 block txs, since last block 0 of 0 tracked, mempool map size 0, max target 0 from current
node0 2021-02-24T18:28:48.847944Z [httpworker.0] [validation.cpp:1340] [IsInitialBlockDownload] Leaving InitialBlockDownload (latching to false)
node0 2021-02-24T18:28:48.848377Z [httpworker.0] [validation.cpp:2468] [UpdateTip] UpdateTip: new best=2f83b334d15641317de1bde9ead383f5f5b24542935f7863af606344be20a36e height=200 version=0x30000000 log2_work=8.651052 tx=201 date='2021-02-24T18:28:48Z' progress=1.000000 cache=0.0MiB(1txo)
node0 2021-02-24T18:28:48.848458Z [httpworker.0] [validation.cpp:2634] [ConnectTip] - Connect postprocess: 2.06ms [0.00s (1.03ms/blk)]
node0 2021-02-24T18:28:48.848517Z [httpworker.0] [validation.cpp:2635] [ConnectTip] - Connect block: 3.76ms [0.00s (1.88ms/blk)]
node0 2021-02-24T18:28:48.848595Z [httpworker.0] [txmempool.cpp:630] [check] Checking mempool with 0 transactions and 0 inputs
node0 2021-02-24T18:28:48.848794Z [httpworker.0] [validationinterface.cpp:226] [BlockConnected] Enqueuing BlockConnected: block hash=2f83b334d15641317de1bde9ead383f5f5b24542935f7863af606344be20a36e block height=200
node0 2021-02-24T18:28:48.848973Z [httpworker.0] [validationinterface.cpp:199] [UpdatedBlockTip] Enqueuing UpdatedBlockTip: new block hash=2f83b334d15641317de1bde9ead383f5f5b24542935f7863af606344be20a36e fork block hash=7bdb817a7584c107fca42ca79286fa34a84cc3e9e930cbad38f7d4e3a0c56ca2 (in IBD=false)
node0 2021-02-24T18:28:48.849070Z [scheduler] [validationinterface.cpp:226] [operator()] BlockConnected: block hash=2f83b334d15641317de1bde9ead383f5f5b24542935f7863af606344be20a36e block height=200
node0 2021-02-24T18:28:48.865443Z [scheduler] [validationinterface.cpp:199] [operator()] UpdatedBlockTip: new block hash=2f83b334d15641317de1bde9ead383f5f5b24542935f7863af606344be20a36e fork block hash=7bdb817a7584c107fca42ca79286fa34a84cc3e9e930cbad38f7d4e3a0c56ca2 (in IBD=false)
node0 2021-02-24T18:28:48.869728Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:43842
node0 2021-02-24T18:28:48.870028Z [httpworker.1] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblock user=__cookie__
node0 2021-02-24T18:28:48.872864Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:43842
node0 2021-02-24T18:28:48.873153Z [httpworker.2] [rpc/request.cpp:174] [parse] ThreadRPCServer method=submitblock user=__cookie__
node0 2021-02-24T18:28:48.874664Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:43842
node0 2021-02-24T18:28:48.874940Z [httpworker.3] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockchaininfo user=__cookie__
node1 2021-02-24T18:28:48.878141Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:49454
node1 2021-02-24T18:28:48.878710Z [httpworker.3] [rpc/request.cpp:174] [parse] ThreadRPCServer method=submitblock user=__cookie__
node1 2021-02-24T18:28:48.882424Z [httpworker.3] [validation.cpp:2603] [ConnectTip] - Load block from disk: 0.00ms [0.00s]
node1 2021-02-24T18:28:48.882640Z [httpworker.3] [validation.cpp:2003] [ConnectBlock] - Sanity checks: 0.03ms [0.00s (0.03ms/blk)]
node1 2021-02-24T18:28:48.882834Z [httpworker.3] [validation.cpp:2105] [ConnectBlock] - Fork checks: 0.21ms [0.00s (0.21ms/blk)]
node1 2021-02-24T18:28:48.882978Z [httpworker.3] [validation.cpp:2190] [ConnectBlock] - Connect 1 transactions: 0.13ms (0.131ms/tx, 0.000ms/txin) [0.00s (0.13ms/blk)]
node1 2021-02-24T18:28:48.883152Z [httpworker.3] [validation.cpp:2203] [ConnectBlock] - Verify 0 txins: 0.32ms (0.000ms/txin) [0.00s (0.32ms/blk)]
node1 2021-02-24T18:28:48.883419Z [httpworker.3] [validation.cpp:2221] [ConnectBlock] - Index writing: 0.25ms [0.00s (0.25ms/blk)]
node1 2021-02-24T18:28:48.883483Z [httpworker.3] [validation.cpp:2224] [ConnectBlock] - Callbacks: 0.08ms [0.00s (0.08ms/blk)]
node1 2021-02-24T18:28:48.883615Z [httpworker.3] [validationinterface.cpp:249] [BlockChecked] BlockChecked: block hash=2f83b334d15641317de1bde9ead383f5f5b24542935f7863af606344be20a36e state=Valid
node1 2021-02-24T18:28:48.883876Z [httpworker.3] [validation.cpp:2615] [ConnectTip] - Connect total: 1.47ms [0.00s (1.47ms/blk)]
node1 2021-02-24T18:28:48.883964Z [httpworker.3] [validation.cpp:2620] [ConnectTip] - Flush: 0.10ms [0.00s (0.10ms/blk)]
node1 2021-02-24T18:28:48.884060Z [httpworker.3] [validation.cpp:2625] [ConnectTip] - Writing chainstate: 0.09ms [0.00s (0.09ms/blk)]
node1 2021-02-24T18:28:48.894260Z [httpworker.3] [policy/fees.cpp:627] [processBlock] Blockpolicy estimates updated by 0 of 0 block txs, since last block 0 of 0 tracked, mempool map size 0, max target 0 from current
node1 2021-02-24T18:28:48.894503Z [httpworker.3] [validation.cpp:1340] [IsInitialBlockDownload] Leaving InitialBlockDownload (latching to false)
node1 2021-02-24T18:28:48.894985Z [httpworker.3] [validation.cpp:2468] [UpdateTip] UpdateTip: new best=2f83b334d15641317de1bde9ead383f5f5b24542935f7863af606344be20a36e height=200 version=0x30000000 log2_work=8.651052 tx=201 date='2021-02-24T18:28:48Z' progress=1.000000 cache=0.0MiB(1txo)
node1 2021-02-24T18:28:48.895055Z [httpworker.3] [validation.cpp:2634] [ConnectTip] - Connect postprocess: 10.99ms [0.01s (10.99ms/blk)]
node1 2021-02-24T18:28:48.895115Z [httpworker.3] [validation.cpp:2635] [ConnectTip] - Connect block: 12.66ms [0.01s (12.66ms/blk)]
node1 2021-02-24T18:28:48.895202Z [httpworker.3] [txmempool.cpp:630] [check] Checking mempool with 0 transactions and 0 inputs
node1 2021-02-24T18:28:48.895405Z [httpworker.3] [validationinterface.cpp:226] [BlockConnected] Enqueuing BlockConnected: block hash=2f83b334d15641317de1bde9ead383f5f5b24542935f7863af606344be20a36e block height=200
node1 2021-02-24T18:28:48.895633Z [scheduler] [validationinterface.cpp:226] [operator()] BlockConnected: block hash=2f83b334d15641317de1bde9ead383f5f5b24542935f7863af606344be20a36e block height=200
node1 2021-02-24T18:28:48.896201Z [httpworker.3] [validationinterface.cpp:199] [UpdatedBlockTip] Enqueuing UpdatedBlockTip: new block hash=2f83b334d15641317de1bde9ead383f5f5b24542935f7863af606344be20a36e fork block hash=7bdb817a7584c107fca42ca79286fa34a84cc3e9e930cbad38f7d4e3a0c56ca2 (in IBD=false)
node1 2021-02-24T18:28:48.896600Z [scheduler] [validationinterface.cpp:199] [operator()] UpdatedBlockTip: new block hash=2f83b334d15641317de1bde9ead383f5f5b24542935f7863af606344be20a36e fork block hash=7bdb817a7584c107fca42ca79286fa34a84cc3e9e930cbad38f7d4e3a0c56ca2 (in IBD=false)
node1 2021-02-24T18:28:48.908103Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:49454
node1 2021-02-24T18:28:48.908355Z [httpworker.0] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockchaininfo user=__cookie__
node1 2021-02-24T18:28:48.915483Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:49454
node1 2021-02-24T18:28:48.915747Z [httpworker.1] [rpc/request.cpp:174] [parse] ThreadRPCServer method=addnode user=__cookie__
node1 2021-02-24T18:28:48.916009Z [httpworker.1] [net.cpp:402] [ConnectNode] trying connection 127.0.0.1:14000 lastseen=0.0hrs
node1 2021-02-24T18:28:48.917574Z [httpworker.1] [net.cpp:2859] [CNode] Added connection peer=0
node1 2021-02-24T18:28:48.918075Z [httpworker.1] [net.cpp:2879] [PushMessage] sending version (114 bytes) peer=0
node1 2021-02-24T18:28:48.918345Z [httpworker.1] [net_processing.cpp:931] [PushNodeVersion] send version message: version 70016, blocks=200, us=[::]:0, txrelay=1, peer=0
node0 2021-02-24T18:28:48.918879Z [net] [net.cpp:2859] [CNode] Added connection peer=0
node0 2021-02-24T18:28:48.919370Z [net] [net.cpp:1104] [AcceptConnection] connection from 127.0.0.1:60880 accepted
node1 2021-02-24T18:28:48.920762Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:49454
node1 2021-02-24T18:28:48.921044Z [httpworker.2] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getpeerinfo user=__cookie__
node0 2021-02-24T18:28:48.922509Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: version (114 bytes) peer=0
node0 2021-02-24T18:28:48.922718Z [msghand] [net.cpp:2879] [PushMessage] sending version (114 bytes) peer=0
node0 2021-02-24T18:28:48.923015Z [msghand] [net_processing.cpp:931] [PushNodeVersion] send version message: version 70016, blocks=200, us=[::]:0, txrelay=1, peer=0
node0 2021-02-24T18:28:48.923135Z [msghand] [net.cpp:2879] [PushMessage] sending wtxidrelay (0 bytes) peer=0
node0 2021-02-24T18:28:48.923290Z [msghand] [net.cpp:2879] [PushMessage] sending sendaddrv2 (0 bytes) peer=0
node0 2021-02-24T18:28:48.923444Z [msghand] [net.cpp:2879] [PushMessage] sending verack (0 bytes) peer=0
node0 2021-02-24T18:28:48.923652Z [msghand] [net_processing.cpp:2710] [ProcessMessage] receive version message: /Satoshi:21.99.0(testnode1)/: version 70016, blocks=200, us=[::]:0, txrelay=1, peer=0
node0 2021-02-24T18:28:48.923797Z [msghand] [timedata.cpp:54] [AddTimeData] added time data, samples 2, offset +0 (+0 minutes)
node1 2021-02-24T18:28:48.950085Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: version (114 bytes) peer=0
node1 2021-02-24T18:28:48.950217Z [msghand] [net.cpp:2879] [PushMessage] sending wtxidrelay (0 bytes) peer=0
node1 2021-02-24T18:28:48.950444Z [msghand] [net.cpp:2879] [PushMessage] sending sendaddrv2 (0 bytes) peer=0
node1 2021-02-24T18:28:48.950594Z [msghand] [net.cpp:2879] [PushMessage] sending verack (0 bytes) peer=0
node1 2021-02-24T18:28:48.950864Z [msghand] [net.cpp:2879] [PushMessage] sending getaddr (0 bytes) peer=0
node1 2021-02-24T18:28:48.951103Z [msghand] [net_processing.cpp:2710] [ProcessMessage] receive version message: /Satoshi:21.99.0(testnode0)/: version 70016, blocks=200, us=[::]:0, txrelay=1, peer=0
node0 2021-02-24T18:28:48.951118Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: wtxidrelay (0 bytes) peer=0
node1 2021-02-24T18:28:48.951240Z [msghand] [timedata.cpp:54] [AddTimeData] added time data, samples 2, offset +0 (+0 minutes)
node0 2021-02-24T18:28:48.951372Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: sendaddrv2 (0 bytes) peer=0
node1 2021-02-24T18:28:48.951493Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: wtxidrelay (0 bytes) peer=0
node0 2021-02-24T18:28:48.951585Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: verack (0 bytes) peer=0
node0 2021-02-24T18:28:48.951661Z [msghand] [net.cpp:2879] [PushMessage] sending sendheaders (0 bytes) peer=0
node1 2021-02-24T18:28:48.951747Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: sendaddrv2 (0 bytes) peer=0
node0 2021-02-24T18:28:48.951848Z [msghand] [net.cpp:2879] [PushMessage] sending sendcmpct (9 bytes) peer=0
node1 2021-02-24T18:28:48.951945Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: verack (0 bytes) peer=0
node0 2021-02-24T18:28:48.952021Z [msghand] [net.cpp:2879] [PushMessage] sending sendcmpct (9 bytes) peer=0
node1 2021-02-24T18:28:48.952035Z [msghand] [net_processing.cpp:2749] [ProcessMessage] New outbound peer connected: version: 70016, blocks=200, peer=0 (manual)
node1 2021-02-24T18:28:48.952125Z [msghand] [net.cpp:2879] [PushMessage] sending sendheaders (0 bytes) peer=0
node0 2021-02-24T18:28:48.952282Z [msghand] [net.cpp:2879] [PushMessage] sending ping (8 bytes) peer=0
node1 2021-02-24T18:28:48.952284Z [msghand] [net.cpp:2879] [PushMessage] sending sendcmpct (9 bytes) peer=0
node1 2021-02-24T18:28:48.952441Z [msghand] [net.cpp:2879] [PushMessage] sending sendcmpct (9 bytes) peer=0
node0 2021-02-24T18:28:48.952783Z [msghand] [net_processing.cpp:4500] [SendMessages] initial getheaders (199) to peer=0 (startheight:200)
node0 2021-02-24T18:28:48.952943Z [msghand] [net.cpp:2879] [PushMessage] sending getheaders (645 bytes) peer=0
node0 2021-02-24T18:28:48.954348Z [msghand] [net.cpp:2879] [PushMessage] sending feefilter (8 bytes) peer=0
node0 2021-02-24T18:28:48.955067Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: getaddr (0 bytes) peer=0
node0 2021-02-24T18:28:48.955520Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: sendheaders (0 bytes) peer=0
node0 2021-02-24T18:28:48.955838Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: sendcmpct (9 bytes) peer=0
node0 2021-02-24T18:28:48.956202Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: sendcmpct (9 bytes) peer=0
node1 2021-02-24T18:28:48.975323Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:49454
node1 2021-02-24T18:28:48.975586Z [httpworker.3] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getpeerinfo user=__cookie__
node1 2021-02-24T18:28:48.978775Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:49454
node1 2021-02-24T18:28:48.978999Z [httpworker.0] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getpeerinfo user=__cookie__
node0 2021-02-24T18:28:48.982659Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:43842
node0 2021-02-24T18:28:48.982917Z [httpworker.1] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getbestblockhash user=__cookie__
node1 2021-02-24T18:28:48.984446Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:49454
node1 2021-02-24T18:28:48.984709Z [httpworker.1] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getbestblockhash user=__cookie__
node0 2021-02-24T18:28:48.987304Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:43842
node0 2021-02-24T18:28:48.987574Z [httpworker.2] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getrawmempool user=__cookie__
node1 2021-02-24T18:28:48.992046Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:49454
node1 2021-02-24T18:28:48.992317Z [httpworker.2] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getrawmempool user=__cookie__
node0 2021-02-24T18:28:48.995356Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:43842
node0 2021-02-24T18:28:48.995650Z [httpworker.3] [rpc/request.cpp:174] [parse] ThreadRPCServer method=syncwithvalidationinterfacequeue user=__cookie__
node1 2021-02-24T18:28:49.003881Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:49454
node1 2021-02-24T18:28:49.004138Z [httpworker.3] [rpc/request.cpp:174] [parse] ThreadRPCServer method=syncwithvalidationinterfacequeue user=__cookie__
test 2021-02-24T18:28:49.005000Z TestFramework (INFO): check if we can access a blockfilter when pruning is enabled but no blocks are actually pruned
node1 2021-02-24T18:28:49.009003Z [msghand] [net.cpp:2879] [PushMessage] sending ping (8 bytes) peer=0
node1 2021-02-24T18:28:49.009645Z [msghand] [net_processing.cpp:4500] [SendMessages] initial getheaders (199) to peer=0 (startheight:200)
node0 2021-02-24T18:28:49.009806Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: ping (8 bytes) peer=0
node1 2021-02-24T18:28:49.009864Z [msghand] [net.cpp:2879] [PushMessage] sending getheaders (645 bytes) peer=0
node0 2021-02-24T18:28:49.009917Z [msghand] [net.cpp:2879] [PushMessage] sending pong (8 bytes) peer=0
node1 2021-02-24T18:28:49.010814Z [msghand] [net.cpp:2879] [PushMessage] sending feefilter (8 bytes) peer=0
node1 2021-02-24T18:28:49.011191Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: sendheaders (0 bytes) peer=0
node0 2021-02-24T18:28:49.011419Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: getheaders (645 bytes) peer=0
node0 2021-02-24T18:28:49.011571Z [msghand] [net_processing.cpp:3174] [ProcessMessage] getheaders 200 to end from peer=0
node1 2021-02-24T18:28:49.011620Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: sendcmpct (9 bytes) peer=0
node0 2021-02-24T18:28:49.011680Z [msghand] [net.cpp:2879] [PushMessage] sending headers (82 bytes) peer=0
node0 2021-02-24T18:28:49.012153Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: feefilter (8 bytes) peer=0
node1 2021-02-24T18:28:49.012184Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: sendcmpct (9 bytes) peer=0
node0 2021-02-24T18:28:49.012269Z [msghand] [net_processing.cpp:3988] [ProcessMessage] received: feefilter of 0.00001000 BTC/kvB from peer=0
node1 2021-02-24T18:28:49.012521Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: ping (8 bytes) peer=0
node1 2021-02-24T18:28:49.012603Z [msghand] [net.cpp:2879] [PushMessage] sending pong (8 bytes) peer=0
node1 2021-02-24T18:28:49.013060Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: getheaders (645 bytes) peer=0
node0 2021-02-24T18:28:49.013122Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: pong (8 bytes) peer=0
node1 2021-02-24T18:28:49.013194Z [msghand] [net_processing.cpp:3174] [ProcessMessage] getheaders 200 to end from peer=0
node1 2021-02-24T18:28:49.013306Z [msghand] [net.cpp:2879] [PushMessage] sending headers (82 bytes) peer=0
node0 2021-02-24T18:28:49.013764Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: headers (82 bytes) peer=0
node1 2021-02-24T18:28:49.013769Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: feefilter (8 bytes) peer=0
node1 2021-02-24T18:28:49.013866Z [msghand] [net_processing.cpp:3988] [ProcessMessage] received: feefilter of 0.00001000 BTC/kvB from peer=0
node1 2021-02-24T18:28:49.014179Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: pong (8 bytes) peer=0
node1 2021-02-24T18:28:49.014472Z [msghand] [net_processing.cpp:2527] [ProcessMessage] received: headers (82 bytes) peer=0
node1 2021-02-24T18:28:49.021742Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:49454
node1 2021-02-24T18:28:49.022016Z [httpworker.0] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getbestblockhash user=__cookie__
node1 2021-02-24T18:28:49.024737Z [http] [httpserver.cpp:238] [http_request_cb] Received a POST request for / from 127.0.0.1:49454
node1 2021-02-24T18:28:49.024965Z [httpworker.1] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockfilter user=__cookie__
test 2021-02-24T18:28:49.026000Z TestFramework (ERROR): JSONRPC error
Traceback (most recent call last):
File "/tmp/cirrus-ci-build/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/test_framework/test_framework.py", line 127, in main
self.run_test()
File "/tmp/cirrus-ci-build/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/feature_blockfilterindex_prune.py", line 21, in run_test
assert len(self.nodes[1].getblockfilter(self.nodes[1].getbestblockhash())['filter']) > 0
File "/tmp/cirrus-ci-build/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/test_framework/coverage.py", line 47, in __call__
return_val = self.auth_service_proxy_instance.__call__(*args, **kwargs)
File "/tmp/cirrus-ci-build/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/test_framework/authproxy.py", line 146, in __call__
raise JSONRPCException(response['error'], status)
test_framework.authproxy.JSONRPCException: Filter not found. Block filters are still in the process of being indexed. (-1)
test 2021-02-24T18:28:49.027000Z TestFramework (DEBUG): Closing down network thread
test 2021-02-24T18:28:49.039000Z TestFramework (INFO): Stopping nodes
test 2021-02-24T18:28:49.040000Z TestFramework.node0 (DEBUG): Stopping node
</p></details>