Skip to content

ci: run some Bitcoin Core CI jobs #253

Open
Sjors wants to merge 3 commits intobitcoin-core:masterfrom
Sjors:2026/03/ci-core
Open

ci: run some Bitcoin Core CI jobs #253
Sjors wants to merge 3 commits intobitcoin-core:masterfrom
Sjors:2026/03/ci-core

Conversation

@Sjors
Copy link
Member

@Sjors Sjors commented Mar 11, 2026

Slightly more elaborate version of #252 with ccache and depends caching.

@Sjors
Copy link
Member Author

Sjors commented Mar 11, 2026

@ryanofsky can you expand the whitelist with actions/cache@* and actions/cache/*@*?

(that's what's causing the new workflows to get ignored, see annotations here: https://github.com/bitcoin-core/libmultiprocess/actions/runs/22963039475)

@DrahtBot
Copy link

DrahtBot commented Mar 11, 2026

The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.

Reviews

See the guideline for information on the review process.
A summary of reviews will appear here.

@Sjors Sjors mentioned this pull request Mar 11, 2026
@ryanofsky ryanofsky closed this Mar 11, 2026
@ryanofsky ryanofsky reopened this Mar 11, 2026
@Sjors
Copy link
Member Author

Sjors commented Mar 11, 2026

Thanks, the jobs run now, I'll debug them later.

@Sjors Sjors force-pushed the 2026/03/ci-core branch from 5b00ed4 to 50a7f05 Compare March 12, 2026 10:47

- name: Run IPC and miner unit tests
run: |
ctest --test-dir build -R "ipc|miner_tests" --output-on-failure --timeout 480
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

same. Also could use the longer --tests-regex instead of -R to be more self-explanatory?

sudo apt-get install --no-install-recommends -y ${{ matrix.packages }}
sudo update-alternatives --install /usr/bin/clang++ clang++ "/usr/bin/clang++-${LLVM_VERSION}" 100
sudo update-alternatives --install /usr/bin/clang clang "/usr/bin/clang-${LLVM_VERSION}" 100
sudo update-alternatives --install /usr/bin/llvm-symbolizer llvm-symbolizer "/usr/bin/llvm-symbolizer-${LLVM_VERSION}" 100
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I wonder if we can split the upstream install script into smaller re-useable bash or python scripts, to be used here?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm not sure about trying to expose bash scripts as a sort of stable CI API, which would essentially give us an undocumented and untested consumer. Inevitably, changes in our repo will break things, and we'll have another loop of having to re-refactor/change, based on requirements here, that nobody in our repository is accounting for when making changes there.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In general we'll need to wait and see if these Bitcoin Core jobs are maintainable here over the long run. If it becomes more hassle that just opening a draft PR on bitcoin/bitcoin then we might just drop them.

@Sjors Sjors force-pushed the 2026/03/ci-core branch 2 times, most recently from a1e0fb1 to cb8a9e8 Compare March 12, 2026 12:53
@Sjors
Copy link
Member Author

Sjors commented Mar 12, 2026

All green. Pushed again to wire up ccache.

@Sjors Sjors marked this pull request as ready for review March 12, 2026 13:16
@maflcko
Copy link
Contributor

maflcko commented Mar 12, 2026

all green

Well, then this is obviously wrong, because it fails to find any of the countless bugs that still exist.

It would be good to find at least one of them. Otherwise, this seems pointless?

@Sjors
Copy link
Member Author

Sjors commented Mar 12, 2026

@maflcko this doesn't include #250 so might not catch those?

@fanquake
Copy link
Member

fanquake commented Mar 12, 2026

this doesn't include #250 so might not catch those?

If it doesn't include #250, then shouldn't it catch all the bugs being fixed by #250? (or any of the others that exist with #250 included, bitcoin/bitcoin#34804 (comment), assuming they don't require #250 to be merged).

@Sjors
Copy link
Member Author

Sjors commented Mar 12, 2026

@fanquake the test hooks added in #250 make it more likely to find those bugs in the first place. They all made it through CI initially. But as a sanity check it could make sense if I add those tests here (without fixes).

@maflcko
Copy link
Contributor

maflcko commented Mar 12, 2026

@fanquake the test hooks added in #250 make it more likely to find those bugs in the first place. They all made it through CI initially. But as a sanity check it could make sense if I add those tests here (without fixes).

I think it makes more sense to try to find the bugs without the new tests. The goal here isn't to catch bugs in newly added deterministic tests, but to catch intermittent bugs in the vanilla (pre-existing) subtree.

@Sjors Sjors force-pushed the 2026/03/ci-core branch from cb8a9e8 to 1c25227 Compare March 12, 2026 16:12
@Sjors
Copy link
Member Author

Sjors commented Mar 12, 2026

I added a third commit for tweaking the frequencies. All three jobs now run the unit and functional tests 200 times.

@Sjors Sjors force-pushed the 2026/03/ci-core branch from 1c25227 to 8c562fe Compare March 12, 2026 16:19
@Sjors
Copy link
Member Author

Sjors commented Mar 12, 2026

Test run times:

  • macOS: unit 4s, functional ?s
  • TSAN: unit 15s, functional ?s
  • ASan / UBSan: unit 10s, functional ?s

Unit tests are still running, from previous experience the functional tests took about 1 second each.

I'd like to keep the job runtimes under 15 minutes:

Assuming 3 minutes for setup, 4 minutes for unit tests and 4 minutes for functional tests, I'll tweak the numbers.

(also forgot to install ccache on macOS)

@Sjors Sjors force-pushed the 2026/03/ci-core branch from 8c562fe to f03e3a2 Compare March 12, 2026 16:33
@maflcko
Copy link
Contributor

maflcko commented Mar 12, 2026

nice. Let's hope one of them fails 😅

@maflcko
Copy link
Contributor

maflcko commented Mar 12, 2026

ok, none failed :(

@Sjors
Copy link
Member Author

Sjors commented Mar 12, 2026

I'm lowering the unit tests a bit. Also noticed I forgot to run the _miner.py test 🤡

@Sjors Sjors force-pushed the 2026/03/ci-core branch from f03e3a2 to 65abbaf Compare March 12, 2026 18:36
run: |
for _ in $(seq 1 "${TSAN_FUNCTIONAL_TEST_RUNS}"); do
LD_LIBRARY_PATH="depends/${{ steps.host.outputs.host }}/lib" \
build/test/functional/test_runner.py --filter='^interface_ipc' --jobs "${PARALLEL}" --timeout-factor=10
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

there are only two tests, so the --jobs PARALLEL won't make any difference, also this is running sequentially over TSAN_FUNCTIONAL_TEST_RUNS

Maybe the GHA machines just won't trigger the failures here?

Has anyone reproduced any of the failures locally, when running the tests?

Copy link
Member Author

@Sjors Sjors Mar 12, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah, I got confused there. You can't use --filter to run tests multiple times, you have to pass the names in multiple times. The latest push should fix this.

(well, the next push...)

@Sjors Sjors force-pushed the 2026/03/ci-core branch from 65abbaf to fddf6e3 Compare March 12, 2026 19:10
@Sjors Sjors marked this pull request as draft March 12, 2026 19:15
@Sjors Sjors force-pushed the 2026/03/ci-core branch from fddf6e3 to f7d4e09 Compare March 12, 2026 19:18
@Sjors
Copy link
Member Author

Sjors commented Mar 12, 2026

I extracted the test runners into a bash script.

Narrowed the unit tests down to just miner_tests and ipc_tests.

Still no failure, so I cranked up the number of functional test runs and increased parallelism.

@Sjors Sjors force-pushed the 2026/03/ci-core branch 2 times, most recently from f92743d to 9e7f825 Compare March 12, 2026 19:58
@Sjors
Copy link
Member Author

Sjors commented Mar 12, 2026

macOS hit a failure:

https://github.com/bitcoin-core/libmultiprocess/actions/runs/23021186537/job/66857665203?pr=253#step:15:2956

stdout:
2026-03-12T20:08:44.082466Z TestFramework (INFO): PRNG seed is: 871016500598777134
2026-03-12T20:08:44.111536Z TestFramework (INFO): Initializing test directory /var/folders/t5/f77_gwnj6p95qxy9py3fckx00000gn/T/test_runner_₿_🏃_20260312_200412/interface_ipc_mining_14
2026-03-12T20:08:44.915954Z TestFramework (INFO): Running Mining interface test
2026-03-12T20:08:46.346762Z TestFramework (INFO): Running Mining interface early startup test
2026-03-12T20:08:47.289738Z TestFramework (INFO): Running BlockTemplate interface test
2026-03-12T20:08:57.030460Z TestFramework (ERROR): Unexpected exception:
Traceback (most recent call last):
  File "/Users/runner/work/libmultiprocess/libmultiprocess/test/functional/test_framework/test_framework.py", line 142, in main
    self.run_test()
    ~~~~~~~~~~~~~^^
  File "/Users/runner/work/libmultiprocess/libmultiprocess/build/test/functional/interface_ipc_mining.py", line 404, in run_test
    self.run_block_template_test()
    ~~~~~~~~~~~~~~~~~~~~~~~~~~~~^^
  File "/Users/runner/work/libmultiprocess/libmultiprocess/build/test/functional/interface_ipc_mining.py", line 282, in run_block_template_test
    asyncio.run(capnp.run(async_routine()))
    ~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Cellar/python@3.14/3.14.3_1/Frameworks/Python.framework/Versions/3.14/lib/python3.14/asyncio/runners.py", line 204, in run
    return runner.run(main)
           ~~~~~~~~~~^^^^^^
  File "/opt/homebrew/Cellar/python@3.14/3.14.3_1/Frameworks/Python.framework/Versions/3.14/lib/python3.14/asyncio/runners.py", line 127, in run
    return self._loop.run_until_complete(task)
           ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^
  File "/opt/homebrew/Cellar/python@3.14/3.14.3_1/Frameworks/Python.framework/Versions/3.14/lib/python3.14/asyncio/base_events.py", line 719, in run_until_complete
    return future.result()
           ~~~~~~~~~~~~~^^
  File "capnp/lib/capnp.pyx", line 2083, in run
  File "capnp/lib/capnp.pyx", line 2084, in capnp.lib.capnp.run
    return await coro
  File "/Users/runner/work/libmultiprocess/libmultiprocess/build/test/functional/interface_ipc_mining.py", line 265, in async_routine
    assert template6 is not None
           ^^^^^^^^^^^^^^^^^^^^^
AssertionError

Though maybe not a very interesting one.

More likely to be brittleness in the test itself under high CPU pressure:

self.log.debug("Wait for another, get one after increase in fees in the mempool")
template6 = await wait_and_do(
    mining_wait_next_template(template5, stack, ctx, waitoptions),
    lambda: self.miniwallet.send_self_transfer(fee_rate=10, from_node=self.nodes[0]))
assert template6 is not None

@Sjors Sjors force-pushed the 2026/03/ci-core branch from 9e7f825 to 9cbb498 Compare March 12, 2026 20:33
@Sjors
Copy link
Member Author

Sjors commented Mar 12, 2026

So far it doesn't seem like we've reproduced the issues from #250.

I slightly lowered the parallel pressure on macOS and slightly the reduced the number of repetitions on the sanitizers to keep them around 10 minutes.

I split the test script between unit and functional tests so can track their time consumption separately. I also adjusted the functional test runner to abort and print the full log after failure.

@Sjors
Copy link
Member Author

Sjors commented Mar 12, 2026

Ah wonderfull, TSan found a WARNING: ThreadSanitizer: heap-use-after-free (virtual call vs free) (pid=9523: https://github.com/bitcoin-core/libmultiprocess/actions/runs/23022571813/job/66862518537?pr=253#step:21:2005

Log
2026-03-12T20:39:20.2369314Z 30/600 - interface_ipc.py failed, Duration: 34 s
2026-03-12T20:39:20.2372491Z 
2026-03-12T20:39:20.2373694Z stdout:
2026-03-12T20:39:20.2398774Z 2026-03-12T20:38:45.879762Z TestFramework (INFO): PRNG seed is: 6963492962394618072
2026-03-12T20:39:20.2494547Z 2026-03-12T20:38:45.907828Z TestFramework (INFO): Initializing test directory /tmp/test_runner_₿_🏃_20260312_203817/interface_ipc_553
2026-03-12T20:39:20.2499353Z Early exiting after test failure
2026-03-12T20:39:20.2505644Z 2026-03-12T20:38:56.595317Z TestFramework (INFO): Running echo test
2026-03-12T20:39:20.2531872Z 2026-03-12T20:38:57.337552Z TestFramework (INFO): Running mining test
2026-03-12T20:39:20.2533490Z 2026-03-12T20:38:57.987523Z TestFramework (INFO): Running deprecated mining interface test
2026-03-12T20:39:20.2537984Z 2026-03-12T20:38:58.049581Z TestFramework (INFO): Running disconnect during BlockTemplate.waitNext
2026-03-12T20:39:20.2543363Z 2026-03-12T20:39:18.610585Z TestFramework (ERROR): Unexpected exception:
2026-03-12T20:39:20.2546899Z Traceback (most recent call last):
2026-03-12T20:39:20.2548141Z   File "/home/runner/work/libmultiprocess/libmultiprocess/test/functional/test_framework/test_framework.py", line 142, in main
2026-03-12T20:39:20.2553664Z     self.run_test()
2026-03-12T20:39:20.2560268Z   File "/home/runner/work/libmultiprocess/libmultiprocess/build/test/functional/interface_ipc.py", line 176, in run_test
2026-03-12T20:39:20.2624971Z     self.run_unclean_disconnect_test()
2026-03-12T20:39:20.2626695Z   File "/home/runner/work/libmultiprocess/libmultiprocess/build/test/functional/interface_ipc.py", line 122, in run_unclean_disconnect_test
2026-03-12T20:39:20.2672261Z     disconnected_log_check.close()
2026-03-12T20:39:20.2682422Z   File "/usr/lib/python3.12/contextlib.py", line 618, in close
2026-03-12T20:39:20.2689108Z     self.__exit__(None, None, None)
2026-03-12T20:39:20.2689965Z   File "/usr/lib/python3.12/contextlib.py", line 610, in __exit__
2026-03-12T20:39:20.2716451Z     raise exc_details[1]
2026-03-12T20:39:20.2751887Z   File "/usr/lib/python3.12/contextlib.py", line 595, in __exit__
2026-03-12T20:39:20.2786300Z     if cb(*exc_details):
2026-03-12T20:39:20.2787496Z        ^^^^^^^^^^^^^^^^
2026-03-12T20:39:20.2827987Z   File "/usr/lib/python3.12/contextlib.py", line 144, in __exit__
2026-03-12T20:39:20.2838987Z     next(self.gen)
2026-03-12T20:39:20.2868811Z   File "/home/runner/work/libmultiprocess/libmultiprocess/test/functional/test_framework/test_node.py", line 607, in assert_debug_log
2026-03-12T20:39:20.2870372Z     self._raise_assertion_error(f'Expected message(s) {remaining_expected!s} '
2026-03-12T20:39:20.2885154Z   File "/home/runner/work/libmultiprocess/libmultiprocess/test/functional/test_framework/test_node.py", line 241, in _raise_assertion_error
2026-03-12T20:39:20.2893910Z     raise AssertionError(self._node_msg(msg))
2026-03-12T20:39:20.3039037Z AssertionError: [node 0] Expected message(s) ['canceled while executing'] not found in log:
2026-03-12T20:39:20.3040376Z 
2026-03-12T20:39:20.3041581Z  - 2026-03-12T20:38:58.573383Z [capnp-loop] [ipc/capnp/protocol.cpp:53] [IpcLogFn] ipc: {bitcoin-node-9523/b-capnp-loop-9612} IPC server destroy N2mp11ProxyServerIN3ipc5capnp8messages6MiningEEE
2026-03-12T20:39:20.3204651Z  - 2026-03-12T20:38:58.574563Z [capnp-loop] [ipc/capnp/protocol.cpp:53] [IpcLogFn] ipc: {bitcoin-node-9523/b-capnp-loop-9612} IPC server: socket disconnected.
2026-03-12T20:39:20.3210186Z  - 2026-03-12T20:38:58.574851Z [capnp-loop] [ipc/capnp/protocol.cpp:53] [IpcLogFn] ipc: {bitcoin-node-9523/b-capnp-loop-9612} IPC server destroy N2mp11ProxyServerIN3ipc5capnp8messages4InitEEE
2026-03-12T20:39:20.3229625Z  - 2026-03-12T20:38:58.575439Z [unknown] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9989 (from pythread)} IPC server executing request #15
2026-03-12T20:39:20.3231058Z 
2026-03-12T20:39:20.3231067Z 
2026-03-12T20:39:20.3231815Z 2026-03-12T20:39:18.686000Z TestFramework (INFO): Not stopping nodes as test failed. The dangling processes will be cleaned up later.
2026-03-12T20:39:20.3238760Z 2026-03-12T20:39:18.686172Z TestFramework (WARNING): Not cleaning up dir /tmp/test_runner_₿_🏃_20260312_203817/interface_ipc_553
2026-03-12T20:39:20.3384726Z 2026-03-12T20:39:18.686254Z TestFramework (ERROR): Test failed. Test logging available at /tmp/test_runner_₿_🏃_20260312_203817/interface_ipc_553/test_framework.log
2026-03-12T20:39:20.3460918Z 2026-03-12T20:39:18.686477Z TestFramework (ERROR): 
2026-03-12T20:39:20.3495523Z 2026-03-12T20:39:18.686646Z TestFramework (ERROR): Hint: Call /home/runner/work/libmultiprocess/libmultiprocess/test/functional/combine_logs.py '/tmp/test_runner_₿_🏃_20260312_203817/interface_ipc_553' to consolidate all logs
2026-03-12T20:39:20.3558861Z 2026-03-12T20:39:18.686725Z TestFramework (ERROR): 
2026-03-12T20:39:20.3576706Z 2026-03-12T20:39:18.686789Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log.
2026-03-12T20:39:20.3578917Z 2026-03-12T20:39:18.686879Z TestFramework (ERROR): https://github.com/bitcoin/bitcoin/issues
2026-03-12T20:39:20.3583520Z 2026-03-12T20:39:18.686945Z TestFramework (ERROR): 
2026-03-12T20:39:20.3584036Z 
2026-03-12T20:39:20.3584043Z 
2026-03-12T20:39:20.3638386Z stderr:
2026-03-12T20:39:20.3677099Z [node 0] Cleaning up leftover process
2026-03-12T20:39:20.3677727Z 
2026-03-12T20:39:20.3677734Z 
2026-03-12T20:39:20.3678164Z Combine the logs and print the last 99999999 lines ...
2026-03-12T20:39:20.3754614Z 
2026-03-12T20:39:20.3754990Z ============
2026-03-12T20:39:20.3807018Z Combined log for /tmp/test_runner_₿_🏃_20260312_203817/interface_ipc_553:
2026-03-12T20:39:20.3815796Z ============
2026-03-12T20:39:20.3816155Z 
2026-03-12T20:39:20.3816734Z  test  2026-03-12T20:38:45.879762Z TestFramework (INFO): PRNG seed is: 6963492962394618072 
2026-03-12T20:39:20.3828277Z  test  2026-03-12T20:38:45.879951Z TestFramework (DEBUG): Setting up network thread 
2026-03-12T20:39:20.3841000Z  test  2026-03-12T20:38:45.907828Z TestFramework (INFO): Initializing test directory /tmp/test_runner_₿_🏃_20260312_203817/interface_ipc_553 
2026-03-12T20:39:20.3933242Z  test  2026-03-12T20:38:45.908062Z TestFramework (DEBUG): Copy cache directory /home/runner/work/libmultiprocess/libmultiprocess/build/test/cache/node0 to node 0 
2026-03-12T20:39:20.3944060Z  test  2026-03-12T20:38:46.115478Z TestFramework.node0 (DEBUG): bitcoind started, waiting for RPC to come up 
2026-03-12T20:39:20.3950722Z  node0 2026-03-12T20:38:46.828385Z [init] [init/common.cpp:156] [LogPackageVersion] Bitcoin Core version v31.99.0-5608b8ce9e0f-dirty (debug build) 
2026-03-12T20:39:20.4024427Z  node0 2026-03-12T20:38:46.855480Z [init] [init.cpp:770] [InitParameterInteraction] parameter interaction: -bind set -> setting -listen=1 
2026-03-12T20:39:20.4044159Z  node0 2026-03-12T20:38:46.857372Z [init] [init/common.cpp:102] [SetLoggingCategories] Log output may contain privacy-sensitive information. Be cautious when sharing logs. 
2026-03-12T20:39:20.4046503Z  node0 2026-03-12T20:38:46.890454Z [init] [kernel/context.cpp:20] [operator()] Using the 'x86_shani(1way;2way)' SHA256 implementation 
2026-03-12T20:39:20.4142468Z  node0 2026-03-12T20:38:47.065475Z [init] [random.cpp:110] [ReportHardwareRand] Using RdSeed as an additional entropy source 
2026-03-12T20:39:20.4148863Z  node0 2026-03-12T20:38:47.065520Z [init] [random.cpp:113] [ReportHardwareRand] Using RdRand as an additional entropy source 
2026-03-12T20:39:20.4163399Z  node0 2026-03-12T20:38:47.157657Z [init] [init/common.cpp:124] [StartLogging] Default data directory /home/runner/.bitcoin 
2026-03-12T20:39:20.4166154Z  node0 2026-03-12T20:38:47.157797Z [init] [init/common.cpp:125] [StartLogging] Using data directory /tmp/test_runner_₿_🏃_20260312_203817/interface_ipc_553/node0/regtest 
2026-03-12T20:39:20.4170847Z  node0 2026-03-12T20:38:47.157994Z [init] [init/common.cpp:134] [StartLogging] Config file: /tmp/test_runner_₿_🏃_20260312_203817/interface_ipc_553/node0/bitcoin.conf 
2026-03-12T20:39:20.4174394Z  node0 2026-03-12T20:38:47.158174Z [init] [common/args.cpp:884] [logArgsPrefix] Config file arg: regtest="1" 
2026-03-12T20:39:20.4224263Z  node0 2026-03-12T20:38:47.158346Z [init] [common/args.cpp:884] [logArgsPrefix] Config file arg: [regtest] bind="127.0.0.1" 
2026-03-12T20:39:20.4243327Z  node0 2026-03-12T20:38:47.158484Z [init] [common/args.cpp:884] [logArgsPrefix] Config file arg: [regtest] connect="0" 
2026-03-12T20:39:20.4264740Z  node0 2026-03-12T20:38:47.158611Z [init] [common/args.cpp:884] [logArgsPrefix] Config file arg: [regtest] discover="0" 
2026-03-12T20:39:20.4267864Z  node0 2026-03-12T20:38:47.158735Z [init] [common/args.cpp:884] [logArgsPrefix] Config file arg: [regtest] dnsseed="0" 
2026-03-12T20:39:20.4284515Z  node0 2026-03-12T20:38:47.158879Z [init] [common/args.cpp:884] [logArgsPrefix] Config file arg: [regtest] fallbackfee="0.0002" 
2026-03-12T20:39:20.4324763Z  node0 2026-03-12T20:38:47.159024Z [init] [common/args.cpp:884] [logArgsPrefix] Config file arg: [regtest] fixedseeds="0" 
2026-03-12T20:39:20.4373021Z  node0 2026-03-12T20:38:47.159168Z [init] [common/args.cpp:884] [logArgsPrefix] Config file arg: [regtest] keypool="1" 
2026-03-12T20:39:20.4374806Z  node0 2026-03-12T20:38:47.159316Z [init] [common/args.cpp:884] [logArgsPrefix] Config file arg: [regtest] listenonion="0" 
2026-03-12T20:39:20.4471590Z  node0 2026-03-12T20:38:47.159445Z [init] [common/args.cpp:884] [logArgsPrefix] Config file arg: [regtest] maxconnections="94" 
2026-03-12T20:39:20.4567302Z  node0 2026-03-12T20:38:47.159572Z [init] [common/args.cpp:884] [logArgsPrefix] Config file arg: [regtest] natpmp="0" 
2026-03-12T20:39:20.4614985Z  node0 2026-03-12T20:38:47.159688Z [init] [common/args.cpp:884] [logArgsPrefix] Config file arg: [regtest] par="2" 
2026-03-12T20:39:20.4617642Z  node0 2026-03-12T20:38:47.159820Z [init] [common/args.cpp:884] [logArgsPrefix] Config file arg: [regtest] peertimeout="999999999" 
2026-03-12T20:39:20.4651063Z  node0 2026-03-12T20:38:47.159947Z [init] [common/args.cpp:884] [logArgsPrefix] Config file arg: [regtest] port="12649" 
2026-03-12T20:39:20.4675479Z  node0 2026-03-12T20:38:47.160092Z [init] [common/args.cpp:884] [logArgsPrefix] Config file arg: [regtest] printtoconsole="0" 
2026-03-12T20:39:20.4729997Z  node0 2026-03-12T20:38:47.207312Z [init] [common/args.cpp:884] [logArgsPrefix] Config file arg: [regtest] rpcdoccheck="1" 
2026-03-12T20:39:20.4731761Z  node0 2026-03-12T20:38:47.207557Z [init] [common/args.cpp:884] [logArgsPrefix] Config file arg: [regtest] rpcport="17649" 
2026-03-12T20:39:20.4739609Z  node0 2026-03-12T20:38:47.207732Z [init] [common/args.cpp:884] [logArgsPrefix] Config file arg: [regtest] rpcservertimeout="99000" 
2026-03-12T20:39:20.4756366Z  node0 2026-03-12T20:38:47.207892Z [init] [common/args.cpp:884] [logArgsPrefix] Config file arg: [regtest] rpcthreads="2" 
2026-03-12T20:39:20.4783861Z  node0 2026-03-12T20:38:47.208045Z [init] [common/args.cpp:884] [logArgsPrefix] Config file arg: [regtest] server="1" 
2026-03-12T20:39:20.4825358Z  node0 2026-03-12T20:38:47.208186Z [init] [common/args.cpp:884] [logArgsPrefix] Config file arg: [regtest] shrinkdebugfile="0" 
2026-03-12T20:39:20.4830397Z  node0 2026-03-12T20:38:47.208354Z [init] [common/args.cpp:884] [logArgsPrefix] Config file arg: [regtest] unsafesqlitesync="1" 
2026-03-12T20:39:20.4835174Z  node0 2026-03-12T20:38:47.208531Z [init] [common/args.cpp:884] [logArgsPrefix] Command-line arg: datadir="/tmp/test_runner_₿_🏃_20260312_203817/interface_ipc_553/node0" 
2026-03-12T20:39:20.4863027Z  node0 2026-03-12T20:38:47.208669Z [init] [common/args.cpp:884] [logArgsPrefix] Command-line arg: debug="" 
2026-03-12T20:39:20.4864913Z  node0 2026-03-12T20:38:47.208799Z [init] [common/args.cpp:884] [logArgsPrefix] Command-line arg: debugexclude="libevent" 
2026-03-12T20:39:20.4911048Z  node0 2026-03-12T20:38:47.208942Z [init] [common/args.cpp:884] [logArgsPrefix] Command-line arg: debugexclude="leveldb" 
2026-03-12T20:39:20.4936926Z  node0 2026-03-12T20:38:47.209064Z [init] [common/args.cpp:884] [logArgsPrefix] Command-line arg: debugexclude="rand" 
2026-03-12T20:39:20.4972983Z  node0 2026-03-12T20:38:47.209177Z [init] [common/args.cpp:884] [logArgsPrefix] Command-line arg: disablewallet="" 
2026-03-12T20:39:20.4974505Z  node0 2026-03-12T20:38:47.209341Z [init] [common/args.cpp:884] [logArgsPrefix] Command-line arg: ipcbind="unix" 
2026-03-12T20:39:20.4998841Z  node0 2026-03-12T20:38:47.209476Z [init] [common/args.cpp:884] [logArgsPrefix] Command-line arg: loglevel="trace" 
2026-03-12T20:39:20.5015781Z  node0 2026-03-12T20:38:47.209613Z [init] [common/args.cpp:884] [logArgsPrefix] Command-line arg: logratelimit=false 
2026-03-12T20:39:20.5083246Z  node0 2026-03-12T20:38:47.209736Z [init] [common/args.cpp:884] [logArgsPrefix] Command-line arg: logsourcelocations="" 
2026-03-12T20:39:20.5091651Z  node0 2026-03-12T20:38:47.209855Z [init] [common/args.cpp:884] [logArgsPrefix] Command-line arg: logthreadnames="" 
2026-03-12T20:39:20.5093347Z  node0 2026-03-12T20:38:47.242436Z [init] [common/args.cpp:884] [logArgsPrefix] Command-line arg: logtimemicros="" 
2026-03-12T20:39:20.5138532Z  node0 2026-03-12T20:38:47.242631Z [init] [common/args.cpp:884] [logArgsPrefix] Command-line arg: uacomment="testnode0" 
2026-03-12T20:39:20.5147856Z  node0 2026-03-12T20:38:47.242780Z [init] [common/args.cpp:884] [logArgsPrefix] Command-line arg: v2transport="0" 
2026-03-12T20:39:20.5155307Z  node0 2026-03-12T20:38:47.242907Z [init] [init.cpp:1441] [AppInitMain] Using at most 94 automatic connections (65536 file descriptors available) 
2026-03-12T20:39:20.5156943Z  node0 2026-03-12T20:38:47.252611Z [scheduler] [util/thread.cpp:20] [TraceThread] scheduler thread start 
2026-03-12T20:39:20.5173794Z  node0 2026-03-12T20:38:47.259003Z [init] [init.cpp:1481] [AppInitMain] Log rate limiting disabled 
2026-03-12T20:39:20.5223122Z  node0 2026-03-12T20:38:47.259287Z [init] [wallet/init.cpp:106] [Construct] Wallet disabled! 
2026-03-12T20:39:20.5247767Z  node0 2026-03-12T20:38:47.301990Z [init] [init.cpp:1509] [AppInitMain] Listening for IPC requests on address unix:/tmp/test_runner_₿_🏃_20260312_203817/interface_ipc_553/node0/regtest/node.sock 
2026-03-12T20:39:20.5265593Z  node0 2026-03-12T20:38:48.164957Z [init] [httpserver.cpp:166] [InitHTTPAllowList] [http] Allowing HTTP connections from: 127.0.0.0/8 ::1/128 
2026-03-12T20:39:20.5307366Z  node0 2026-03-12T20:38:48.165484Z [init] [httpserver.cpp:342] [HTTPBindAddresses] Binding RPC on address ::1 port 17649 
2026-03-12T20:39:20.5314088Z  node0 2026-03-12T20:38:48.165790Z [init] [httpserver.cpp:342] [HTTPBindAddresses] Binding RPC on address 127.0.0.1 port 17649 
2026-03-12T20:39:20.5392914Z  node0 2026-03-12T20:38:48.166007Z [init] [httpserver.cpp:418] [InitHTTPServer] [http] Initialized HTTP server 
2026-03-12T20:39:20.5394497Z  node0 2026-03-12T20:38:48.166204Z [init] [httpserver.cpp:420] [InitHTTPServer] [http] set work queue of depth 64 
2026-03-12T20:39:20.5421591Z  node0 2026-03-12T20:38:48.166342Z [init] [rpc/server.cpp:275] [StartRPC] [rpc] Starting RPC 
2026-03-12T20:39:20.5456195Z  node0 2026-03-12T20:38:48.166461Z [init] [httprpc.cpp:333] [StartHTTPRPC] [rpc] Starting HTTP RPC server 
2026-03-12T20:39:20.5513239Z  node0 2026-03-12T20:38:48.202553Z [init] [rpc/request.cpp:140] [GenerateAuthCookie] Generated RPC authentication cookie /tmp/test_runner_₿_🏃_20260312_203817/interface_ipc_553/node0/regtest/.cookie 
2026-03-12T20:39:20.5534171Z  node0 2026-03-12T20:38:48.202710Z [init] [rpc/request.cpp:141] [GenerateAuthCookie] Permissions used for cookie: rw------- 
2026-03-12T20:39:20.5561571Z  node0 2026-03-12T20:38:48.202823Z [init] [httprpc.cpp:265] [InitRPCAuthentication] Using random cookie authentication. 
2026-03-12T20:39:20.5566609Z  node0 2026-03-12T20:38:48.203240Z [init] [httpserver.cpp:690] [RegisterHTTPHandler] [http] Registering HTTP handler for / (exactmatch 1) 
2026-03-12T20:39:20.5621019Z  node0 2026-03-12T20:38:48.203430Z [init] [httpserver.cpp:690] [RegisterHTTPHandler] [http] Registering HTTP handler for /wallet/ (exactmatch 0) 
2026-03-12T20:39:20.5623326Z  node0 2026-03-12T20:38:48.203689Z [init] [httpserver.cpp:441] [StartHTTPServer] Starting HTTP server with 2 worker threads 
2026-03-12T20:39:20.5679553Z  node0 2026-03-12T20:38:48.204328Z [http_pool_0] [util/thread.cpp:20] [TraceThread] http_pool_0 thread start 
2026-03-12T20:39:20.5685359Z  node0 2026-03-12T20:38:48.207572Z [http_pool_0] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_mutex, util/threadpool.h:62 started 
2026-03-12T20:39:20.5716396Z  node0 2026-03-12T20:38:48.207971Z [http_pool_1] [util/thread.cpp:20] [TraceThread] http_pool_1 thread start 
2026-03-12T20:39:20.5751719Z  node0 2026-03-12T20:38:48.208241Z [http_pool_1] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_mutex, util/threadpool.h:62 started 
2026-03-12T20:39:20.5753602Z  node0 2026-03-12T20:38:48.224290Z [init] [init.cpp:1631] [AppInitMain] Using /16 prefix for IP bucketing 
2026-03-12T20:39:20.5804582Z  node0 2026-03-12T20:38:48.224455Z [init] [noui.cpp:56] [noui_InitMessage] init message: Loading P2P addresses… 
2026-03-12T20:39:20.5868994Z  node0 2026-03-12T20:38:48.227356Z [http] [httpserver.cpp:302] [ThreadHTTP] [http] Entering http event loop 
2026-03-12T20:39:20.5887891Z  node0 2026-03-12T20:38:48.244695Z [http_pool_0] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_mutex, util/threadpool.h:62 completed (36878μs) 
2026-03-12T20:39:20.5890272Z  node0 2026-03-12T20:38:48.261804Z [http_pool_1] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_mutex, util/threadpool.h:62 completed (53326μs) 
2026-03-12T20:39:20.5934220Z  node0 2026-03-12T20:38:48.354833Z [init] [addrdb.cpp:211] [LoadAddrman] Creating peers.dat because the file was not found ("/tmp/test_runner_₿_🏃_20260312_203817/interface_ipc_553/node0/regtest/peers.dat") 
2026-03-12T20:39:20.5962069Z  node0 2026-03-12T20:38:48.412878Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:46646 
2026-03-12T20:39:20.5998216Z  node0 2026-03-12T20:38:48.413828Z [http_pool_0] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
2026-03-12T20:39:20.6000200Z  node0 2026-03-12T20:38:48.553495Z [init] [noui.cpp:56] [noui_InitMessage] init message: Loading banlist… 
2026-03-12T20:39:20.6091908Z  node0 2026-03-12T20:38:48.553711Z [init] [banman.cpp:42] [LoadBanlist] Recreating the banlist database 
2026-03-12T20:39:20.6134123Z  node0 2026-03-12T20:38:48.554167Z [init] [banman.cpp:69] [DumpBanlist] [net] Flushed 0 banned node addresses/subnets to disk 0ms 
2026-03-12T20:39:20.6191345Z  node0 2026-03-12T20:38:48.557495Z [init] [net.cpp:2437] [SetTryNewOutboundPeer] [net] setting try another outbound peer=false 
2026-03-12T20:39:20.6193280Z  node0 2026-03-12T20:38:48.557708Z [init] [net.cpp:3359] [SetNetworkActive] SetNetworkActive: true 
2026-03-12T20:39:20.6200380Z  node0 2026-03-12T20:38:48.699755Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:46658 
2026-03-12T20:39:20.6220656Z  node0 2026-03-12T20:38:48.700787Z [http_pool_1] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
2026-03-12T20:39:20.6287890Z  node0 2026-03-12T20:38:48.942719Z [init] [policy/fees/block_policy_estimator.cpp:564] [CBlockPolicyEstimator] /tmp/test_runner_₿_🏃_20260312_203817/interface_ipc_553/node0/regtest/fee_estimates.dat is not found. Continue anyway. 
2026-03-12T20:39:20.6290337Z  node0 2026-03-12T20:38:48.943693Z [init] [init.cpp:1833] [AppInitMain] Cache configuration: 
2026-03-12T20:39:20.6317688Z  node0 2026-03-12T20:38:48.943807Z [init] [init.cpp:1834] [AppInitMain] * Using 2.0 MiB for block index database 
2026-03-12T20:39:20.6374830Z  node0 2026-03-12T20:38:48.943999Z [init] [init.cpp:1845] [AppInitMain] * Using 8.0 MiB for chain state database 
2026-03-12T20:39:20.6416990Z  node0 2026-03-12T20:38:48.972424Z [init] [init.cpp:1328] [InitAndLoadChainstate] * Using 1014.0 MiB for in-memory UTXO set (plus up to 286.1 MiB of unused mempool space) 
2026-03-12T20:39:20.6418936Z  node0 2026-03-12T20:38:48.973190Z [init] [checkqueue.h:147] [CCheckQueue] Script verification uses 1 additional threads 
2026-03-12T20:39:20.6464090Z  node0 2026-03-12T20:38:48.991796Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:46670 
2026-03-12T20:39:20.6510357Z  node0 2026-03-12T20:38:49.003638Z [http_pool_0] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
2026-03-12T20:39:20.6537991Z  node0 2026-03-12T20:38:49.009955Z [init] [node/blockstorage.cpp:1220] [InitBlocksdirXorKey] Using obfuscation key for blocksdir *.dat files (/tmp/test_runner_₿_🏃_20260312_203817/interface_ipc_553/node0/regtest/blocks): '483dac57094756bf' 
2026-03-12T20:39:20.6723452Z  node0 2026-03-12T20:38:49.010192Z [init] [dbwrapper.cpp:237] [CDBWrapper] Opening LevelDB in /tmp/test_runner_₿_🏃_20260312_203817/interface_ipc_553/node0/regtest/blocks/index 
2026-03-12T20:39:20.6732301Z  node0 2026-03-12T20:38:49.142635Z [init] [dbwrapper.cpp:245] [CDBWrapper] Opened LevelDB successfully 
2026-03-12T20:39:20.6743120Z  node0 2026-03-12T20:38:49.142858Z [init] [dbwrapper.cpp:261] [CDBWrapper] Using obfuscation key for /tmp/test_runner_₿_🏃_20260312_203817/interface_ipc_553/node0/regtest/blocks/index: 0000000000000000 
2026-03-12T20:39:20.6754207Z  node0 2026-03-12T20:38:49.279875Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:46672 
2026-03-12T20:39:20.6831513Z  node0 2026-03-12T20:38:49.297359Z [http_pool_1] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
2026-03-12T20:39:20.6843761Z  node0 2026-03-12T20:38:49.588444Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:46686 
2026-03-12T20:39:20.6850700Z  node0 2026-03-12T20:38:49.604822Z [http_pool_0] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
2026-03-12T20:39:20.6904083Z  node0 2026-03-12T20:38:49.889297Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:46692 
2026-03-12T20:39:20.6949296Z  node0 2026-03-12T20:38:49.905368Z [http_pool_1] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
2026-03-12T20:39:20.6951499Z  node0 2026-03-12T20:38:50.193887Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:46700 
2026-03-12T20:39:20.6957197Z  node0 2026-03-12T20:38:50.203405Z [http_pool_0] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
2026-03-12T20:39:20.6969920Z  node0 2026-03-12T20:38:50.490687Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:46710 
2026-03-12T20:39:20.7013330Z  node0 2026-03-12T20:38:50.509042Z [http_pool_1] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
2026-03-12T20:39:20.7015103Z  node0 2026-03-12T20:38:50.800829Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:46716 
2026-03-12T20:39:20.7045471Z  node0 2026-03-12T20:38:50.809288Z [http_pool_0] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
2026-03-12T20:39:20.7074784Z  node0 2026-03-12T20:38:51.082594Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:46728 
2026-03-12T20:39:20.7089785Z  node0 2026-03-12T20:38:51.094441Z [http_pool_1] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
2026-03-12T20:39:20.7103082Z  node0 2026-03-12T20:38:51.379841Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:46732 
2026-03-12T20:39:20.7105138Z  node0 2026-03-12T20:38:51.397835Z [http_pool_0] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
2026-03-12T20:39:20.7134701Z  node0 2026-03-12T20:38:51.683640Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:46740 
2026-03-12T20:39:20.7177982Z  node0 2026-03-12T20:38:51.703131Z [http_pool_1] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
2026-03-12T20:39:20.7228649Z  node0 2026-03-12T20:38:51.941530Z [init] [script/sigcache.cpp:36] [SignatureCache] Using 16 MiB out of 16 MiB requested for signature cache, able to store 524288 elements 
2026-03-12T20:39:20.7230816Z  node0 2026-03-12T20:38:51.972278Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:46754 
2026-03-12T20:39:20.7257454Z  node0 2026-03-12T20:38:51.974233Z [http_pool_0] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
2026-03-12T20:39:20.7318551Z  node0 2026-03-12T20:38:52.232905Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:46760 
2026-03-12T20:39:20.7343941Z  node0 2026-03-12T20:38:52.236042Z [http_pool_1] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
2026-03-12T20:39:20.7353939Z  node0 2026-03-12T20:38:52.489762Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:46776 
2026-03-12T20:39:20.7370063Z  node0 2026-03-12T20:38:52.491783Z [http_pool_0] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
2026-03-12T20:39:20.7381837Z  node0 2026-03-12T20:38:52.769003Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:46782 
2026-03-12T20:39:20.7419946Z  node0 2026-03-12T20:38:52.785842Z [http_pool_1] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
2026-03-12T20:39:20.7422218Z  node0 2026-03-12T20:38:52.895767Z [init] [validation.cpp:2036] [ValidationCache] Using 16 MiB out of 16 MiB requested for script execution cache, able to store 524288 elements 
2026-03-12T20:39:20.7563585Z  node0 2026-03-12T20:38:52.896248Z [init] [noui.cpp:56] [noui_InitMessage] init message: Loading block index… 
2026-03-12T20:39:20.7623711Z  node0 2026-03-12T20:38:52.896454Z [init] [node/chainstate.cpp:157] [LoadChainstate] Validating signatures for all blocks. 
2026-03-12T20:39:20.7647003Z  node0 2026-03-12T20:38:52.896589Z [init] [node/chainstate.cpp:159] [LoadChainstate] Setting nMinimumChainWork=0000000000000000000000000000000000000000000000000000000000000000 
2026-03-12T20:39:20.7649044Z  node0 2026-03-12T20:38:53.065793Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:46788 
2026-03-12T20:39:20.7672521Z  node0 2026-03-12T20:38:53.087402Z [http_pool_0] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
2026-03-12T20:39:20.7680381Z  node0 2026-03-12T20:38:53.230627Z [init] [node/blockstorage.cpp:539] [LoadBlockIndexDB] Loading block index db: last block file = 0 
2026-03-12T20:39:20.7688343Z  node0 2026-03-12T20:38:53.231048Z [init] [node/blockstorage.cpp:543] [LoadBlockIndexDB] Loading block index db: last block file info: CBlockFileInfo(blocks=200, size=52530, heights=0...199, time=2011-02-02...2011-02-02) 
2026-03-12T20:39:20.7806566Z  node0 2026-03-12T20:38:53.231247Z [init] [node/blockstorage.cpp:554] [LoadBlockIndexDB] Checking all blk files are present... 
2026-03-12T20:39:20.7863394Z  node0 2026-03-12T20:38:53.269503Z [init] [node/chainstate.cpp:87] [CompleteChainstateInitialization] Initializing chainstate Chainstate [ibd] @ height -1 (null) 
2026-03-12T20:39:20.7901317Z  node0 2026-03-12T20:38:53.269789Z [init] [dbwrapper.cpp:237] [CDBWrapper] Opening LevelDB in /tmp/test_runner_₿_🏃_20260312_203817/interface_ipc_553/node0/regtest/chainstate 
2026-03-12T20:39:20.7904582Z  node0 2026-03-12T20:38:53.376892Z [init] [dbwrapper.cpp:245] [CDBWrapper] Opened LevelDB successfully 
2026-03-12T20:39:20.7906919Z  node0 2026-03-12T20:38:53.377247Z [init] [dbwrapper.cpp:261] [CDBWrapper] Using obfuscation key for /tmp/test_runner_₿_🏃_20260312_203817/interface_ipc_553/node0/regtest/chainstate: fd83718dc51bd8f5 
2026-03-12T20:39:21.0421335Z  node0 2026-03-12T20:38:53.391318Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:33508 
2026-03-12T20:39:21.0474338Z  node0 2026-03-12T20:38:53.404599Z [http_pool_1] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
2026-03-12T20:39:21.0478966Z  node0 2026-03-12T20:38:53.408772Z [init] [validation.cpp:4580] [LoadChainTip] Loaded best chain: hashBestChain=30068a561f1d748696d6fe1368b2b9b9f765095cda5b767b291e8bf84caff9f1 height=199 date=2011-02-02T23:17:17Z progress=0.000419 
2026-03-12T20:39:21.0481595Z  node0 2026-03-12T20:38:53.410783Z [init] [noui.cpp:56] [noui_InitMessage] init message: Verifying blocks… 
2026-03-12T20:39:21.0485379Z  node0 2026-03-12T20:38:53.411067Z [init] [validation.cpp:4624] [VerifyDB] Verifying last 6 blocks at level 3 
2026-03-12T20:39:21.0518703Z  node0 2026-03-12T20:38:53.441712Z [init] [validation.cpp:4633] [VerifyDB] Verification progress: 0% 
2026-03-12T20:39:21.0567377Z  node0 2026-03-12T20:38:53.638759Z [init] [validation.cpp:4641] [VerifyDB] Verification progress: 16% 
2026-03-12T20:39:21.0569070Z  node0 2026-03-12T20:38:53.690697Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:33510 
2026-03-12T20:39:21.0604846Z  node0 2026-03-12T20:38:53.691596Z [http_pool_0] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
2026-03-12T20:39:21.0643836Z  node0 2026-03-12T20:38:53.853215Z [init] [validation.cpp:4641] [VerifyDB] Verification progress: 33% 
2026-03-12T20:39:21.0650675Z  node0 2026-03-12T20:38:53.985909Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:33520 
2026-03-12T20:39:21.0683019Z  node0 2026-03-12T20:38:54.003842Z [http_pool_1] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
2026-03-12T20:39:21.0684426Z  node0 2026-03-12T20:38:54.185997Z [init] [validation.cpp:4641] [VerifyDB] Verification progress: 50% 
2026-03-12T20:39:21.0693137Z  node0 2026-03-12T20:38:54.314990Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:33534 
2026-03-12T20:39:21.0733321Z  node0 2026-03-12T20:38:54.329053Z [http_pool_0] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
2026-03-12T20:39:21.0752952Z  node0 2026-03-12T20:38:54.476846Z [init] [validation.cpp:4641] [VerifyDB] Verification progress: 66% 
2026-03-12T20:39:21.0763362Z  node0 2026-03-12T20:38:54.608973Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:33550 
2026-03-12T20:39:21.0765191Z  node0 2026-03-12T20:38:54.627690Z [http_pool_1] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
2026-03-12T20:39:21.0806779Z  node0 2026-03-12T20:38:54.708865Z [init] [validation.cpp:4641] [VerifyDB] Verification progress: 83% 
2026-03-12T20:39:21.0820024Z  node0 2026-03-12T20:38:54.912789Z [init] [validation.cpp:4641] [VerifyDB] Verification progress: 99% 
2026-03-12T20:39:21.0825843Z  node0 2026-03-12T20:38:54.912977Z [init] [validation.cpp:4735] [VerifyDB] Verification: No coin database inconsistencies in last 6 blocks (6 transactions) 
2026-03-12T20:39:21.0827712Z  node0 2026-03-12T20:38:54.925693Z [init] [init.cpp:1414] [InitAndLoadChainstate] Block index and chainstate loaded 
2026-03-12T20:39:21.0858356Z  node0 2026-03-12T20:38:54.934483Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:33562 
2026-03-12T20:39:21.0879473Z  node0 2026-03-12T20:38:54.938438Z [http_pool_0] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
2026-03-12T20:39:21.0886428Z  node0 2026-03-12T20:38:54.963282Z [init] [init.cpp:1949] [AppInitMain] Setting NODE_NETWORK in non-prune mode 
2026-03-12T20:39:21.0891770Z  node0 2026-03-12T20:38:54.964113Z [initload] [util/thread.cpp:20] [TraceThread] initload thread start 
2026-03-12T20:39:21.0897908Z  node0 2026-03-12T20:38:54.968225Z [initload] [node/mempool_persist.cpp:49] [LoadMempool] Failed to open mempool file. Continuing anyway. 
2026-03-12T20:39:21.0909377Z  node0 2026-03-12T20:38:54.994533Z [initload] [util/thread.cpp:22] [TraceThread] initload thread exit 
2026-03-12T20:39:21.0940466Z  node0 2026-03-12T20:38:54.994950Z [init] [init.cpp:2080] [AppInitMain] block tree size = 200 
2026-03-12T20:39:21.0969303Z  node0 2026-03-12T20:38:54.995118Z [init] [init.cpp:2093] [AppInitMain] nBestHeight = 199 
2026-03-12T20:39:21.0988664Z  node0 2026-03-12T20:38:54.996666Z [init] [net.cpp:3332] [BindListenPort] Bound to 127.0.0.1:12649 
2026-03-12T20:39:21.0996340Z  node0 2026-03-12T20:38:54.996918Z [init] [noui.cpp:56] [noui_InitMessage] init message: Starting network threads… 
2026-03-12T20:39:21.1082839Z  node0 2026-03-12T20:38:55.090493Z [net] [util/thread.cpp:20] [TraceThread] net thread start 
2026-03-12T20:39:21.1163453Z  node0 2026-03-12T20:38:55.090963Z [init] [net.cpp:3528] [Start] DNS seeding disabled 
2026-03-12T20:39:21.1165021Z  node0 2026-03-12T20:38:55.093778Z [addcon] [util/thread.cpp:20] [TraceThread] addcon thread start 
2026-03-12T20:39:21.1229525Z  node0 2026-03-12T20:38:55.100119Z [init] [noui.cpp:56] [noui_InitMessage] init message: Done loading 
2026-03-12T20:39:21.1241005Z  node0 2026-03-12T20:38:55.100906Z [msghand] [util/thread.cpp:20] [TraceThread] msghand thread start 
2026-03-12T20:39:21.1248333Z  node0 2026-03-12T20:38:55.214241Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:33572 
2026-03-12T20:39:21.1250134Z  node0 2026-03-12T20:38:55.231802Z [http_pool_1] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
2026-03-12T20:39:21.1388367Z  node0 2026-03-12T20:38:55.257788Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:33572 
2026-03-12T20:39:21.1401882Z  node0 2026-03-12T20:38:55.266705Z [http_pool_0] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getmempoolinfo user=__cookie__ 
2026-03-12T20:39:21.1412864Z  test  2026-03-12T20:38:55.291623Z TestFramework.node0 (DEBUG): RPC successfully started 
2026-03-12T20:39:21.1414805Z  node0 2026-03-12T20:38:55.292399Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:33572 
2026-03-12T20:39:21.1463489Z  node0 2026-03-12T20:38:55.314725Z [http_pool_1] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockchaininfo user=__cookie__ 
2026-03-12T20:39:21.1493673Z  test  2026-03-12T20:38:55.327731Z TestFramework (DEBUG): Generate a block with current time 
2026-03-12T20:39:21.1543197Z  test  2026-03-12T20:38:55.327894Z TestFramework.node0 (DEBUG): TestNode.generate() dispatches `generate` call to `generatetoaddress` 
2026-03-12T20:39:21.1552168Z  node0 2026-03-12T20:38:55.339610Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:33572 
2026-03-12T20:39:21.1554096Z  node0 2026-03-12T20:38:55.347881Z [http_pool_0] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=generatetoaddress user=__cookie__ 
2026-03-12T20:39:21.1561100Z  node0 2026-03-12T20:38:55.350032Z [http_pool_0] [node/miner.cpp:215] [CreateNewBlock] CreateNewBlock(): block weight: 904 txs: 0 fees: 0 sigops 400 
2026-03-12T20:39:21.1577020Z  node0 2026-03-12T20:38:55.384623Z [http_pool_0] [validation.cpp:2387] [ConnectBlock] [bench]     - Sanity checks: 0.10ms [0.00s (0.10ms/blk)] 
2026-03-12T20:39:21.1624482Z  node0 2026-03-12T20:38:55.385089Z [http_pool_0] [validation.cpp:2489] [ConnectBlock] [bench]     - Fork checks: 0.51ms [0.00s (0.51ms/blk)] 
2026-03-12T20:39:21.1627641Z  node0 2026-03-12T20:38:55.385277Z [http_pool_0] [validation.cpp:2496] [ConnectBlock] Enabling script verification at block #200 (30834aeeab709f1c6be9b9b30450740e09116b86c7500b0c40d203a96417bcce): assumevalid=0 (always verify). 
2026-03-12T20:39:21.1742402Z  node0 2026-03-12T20:38:55.385569Z [http_pool_0] [validation.cpp:2605] [ConnectBlock] [bench]       - Connect 1 transactions: 0.46ms (0.462ms/tx, 0.000ms/txin) [0.00s (0.46ms/blk)] 
2026-03-12T20:39:21.1773902Z  node0 2026-03-12T20:38:55.385860Z [http_pool_0] [validation.cpp:2628] [ConnectBlock] [bench]     - Verify 0 txins: 0.76ms (0.000ms/txin) [0.00s (0.76ms/blk)] 
2026-03-12T20:39:21.1787331Z  node0 2026-03-12T20:38:55.420565Z [http_pool_0] [node/miner.cpp:234] [CreateNewBlock] [bench] CreateNewBlock() chunks: 0.24ms, validity: 70.93ms (total 71.18ms) 
2026-03-12T20:39:21.1789085Z  node0 2026-03-12T20:38:55.538059Z [http_pool_0] [validation.cpp:3021] [ConnectTip] [bench]   - Using cached block 
2026-03-12T20:39:21.1797591Z  node0 2026-03-12T20:38:55.538200Z [http_pool_0] [validation.cpp:3029] [ConnectTip] [bench]   - Load block from disk: 0.14ms 
2026-03-12T20:39:21.1804252Z  node0 2026-03-12T20:38:55.538408Z [http_pool_0] [validation.cpp:2387] [ConnectBlock] [bench]     - Sanity checks: 0.01ms [0.00s (0.06ms/blk)] 
2026-03-12T20:39:21.1937360Z  node0 2026-03-12T20:38:55.538769Z [http_pool_0] [validation.cpp:2489] [ConnectBlock] [bench]     - Fork checks: 0.37ms [0.00s (0.44ms/blk)] 
2026-03-12T20:39:21.1940265Z  node0 2026-03-12T20:38:55.539044Z [http_pool_0] [validation.cpp:2605] [ConnectBlock] [bench]       - Connect 1 transactions: 0.25ms (0.254ms/tx, 0.000ms/txin) [0.00s (0.36ms/blk)] 
2026-03-12T20:39:21.1998350Z  node0 2026-03-12T20:38:55.539289Z [http_pool_0] [validation.cpp:2628] [ConnectBlock] [bench]     - Verify 0 txins: 0.49ms (0.000ms/txin) [0.00s (0.62ms/blk)] 
2026-03-12T20:39:21.2006790Z  node0 2026-03-12T20:38:55.652619Z [http_pool_0] [validation.cpp:2643] [ConnectBlock] [bench]     - Write undo data: 113.33ms [0.11s (56.67ms/blk)] 
2026-03-12T20:39:21.2053284Z  node0 2026-03-12T20:38:55.652769Z [http_pool_0] [validation.cpp:2658] [ConnectBlock] [bench]     - Index writing: 0.19ms [0.00s (0.09ms/blk)] 
2026-03-12T20:39:21.2059309Z  node0 2026-03-12T20:38:55.652935Z [http_pool_0] [validationinterface.cpp:256] [BlockChecked] [validation] BlockChecked: block hash=068c09fbdac88e084ac4c8c5e876a5532b7c2ee1d72f967384a77ef5ef7c1a72 state=Valid 
2026-03-12T20:39:21.2061975Z  node0 2026-03-12T20:38:55.653246Z [http_pool_0] [validation.cpp:3049] [ConnectTip] [bench]   - Connect total: 115.04ms [0.12s (57.52ms/blk)] 
2026-03-12T20:39:21.2124035Z  node0 2026-03-12T20:38:55.653437Z [http_pool_0] [validation.cpp:3057] [ConnectTip] [bench]   - Flush: 0.19ms [0.00s (0.10ms/blk)] 
2026-03-12T20:39:21.2131335Z  node0 2026-03-12T20:38:55.653689Z [http_pool_0] [validation.cpp:3067] [ConnectTip] [bench]   - Writing chainstate: 0.25ms [0.00s (0.13ms/blk)] 
2026-03-12T20:39:21.2216380Z  node0 2026-03-12T20:38:55.653825Z [http_pool_0] [validationinterface.cpp:231] [MempoolTransactionsRemovedForBlock] [validation] Enqueuing MempoolTransactionsRemovedForBlock: block height=200 txs removed=0 
2026-03-12T20:39:21.2219878Z  node0 2026-03-12T20:38:55.654225Z [http_pool_0] [validation.cpp:3285] [UpdateIBDStatus] Leaving InitialBlockDownload (latching to false) 
2026-03-12T20:39:21.2286570Z  node0 2026-03-12T20:38:55.718071Z [http_pool_0] [validation.cpp:2875] [UpdateTipLog] UpdateTip: new best=068c09fbdac88e084ac4c8c5e876a5532b7c2ee1d72f967384a77ef5ef7c1a72 height=200 version=0x30000000 log2_work=8.651052 tx=201 date='2026-03-12T20:38:55Z' progress=1.000000 cache=0.3MiB(1txo) 
2026-03-12T20:39:21.2335029Z  node0 2026-03-12T20:38:55.718251Z [http_pool_0] [validation.cpp:3084] [ConnectTip] [bench]   - Connect postprocess: 64.55ms [0.06s (32.28ms/blk)] 
2026-03-12T20:39:21.2363795Z  node0 2026-03-12T20:38:55.718397Z [http_pool_0] [validation.cpp:3088] [ConnectTip] [bench] - Connect block: 180.17ms [0.18s (90.09ms/blk)] 
2026-03-12T20:39:21.2378236Z  node0 2026-03-12T20:38:55.718684Z [scheduler] [validationinterface.cpp:231] [operator()] [validation] MempoolTransactionsRemovedForBlock: block height=200 txs removed=0 
2026-03-12T20:39:21.2380356Z  node0 2026-03-12T20:38:55.721293Z [http_pool_0] [txmempool.cpp:441] [check] [mempool] Checking mempool with 0 transactions and 0 inputs 
2026-03-12T20:39:21.2385472Z  node0 2026-03-12T20:38:55.722907Z [http_pool_0] [validationinterface.cpp:221] [BlockConnected] [validation] Enqueuing BlockConnected: block hash=068c09fbdac88e084ac4c8c5e876a5532b7c2ee1d72f967384a77ef5ef7c1a72 block height=200 
2026-03-12T20:39:21.2438720Z  node0 2026-03-12T20:38:55.723161Z [http_pool_0] [validationinterface.cpp:185] [UpdatedBlockTip] [validation] Enqueuing UpdatedBlockTip: new block hash=068c09fbdac88e084ac4c8c5e876a5532b7c2ee1d72f967384a77ef5ef7c1a72 fork block hash=30068a561f1d748696d6fe1368b2b9b9f765095cda5b767b291e8bf84caff9f1 (in IBD=false) 
2026-03-12T20:39:21.2442813Z  node0 2026-03-12T20:38:55.753627Z [scheduler] [policy/fees/block_policy_estimator.cpp:712] [processBlock] [estimatefee] 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 
2026-03-12T20:39:21.2445159Z  node0 2026-03-12T20:38:55.762859Z [http_pool_0] [validationinterface.cpp:190] [ActiveTipChange] [validation] ActiveTipChange: new block hash=068c09fbdac88e084ac4c8c5e876a5532b7c2ee1d72f967384a77ef5ef7c1a72 block height=200 
2026-03-12T20:39:21.2447296Z  node0 2026-03-12T20:38:55.768647Z [scheduler] [validationinterface.cpp:221] [operator()] [validation] BlockConnected: block hash=068c09fbdac88e084ac4c8c5e876a5532b7c2ee1d72f967384a77ef5ef7c1a72 block height=200 
2026-03-12T20:39:21.2449024Z  node0 2026-03-12T20:38:55.768886Z [scheduler] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_tx_download_mutex, net_processing.cpp:2085 started 
2026-03-12T20:39:21.2450877Z  node0 2026-03-12T20:38:55.950788Z [scheduler] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_tx_download_mutex, net_processing.cpp:2085 completed (181751μs) 
2026-03-12T20:39:21.2452255Z  node0 2026-03-12T20:38:55.990458Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:33572 
2026-03-12T20:39:21.2453652Z  node0 2026-03-12T20:38:55.991221Z [http_pool_1] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblock user=__cookie__ 
2026-03-12T20:39:21.2454837Z  node0 2026-03-12T20:38:56.047698Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:33572 
2026-03-12T20:39:21.2456403Z  node0 2026-03-12T20:38:56.048492Z [http_pool_0] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=submitblock user=__cookie__ 
2026-03-12T20:39:21.2457652Z  node0 2026-03-12T20:38:56.095758Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:33572 
2026-03-12T20:39:21.2458931Z  node0 2026-03-12T20:38:56.111089Z [http_pool_1] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getblockchaininfo user=__cookie__ 
2026-03-12T20:39:21.2461202Z  node0 2026-03-12T20:38:56.130743Z [scheduler] [validationinterface.cpp:185] [operator()] [validation] UpdatedBlockTip: new block hash=068c09fbdac88e084ac4c8c5e876a5532b7c2ee1d72f967384a77ef5ef7c1a72 fork block hash=30068a561f1d748696d6fe1368b2b9b9f765095cda5b767b291e8bf84caff9f1 (in IBD=false) 
2026-03-12T20:39:21.2724900Z  node0 2026-03-12T20:38:56.418099Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:33572 
2026-03-12T20:39:21.2727611Z  node0 2026-03-12T20:38:56.438015Z [http_pool_0] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getbestblockhash user=__cookie__ 
2026-03-12T20:39:21.2737737Z  node0 2026-03-12T20:38:56.467872Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:33572 
2026-03-12T20:39:21.2739632Z  node0 2026-03-12T20:38:56.491174Z [http_pool_1] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getrawmempool user=__cookie__ 
2026-03-12T20:39:21.2741467Z  node0 2026-03-12T20:38:56.545686Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:33572 
2026-03-12T20:39:21.2743333Z  node0 2026-03-12T20:38:56.570679Z [http_pool_0] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=syncwithvalidationinterfacequeue user=__cookie__ 
2026-03-12T20:39:21.2744661Z  test  2026-03-12T20:38:56.595317Z TestFramework (INFO): Running echo test 
2026-03-12T20:39:21.2745514Z  test  2026-03-12T20:38:56.634479Z TestFramework (DEBUG): Create Echo proxy object 
2026-03-12T20:39:21.2746442Z  test  2026-03-12T20:38:56.634756Z TestFramework (DEBUG): Test a few invocations of echo 
2026-03-12T20:39:21.2747882Z  node0 2026-03-12T20:38:56.682296Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server recv request  #1 Init.construct$Params 
2026-03-12T20:39:21.2749726Z  node0 2026-03-12T20:38:56.682636Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} request data: () 
2026-03-12T20:39:21.2751566Z  node0 2026-03-12T20:38:56.683055Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server send response #1 Init.construct$Results 
2026-03-12T20:39:21.2753780Z  node0 2026-03-12T20:38:56.734820Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} response data: (threadMap = <external capability>) 
2026-03-12T20:39:21.2755752Z  node0 2026-03-12T20:38:56.781141Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server recv request  #2 Init.makeEcho$Params 
2026-03-12T20:39:21.2757846Z  node0 2026-03-12T20:38:56.781865Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} request data: (context = (thread = <external capability>)) 
2026-03-12T20:39:21.2760210Z  node0 2026-03-12T20:38:56.864823Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server post request  #2 {bitcoin-node-9523/b-capnp-loop-9955 (from pythread)} 
2026-03-12T20:39:21.2762265Z  node0 2026-03-12T20:38:56.917631Z [unknown] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9955 (from pythread)} IPC server executing request #2 
2026-03-12T20:39:21.2936489Z  node0 2026-03-12T20:38:56.985152Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server send response #2 Init.makeEcho$Results 
2026-03-12T20:39:21.2939768Z  node0 2026-03-12T20:38:56.985622Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} response data: (result = <external capability>) 
2026-03-12T20:39:21.2941882Z  node0 2026-03-12T20:38:56.997846Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server recv request  #3 Echo.echo$Params 
2026-03-12T20:39:21.2944176Z  node0 2026-03-12T20:38:56.998562Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} request data: (context = (thread = <external capability>), echo = "hallo") 
2026-03-12T20:39:21.2946533Z  node0 2026-03-12T20:38:56.999070Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server post request  #3 {bitcoin-node-9523/b-capnp-loop-9955 (from pythread)} 
2026-03-12T20:39:21.2948707Z  node0 2026-03-12T20:38:57.057752Z [unknown] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9955 (from pythread)} IPC server executing request #3 
2026-03-12T20:39:21.2950763Z  node0 2026-03-12T20:38:57.068223Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server send response #3 Echo.echo$Results 
2026-03-12T20:39:21.3034598Z  node0 2026-03-12T20:38:57.068651Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} response data: (result = "hallo") 
2026-03-12T20:39:21.3036919Z  node0 2026-03-12T20:38:57.090081Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server recv request  #4 Echo.echo$Params 
2026-03-12T20:39:21.3038932Z  node0 2026-03-12T20:38:57.142943Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} request data: (context = (thread = <external capability>), echo = "") 
2026-03-12T20:39:21.3041152Z  node0 2026-03-12T20:38:57.143463Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server post request  #4 {bitcoin-node-9523/b-capnp-loop-9955 (from pythread)} 
2026-03-12T20:39:21.3141026Z  node0 2026-03-12T20:38:57.185576Z [unknown] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9955 (from pythread)} IPC server executing request #4 
2026-03-12T20:39:21.3143727Z  node0 2026-03-12T20:38:57.199587Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server send response #4 Echo.echo$Results 
2026-03-12T20:39:21.3146838Z  node0 2026-03-12T20:38:57.199974Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} response data: (result = "") 
2026-03-12T20:39:21.3164306Z  node0 2026-03-12T20:38:57.245498Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server recv request  #5 Echo.echo$Params 
2026-03-12T20:39:21.3166343Z  node0 2026-03-12T20:38:57.245938Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} request data: (context = (thread = <external capability>), echo = "haha") 
2026-03-12T20:39:21.3168551Z  node0 2026-03-12T20:38:57.246232Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server post request  #5 {bitcoin-node-9523/b-capnp-loop-9955 (from pythread)} 
2026-03-12T20:39:21.3170609Z  node0 2026-03-12T20:38:57.267816Z [unknown] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9955 (from pythread)} IPC server executing request #5 
2026-03-12T20:39:21.3253108Z  node0 2026-03-12T20:38:57.315991Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server send response #5 Echo.echo$Results 
2026-03-12T20:39:21.3371700Z  node0 2026-03-12T20:38:57.316275Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} response data: (result = "haha") 
2026-03-12T20:39:21.3385248Z  test  2026-03-12T20:38:57.336881Z TestFramework (DEBUG): Destroy the Echo object 
2026-03-12T20:39:21.3386547Z  test  2026-03-12T20:38:57.337552Z TestFramework (INFO): Running mining test 
2026-03-12T20:39:21.3417494Z  test  2026-03-12T20:38:57.338196Z TestFramework (DEBUG): Create Mining proxy object 
2026-03-12T20:39:21.3556131Z  test  2026-03-12T20:38:57.338402Z TestFramework (DEBUG): Test simple inspectors 
2026-03-12T20:39:21.3580608Z  node0 2026-03-12T20:38:57.374039Z [capnp-loop] [ipc/capnp/protocol.cpp:53] [IpcLogFn] ipc: {bitcoin-node-9523/b-capnp-loop-9612} IPC server destroy N2mp11ProxyServerIN3ipc5capnp8messages4EchoEEE 
2026-03-12T20:39:21.3583490Z  node0 2026-03-12T20:38:57.467277Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server recv request  #6 Init.construct$Params 
2026-03-12T20:39:21.3659590Z  node0 2026-03-12T20:38:57.467530Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} request data: () 
2026-03-12T20:39:21.3669098Z  node0 2026-03-12T20:38:57.490415Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server send response #6 Init.construct$Results 
2026-03-12T20:39:21.3703550Z  node0 2026-03-12T20:38:57.490775Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} response data: (threadMap = <external capability>) 
2026-03-12T20:39:21.3706542Z  node0 2026-03-12T20:38:57.548721Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server recv request  #7 Init.makeMining$Params 
2026-03-12T20:39:21.3734426Z  node0 2026-03-12T20:38:57.549278Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} request data: (context = (thread = <external capability>)) 
2026-03-12T20:39:21.3764197Z  node0 2026-03-12T20:38:57.549578Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server post request  #7 {bitcoin-node-9523/b-capnp-loop-9971 (from pythread)} 
2026-03-12T20:39:21.3793469Z  node0 2026-03-12T20:38:57.617766Z [capnp-loop] [ipc/capnp/protocol.cpp:53] [IpcLogFn] ipc: {bitcoin-node-9523/b-capnp-loop-9612} IPC server: socket disconnected. 
2026-03-12T20:39:21.3796057Z  node0 2026-03-12T20:38:57.617999Z [capnp-loop] [ipc/capnp/protocol.cpp:53] [IpcLogFn] ipc: {bitcoin-node-9523/b-capnp-loop-9612} IPC server destroy N2mp11ProxyServerIN3ipc5capnp8messages4InitEEE 
2026-03-12T20:39:21.3840897Z  node0 2026-03-12T20:38:57.683946Z [unknown] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9971 (from pythread)} IPC server executing request #7 
2026-03-12T20:39:21.3871365Z  node0 2026-03-12T20:38:57.729655Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server send response #7 Init.makeMining$Results 
2026-03-12T20:39:21.3894245Z  node0 2026-03-12T20:38:57.730397Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} response data: (result = <external capability>) 
2026-03-12T20:39:21.3918481Z  node0 2026-03-12T20:38:57.730869Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server recv request  #8 Mining.isTestChain$Params 
2026-03-12T20:39:21.3921007Z  node0 2026-03-12T20:38:57.731196Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} request data: (context = (thread = <external capability>)) 
2026-03-12T20:39:21.4023734Z  node0 2026-03-12T20:38:57.731565Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server post request  #8 {bitcoin-node-9523/b-capnp-loop-9971 (from pythread)} 
2026-03-12T20:39:21.4063332Z  node0 2026-03-12T20:38:57.782473Z [unknown] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9971 (from pythread)} IPC server executing request #8 
2026-03-12T20:39:21.4120845Z  node0 2026-03-12T20:38:57.831554Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server send response #8 Mining.isTestChain$Results 
2026-03-12T20:39:21.4123553Z  node0 2026-03-12T20:38:57.831938Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} response data: (result = true) 
2026-03-12T20:39:21.4149636Z  node0 2026-03-12T20:38:57.847963Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server recv request  #9 Mining.isInitialBlockDownload$Params 
2026-03-12T20:39:21.4210028Z  node0 2026-03-12T20:38:57.899514Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} request data: (context = (thread = <external capability>)) 
2026-03-12T20:39:21.4249291Z  node0 2026-03-12T20:38:57.899981Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server post request  #9 {bitcoin-node-9523/b-capnp-loop-9971 (from pythread)} 
2026-03-12T20:39:21.4251608Z  node0 2026-03-12T20:38:57.906482Z [unknown] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9971 (from pythread)} IPC server executing request #9 
2026-03-12T20:39:21.4315867Z  node0 2026-03-12T20:38:57.908367Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server send response #9 Mining.isInitialBlockDownload$Results 
2026-03-12T20:39:21.4364066Z  node0 2026-03-12T20:38:57.908706Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} response data: (result = false) 
2026-03-12T20:39:21.4428115Z  node0 2026-03-12T20:38:57.914643Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server recv request  #10 Mining.getTip$Params 
2026-03-12T20:39:21.4470384Z  node0 2026-03-12T20:38:57.915167Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} request data: (context = (thread = <external capability>)) 
2026-03-12T20:39:21.4473584Z  node0 2026-03-12T20:38:57.915641Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server post request  #10 {bitcoin-node-9523/b-capnp-loop-9971 (from pythread)} 
2026-03-12T20:39:21.4491100Z  node0 2026-03-12T20:38:57.918468Z [unknown] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9971 (from pythread)} IPC server executing request #10 
2026-03-12T20:39:21.4519923Z  node0 2026-03-12T20:38:57.919643Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server send response #10 Mining.getTip$Results 
2026-03-12T20:39:21.4593560Z  node0 2026-03-12T20:38:57.920217Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} response data: (result = (hash = "r\\032|\\357\\365~\\247\\204s\\226/\\327\\341.|+S\\245v\\350\\305\\310\\304J\\b\\216\\310\\332\\373\\t\\214\\006", height = 200), hasResult = true) 
2026-03-12T20:39:21.4596400Z  node0 2026-03-12T20:38:57.947621Z [http] [httpserver.cpp:233] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:33572 
2026-03-12T20:39:21.4704406Z  node0 2026-03-12T20:38:57.948383Z [http_pool_1] [rpc/request.cpp:243] [parse] [rpc] ThreadRPCServer method=getchaintips user=__cookie__ 
2026-03-12T20:39:21.4723853Z  test  2026-03-12T20:38:57.987523Z TestFramework (INFO): Running deprecated mining interface test 
2026-03-12T20:39:21.4735843Z  test  2026-03-12T20:38:57.988011Z TestFramework (DEBUG): Calling deprecated makeMiningOld2 should raise an error 
2026-03-12T20:39:21.4738475Z  node0 2026-03-12T20:38:57.996922Z [capnp-loop] [ipc/capnp/protocol.cpp:53] [IpcLogFn] ipc: {bitcoin-node-9523/b-capnp-loop-9612} IPC server destroy N2mp11ProxyServerIN3ipc5capnp8messages6MiningEEE 
2026-03-12T20:39:21.4765305Z  node0 2026-03-12T20:38:57.998134Z [capnp-loop] [ipc/capnp/protocol.cpp:53] [IpcLogFn] ipc: {bitcoin-node-9523/b-capnp-loop-9612} IPC server: socket disconnected. 
2026-03-12T20:39:21.4785294Z  node0 2026-03-12T20:38:58.009655Z [capnp-loop] [ipc/capnp/protocol.cpp:53] [IpcLogFn] ipc: {bitcoin-node-9523/b-capnp-loop-9612} IPC server destroy N2mp11ProxyServerIN3ipc5capnp8messages4InitEEE 
2026-03-12T20:39:21.4878238Z  node0 2026-03-12T20:38:58.028543Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server recv request  #11 Init.makeMiningOld2$Params 
2026-03-12T20:39:21.4920510Z  node0 2026-03-12T20:38:58.028732Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} request data: () 
2026-03-12T20:39:21.4923213Z  node0 2026-03-12T20:38:58.034342Z [capnp-loop] [ipc/capnp/protocol.cpp:59] [IpcLogFn] [error] ipc: {bitcoin-node-9523/b-capnp-loop-9612} IPC server unhandled exception: Old mining interface (@2) not supported. Please update your client! 
2026-03-12T20:39:21.4994217Z  test  2026-03-12T20:38:58.049581Z TestFramework (INFO): Running disconnect during BlockTemplate.waitNext 
2026-03-12T20:39:21.5023406Z  test  2026-03-12T20:38:58.050442Z TestFramework (DEBUG): Create Mining proxy object 
2026-03-12T20:39:21.5028491Z  test  2026-03-12T20:38:58.050607Z TestFramework (DEBUG): Create a template 
2026-03-12T20:39:21.5030473Z  node0 2026-03-12T20:38:58.061777Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server recv request  #12 Init.construct$Params 
2026-03-12T20:39:21.5035872Z  node0 2026-03-12T20:38:58.062073Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} request data: () 
2026-03-12T20:39:21.5041910Z  node0 2026-03-12T20:38:58.104514Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server send response #12 Init.construct$Results 
2026-03-12T20:39:21.5080342Z  node0 2026-03-12T20:38:58.104946Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} response data: (threadMap = <external capability>) 
2026-03-12T20:39:21.5083026Z  node0 2026-03-12T20:38:58.144914Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server recv request  #13 Init.makeMining$Params 
2026-03-12T20:39:21.5147590Z  node0 2026-03-12T20:38:58.145454Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} request data: (context = (thread = <external capability>)) 
2026-03-12T20:39:21.5254626Z  node0 2026-03-12T20:38:58.145854Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server post request  #13 {bitcoin-node-9523/b-capnp-loop-9989 (from pythread)} 
2026-03-12T20:39:21.5283058Z  node0 2026-03-12T20:38:58.196836Z [capnp-loop] [ipc/capnp/protocol.cpp:53] [IpcLogFn] ipc: {bitcoin-node-9523/b-capnp-loop-9612} IPC server: socket disconnected. 
2026-03-12T20:39:21.5285636Z  node0 2026-03-12T20:38:58.197130Z [capnp-loop] [ipc/capnp/protocol.cpp:53] [IpcLogFn] ipc: {bitcoin-node-9523/b-capnp-loop-9612} IPC server destroy N2mp11ProxyServerIN3ipc5capnp8messages4InitEEE 
2026-03-12T20:39:21.5318533Z  node0 2026-03-12T20:38:58.237087Z [unknown] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9989 (from pythread)} IPC server executing request #13 
2026-03-12T20:39:21.5338940Z  node0 2026-03-12T20:38:58.279699Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server send response #13 Init.makeMining$Results 
2026-03-12T20:39:21.5376755Z  node0 2026-03-12T20:38:58.280024Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} response data: (result = <external capability>) 
2026-03-12T20:39:21.5412912Z  node0 2026-03-12T20:38:58.280602Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server recv request  #14 Mining.createNewBlock$Params 
2026-03-12T20:39:21.5416763Z  node0 2026-03-12T20:38:58.281483Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} request data: (context = (thread = <external capability>), options = (useMempool = true, blockReservedWeight = 8000, coinbaseOutputMaxAdditionalSigops = 400), cooldown = true) 
2026-03-12T20:39:21.5472866Z  node0 2026-03-12T20:38:58.281860Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server post request  #14 {bitcoin-node-9523/b-capnp-loop-9989 (from pythread)} 
2026-03-12T20:39:21.5485259Z  node0 2026-03-12T20:38:58.330708Z [unknown] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9989 (from pythread)} IPC server executing request #14 
2026-03-12T20:39:21.5498918Z  node0 2026-03-12T20:38:58.346766Z [unknown] [node/miner.cpp:215] [CreateNewBlock] CreateNewBlock(): block weight: 804 txs: 0 fees: 0 sigops 400 
2026-03-12T20:39:21.5500734Z  node0 2026-03-12T20:38:58.347476Z [unknown] [validation.cpp:2387] [ConnectBlock] [bench]     - Sanity checks: 0.08ms [0.00s (0.06ms/blk)] 
2026-03-12T20:39:21.5567342Z  node0 2026-03-12T20:38:58.347893Z [unknown] [validation.cpp:2489] [ConnectBlock] [bench]     - Fork checks: 0.45ms [0.00s (0.44ms/blk)] 
2026-03-12T20:39:21.5581658Z  node0 2026-03-12T20:38:58.348142Z [unknown] [validation.cpp:2605] [ConnectBlock] [bench]       - Connect 1 transactions: 0.23ms (0.229ms/tx, 0.000ms/txin) [0.00s (0.32ms/blk)] 
2026-03-12T20:39:21.5615299Z  node0 2026-03-12T20:38:58.409959Z [unknown] [validation.cpp:2628] [ConnectBlock] [bench]     - Verify 0 txins: 61.99ms (0.000ms/txin) [0.06s (21.08ms/blk)] 
2026-03-12T20:39:21.5639772Z  node0 2026-03-12T20:38:58.411482Z [unknown] [node/miner.cpp:234] [CreateNewBlock] [bench] CreateNewBlock() chunks: 0.22ms, validity: 64.99ms (total 65.21ms) 
2026-03-12T20:39:21.5705218Z  node0 2026-03-12T20:38:58.452079Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server send response #14 Mining.createNewBlock$Results 
2026-03-12T20:39:21.5713755Z  node0 2026-03-12T20:38:58.452604Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} response data: (result = <external capability>) 
2026-03-12T20:39:21.5715505Z  test  2026-03-12T20:38:58.454011Z TestFramework (DEBUG): Wait for a new template 
2026-03-12T20:39:21.5764920Z  node0 2026-03-12T20:38:58.482108Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server recv request  #15 BlockTemplate.waitNext$Params 
2026-03-12T20:39:21.5767404Z  node0 2026-03-12T20:38:58.523542Z [capnp-loop] [ipc/capnp/protocol.cpp:47] [IpcLogFn] [ipc:trace] {bitcoin-node-9523/b-capnp-loop-9612} request data: (context = (thread = <external capability>), options = (timeout = 600000, feeThreshold = 1)) 
2026-03-12T20:39:21.5770161Z  node0 2026-03-12T20:38:58.523944Z [capnp-loop] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9612} IPC server post request  #15 {bitcoin-node-9523/b-capnp-loop-9989 (from pythread)} 
2026-03-12T20:39:21.5772746Z  node0 2026-03-12T20:38:58.573383Z [capnp-loop] [ipc/capnp/protocol.cpp:53] [IpcLogFn] ipc: {bitcoin-node-9523/b-capnp-loop-9612} IPC server destroy N2mp11ProxyServerIN3ipc5capnp8messages6MiningEEE 
2026-03-12T20:39:21.5774737Z  node0 2026-03-12T20:38:58.574563Z [capnp-loop] [ipc/capnp/protocol.cpp:53] [IpcLogFn] ipc: {bitcoin-node-9523/b-capnp-loop-9612} IPC server: socket disconnected. 
2026-03-12T20:39:21.5776946Z  node0 2026-03-12T20:38:58.574851Z [capnp-loop] [ipc/capnp/protocol.cpp:53] [IpcLogFn] ipc: {bitcoin-node-9523/b-capnp-loop-9612} IPC server destroy N2mp11ProxyServerIN3ipc5capnp8messages4InitEEE 
2026-03-12T20:39:21.5779422Z  node0 2026-03-12T20:38:58.575439Z [unknown] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9989 (from pythread)} IPC server executing request #15 
2026-03-12T20:39:21.5781394Z  test  2026-03-12T20:39:18.610585Z TestFramework (ERROR): Unexpected exception: 
2026-03-12T20:39:21.5782213Z                                    Traceback (most recent call last):
2026-03-12T20:39:21.5783570Z                                      File "/home/runner/work/libmultiprocess/libmultiprocess/test/functional/test_framework/test_framework.py", line 142, in main
2026-03-12T20:39:21.5784660Z                                        self.run_test()
2026-03-12T20:39:21.5785682Z                                      File "/home/runner/work/libmultiprocess/libmultiprocess/build/test/functional/interface_ipc.py", line 176, in run_test
2026-03-12T20:39:21.5786796Z                                        self.run_unclean_disconnect_test()
2026-03-12T20:39:21.5787919Z                                      File "/home/runner/work/libmultiprocess/libmultiprocess/build/test/functional/interface_ipc.py", line 122, in run_unclean_disconnect_test
2026-03-12T20:39:21.5789067Z                                        disconnected_log_check.close()
2026-03-12T20:39:21.5789776Z                                      File "/usr/lib/python3.12/contextlib.py", line 618, in close
2026-03-12T20:39:21.5790535Z                                        self.__exit__(None, None, None)
2026-03-12T20:39:21.5791150Z                                      File "/usr/lib/python3.12/contextlib.py", line 610, in __exit__
2026-03-12T20:39:21.5792052Z                                        raise exc_details[1]
2026-03-12T20:39:21.6127434Z                                      File "/usr/lib/python3.12/contextlib.py", line 595, in __exit__
2026-03-12T20:39:21.6128441Z                                        if cb(*exc_details):
2026-03-12T20:39:21.6129004Z                                           ^^^^^^^^^^^^^^^^
2026-03-12T20:39:21.6129739Z                                      File "/usr/lib/python3.12/contextlib.py", line 144, in __exit__
2026-03-12T20:39:21.6130538Z                                        next(self.gen)
2026-03-12T20:39:21.6131928Z                                      File "/home/runner/work/libmultiprocess/libmultiprocess/test/functional/test_framework/test_node.py", line 607, in assert_debug_log
2026-03-12T20:39:21.6133631Z                                        self._raise_assertion_error(f'Expected message(s) {remaining_expected!s} '
2026-03-12T20:39:21.6135138Z                                      File "/home/runner/work/libmultiprocess/libmultiprocess/test/functional/test_framework/test_node.py", line 241, in _raise_assertion_error
2026-03-12T20:39:21.6136391Z                                        raise AssertionError(self._node_msg(msg))
2026-03-12T20:39:21.6137326Z                                    AssertionError: [node 0] Expected message(s) ['canceled while executing'] not found in log:
2026-03-12T20:39:21.6139156Z                                     - 2026-03-12T20:38:58.573383Z [capnp-loop] [ipc/capnp/protocol.cpp:53] [IpcLogFn] ipc: {bitcoin-node-9523/b-capnp-loop-9612} IPC server destroy N2mp11ProxyServerIN3ipc5capnp8messages6MiningEEE
2026-03-12T20:39:21.6141402Z                                     - 2026-03-12T20:38:58.574563Z [capnp-loop] [ipc/capnp/protocol.cpp:53] [IpcLogFn] ipc: {bitcoin-node-9523/b-capnp-loop-9612} IPC server: socket disconnected.
2026-03-12T20:39:21.6143811Z                                     - 2026-03-12T20:38:58.574851Z [capnp-loop] [ipc/capnp/protocol.cpp:53] [IpcLogFn] ipc: {bitcoin-node-9523/b-capnp-loop-9612} IPC server destroy N2mp11ProxyServerIN3ipc5capnp8messages4InitEEE
2026-03-12T20:39:21.6146083Z                                     - 2026-03-12T20:38:58.575439Z [unknown] [ipc/capnp/protocol.cpp:50] [IpcLogFn] [ipc] {bitcoin-node-9523/b-capnp-loop-9989 (from pythread)} IPC server executing request #15
2026-03-12T20:39:21.6147562Z  test  2026-03-12T20:39:18.620194Z TestFramework (DEBUG): Closing down network thread 
2026-03-12T20:39:21.6148823Z  test  2026-03-12T20:39:18.686000Z TestFramework (INFO): Not stopping nodes as test failed. The dangling processes will be cleaned up later. 
2026-03-12T20:39:21.6151156Z  test  2026-03-12T20:39:18.686172Z TestFramework (WARNING): Not cleaning up dir /tmp/test_runner_₿_🏃_20260312_203817/interface_ipc_553 
2026-03-12T20:39:21.6414296Z  test  2026-03-12T20:39:18.686254Z TestFramework (ERROR): Test failed. Test logging available at /tmp/test_runner_₿_🏃_20260312_203817/interface_ipc_553/test_framework.log 
2026-03-12T20:39:21.6415780Z  test  2026-03-12T20:39:18.686477Z TestFramework (ERROR): 
2026-03-12T20:39:21.6417930Z  test  2026-03-12T20:39:18.686646Z TestFramework (ERROR): Hint: Call /home/runner/work/libmultiprocess/libmultiprocess/test/functional/combine_logs.py '/tmp/test_runner_₿_🏃_20260312_203817/interface_ipc_553' to consolidate all logs 
2026-03-12T20:39:21.6419596Z  test  2026-03-12T20:39:18.686725Z TestFramework (ERROR): 
2026-03-12T20:39:21.6420903Z  test  2026-03-12T20:39:18.686789Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log. 
2026-03-12T20:39:21.6422475Z  test  2026-03-12T20:39:18.686879Z TestFramework (ERROR): https://github.com/bitcoin/bitcoin/issues 
2026-03-12T20:39:21.6423488Z  test  2026-03-12T20:39:18.686945Z TestFramework (ERROR): 
2026-03-12T20:39:21.6423860Z 
2026-03-12T20:39:21.6424011Z  node0 stderr ==================
2026-03-12T20:39:21.6424693Z WARNING: ThreadSanitizer: heap-use-after-free (virtual call vs free) (pid=9523)
2026-03-12T20:39:21.6425734Z   Read of size 8 at 0x723c0000f000 by thread T14:
2026-03-12T20:39:21.6495389Z     #0 capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>::getParams() /home/runner/work/libmultiprocess/libmultiprocess/depends/x86_64-pc-linux-gnu/include/capnp/capability.h:1129:16 (bitcoin-node+0x12c3f52) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.6724382Z     #1 std::__1::enable_if<std::is_same<decltype(mp::Accessor<mp::mining_fields::Context, 17>::get(fp1.call_context.getParams())), mp::Context::Reader>::value, kj::Promise<mp::ServerInvokeContext<mp::ProxyServer<ipc::capnp::messages::BlockTemplate>, capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>>::CallContext>>::type mp::PassField<mp::Accessor<mp::mining_fields::Context, 17>, mp::ServerInvokeContext<mp::ProxyServer<ipc::capnp::messages::BlockTemplate>, capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>>, mp::ServerField<1, mp::Accessor<mp::mining_fields::Options, 17>, mp::ServerRet<mp::Accessor<mp::mining_fields::Result, 18>, mp::ServerCall>>, mp::TypeList<node::BlockWaitOptions>>(mp::Priority<1>, mp::TypeList<>, mp::ServerInvokeContext<mp::ProxyServer<ipc::capnp::messages::BlockTemplate>, capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>>&, mp::ServerField<1, mp::Accessor<mp::mining_fields::Options, 17>, mp::ServerRet<mp::Accessor<mp::mining_fields::Result, 18>, mp::ServerCall>> const&, mp::TypeList<node::BlockWaitOptions>&&)::'lambda'(mp::CancelMonitor&)::operator()(mp::CancelMonitor&) /home/runner/work/libmultiprocess/libmultiprocess/src/ipc/libmultiprocess/include/mp/type-context.h:77:51 (bitcoin-node+0x12ccc42) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.7084859Z     #2 kj::Promise<mp::Accessor<mp::mining_fields::Context, 17>> mp::ProxyServer<mp::Thread>::post<capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>, std::__1::enable_if<std::is_same<decltype(mp::Accessor<mp::mining_fields::Context, 17>::get(fp1.call_context.getParams())), mp::Context::Reader>::value, kj::Promise<mp::ServerInvokeContext<mp::ProxyServer<ipc::capnp::messages::BlockTemplate>, capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>>::CallContext>>::type mp::PassField<mp::Accessor<mp::mining_fields::Context, 17>, mp::ServerInvokeContext<mp::ProxyServer<ipc::capnp::messages::BlockTemplate>, capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>>, mp::ServerField<1, mp::Accessor<mp::mining_fields::Options, 17>, mp::ServerRet<mp::Accessor<mp::mining_fields::Result, 18>, mp::ServerCall>>, mp::TypeList<node::BlockWaitOptions>>(mp::Priority<1>, mp::TypeList<>, mp::ServerInvokeContext<mp::ProxyServer<ipc::capnp::messages::BlockTemplate>, capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>>&, mp::ServerField<1, mp::Accessor<mp::mining_fields::Options, 17>, mp::ServerRet<mp::Accessor<mp::mining_fields::Result, 18>, mp::ServerCall>> const&, mp::TypeList<node::BlockWaitOptions>&&)::'lambda'(mp::CancelMonitor&)>(mp::ServerInvokeContext<mp::ProxyServer<ipc::capnp::messages::BlockTemplate>, capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>>&&)::'lambda'()::operator()()::'lambda'()::operator()()::'lambda0'()::operator()() const /home/runner/work/libmultiprocess/libmultiprocess/src/ipc/libmultiprocess/include/mp/proxy-io.h:744:100 (bitcoin-node+0x12cc903) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.7336212Z     #3 kj::Maybe<kj::Exception> kj::runCatchingExceptions<kj::Promise<mp::Accessor<mp::mining_fields::Context, 17>> mp::ProxyServer<mp::Thread>::post<capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>, std::__1::enable_if<std::is_same<decltype(mp::Accessor<mp::mining_fields::Context, 17>::get(fp1.call_context.getParams())), mp::Context::Reader>::value, kj::Promise<mp::ServerInvokeContext<mp::ProxyServer<ipc::capnp::messages::BlockTemplate>, capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>>::CallContext>>::type mp::PassField<mp::Accessor<mp::mining_fields::Context, 17>, mp::ServerInvokeContext<mp::ProxyServer<ipc::capnp::messages::BlockTemplate>, capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>>, mp::ServerField<1, mp::Accessor<mp::mining_fields::Options, 17>, mp::ServerRet<mp::Accessor<mp::mining_fields::Result, 18>, mp::ServerCall>>, mp::TypeList<node::BlockWaitOptions>>(mp::Priority<1>, mp::TypeList<>, mp::ServerInvokeContext<mp::ProxyServer<ipc::capnp::messages::BlockTemplate>, capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>>&, mp::ServerField<1, mp::Accessor<mp::mining_fields::Options, 17>, mp::ServerRet<mp::Accessor<mp::mining_fields::Result, 18>, mp::ServerCall>> const&, mp::TypeList<node::BlockWaitOptions>&&)::'lambda'(mp::CancelMonitor&)>(mp::ServerInvokeContext<mp::ProxyServer<ipc::capnp::messages::BlockTemplate>, capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>>&&)::'lambda'()::operator()()::'lambda'()::operator()()::'lambda0'()>(mp::Accessor<mp::mining_fields::Context, 17>&&) /home/runner/work/libmultiprocess/libmultiprocess/depends/x86_64-pc-linux-gnu/include/kj/exception.h:371:5 (bitcoin-node+0x12cb771) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.7639621Z     #4 kj::Promise<mp::Accessor<mp::mining_fields::Context, 17>> mp::ProxyServer<mp::Thread>::post<capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>, std::__1::enable_if<std::is_same<decltype(mp::Accessor<mp::mining_fields::Context, 17>::get(fp1.call_context.getParams())), mp::Context::Reader>::value, kj::Promise<mp::ServerInvokeContext<mp::ProxyServer<ipc::capnp::messages::BlockTemplate>, capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>>::CallContext>>::type mp::PassField<mp::Accessor<mp::mining_fields::Context, 17>, mp::ServerInvokeContext<mp::ProxyServer<ipc::capnp::messages::BlockTemplate>, capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>>, mp::ServerField<1, mp::Accessor<mp::mining_fields::Options, 17>, mp::ServerRet<mp::Accessor<mp::mining_fields::Result, 18>, mp::ServerCall>>, mp::TypeList<node::BlockWaitOptions>>(mp::Priority<1>, mp::TypeList<>, mp::ServerInvokeContext<mp::ProxyServer<ipc::capnp::messages::BlockTemplate>, capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>>&, mp::ServerField<1, mp::Accessor<mp::mining_fields::Options, 17>, mp::ServerRet<mp::Accessor<mp::mining_fields::Result, 18>, mp::ServerCall>> const&, mp::TypeList<node::BlockWaitOptions>&&)::'lambda'(mp::CancelMonitor&)>(mp::ServerInvokeContext<mp::ProxyServer<ipc::capnp::messages::BlockTemplate>, capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>>&&)::'lambda'()::operator()()::'lambda'()::operator()() /home/runner/work/libmultiprocess/libmultiprocess/src/ipc/libmultiprocess/include/mp/proxy-io.h:744:48 (bitcoin-node+0x12cb2d5) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.7999045Z     #5 kj::Function<void ()>::Impl<kj::Promise<mp::Accessor<mp::mining_fields::Context, 17>> mp::ProxyServer<mp::Thread>::post<capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>, std::__1::enable_if<std::is_same<decltype(mp::Accessor<mp::mining_fields::Context, 17>::get(fp1.call_context.getParams())), mp::Context::Reader>::value, kj::Promise<mp::ServerInvokeContext<mp::ProxyServer<ipc::capnp::messages::BlockTemplate>, capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>>::CallContext>>::type mp::PassField<mp::Accessor<mp::mining_fields::Context, 17>, mp::ServerInvokeContext<mp::ProxyServer<ipc::capnp::messages::BlockTemplate>, capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>>, mp::ServerField<1, mp::Accessor<mp::mining_fields::Options, 17>, mp::ServerRet<mp::Accessor<mp::mining_fields::Result, 18>, mp::ServerCall>>, mp::TypeList<node::BlockWaitOptions>>(mp::Priority<1>, mp::TypeList<>, mp::ServerInvokeContext<mp::ProxyServer<ipc::capnp::messages::BlockTemplate>, capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>>&, mp::ServerField<1, mp::Accessor<mp::mining_fields::Options, 17>, mp::ServerRet<mp::Accessor<mp::mining_fields::Result, 18>, mp::ServerCall>> const&, mp::TypeList<node::BlockWaitOptions>&&)::'lambda'(mp::CancelMonitor&)>(mp::ServerInvokeContext<mp::ProxyServer<ipc::capnp::messages::BlockTemplate>, capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>>&&)::'lambda'()::operator()()::'lambda'()>::operator()() /home/runner/work/libmultiprocess/libmultiprocess/depends/x86_64-pc-linux-gnu/include/kj/function.h:142:14 (bitcoin-node+0x12cb12a) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.8313229Z     #6 kj::Function<void ()>::operator()() /home/runner/work/libmultiprocess/libmultiprocess/depends/x86_64-pc-linux-gnu/include/kj/function.h:119:12 (bitcoin-node+0xf6c0c1) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.8316480Z     #7 void mp::Unlock<mp::Lock, kj::Function<void ()>&>(mp::Lock&, kj::Function<void ()>&) /home/runner/work/libmultiprocess/libmultiprocess/src/ipc/libmultiprocess/include/mp/util.h:210:5 (bitcoin-node+0xf6bce1) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.8321424Z     #8 void mp::Waiter::wait<mp::ProxyServer<mp::ThreadMap>::makeThread(capnp::CallContext<mp::ThreadMap::MakeThreadParams, mp::ThreadMap::MakeThreadResults>)::$_0::operator()() const::'lambda'()>(mp::Lock&, mp::ProxyServer<mp::ThreadMap>::makeThread(capnp::CallContext<mp::ThreadMap::MakeThreadParams, mp::ThreadMap::MakeThreadResults>)::$_0::operator()() const::'lambda'())::'lambda'()::operator()() const /home/runner/work/libmultiprocess/libmultiprocess/src/ipc/libmultiprocess/include/mp/proxy-io.h:382:17 (bitcoin-node+0x186c45f) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.8329872Z     #9 void std::__1::condition_variable::wait[abi:nqe220100]<void mp::Waiter::wait<mp::ProxyServer<mp::ThreadMap>::makeThread(capnp::CallContext<mp::ThreadMap::MakeThreadParams, mp::ThreadMap::MakeThreadResults>)::$_0::operator()() const::'lambda'()>(mp::Lock&, mp::ProxyServer<mp::ThreadMap>::makeThread(capnp::CallContext<mp::ThreadMap::MakeThreadParams, mp::ThreadMap::MakeThreadResults>)::$_0::operator()() const::'lambda'())::'lambda'()>(std::__1::unique_lock<std::__1::mutex>&, mp::ProxyServer<mp::ThreadMap>::makeThread(capnp::CallContext<mp::ThreadMap::MakeThreadParams, mp::ThreadMap::MakeThreadResults>)::$_0::operator()() const::'lambda'()) /tmp/libcxx-build/include/c++/v1/__condition_variable/condition_variable.h:111:13 (bitcoin-node+0x186c34e) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.8430177Z     #10 void mp::Waiter::wait<mp::ProxyServer<mp::ThreadMap>::makeThread(capnp::CallContext<mp::ThreadMap::MakeThreadParams, mp::ThreadMap::MakeThreadResults>)::$_0::operator()() const::'lambda'()>(mp::Lock&, mp::ProxyServer<mp::ThreadMap>::makeThread(capnp::CallContext<mp::ThreadMap::MakeThreadParams, mp::ThreadMap::MakeThreadResults>)::$_0::operator()() const::'lambda'()) /home/runner/work/libmultiprocess/libmultiprocess/src/ipc/libmultiprocess/include/mp/proxy-io.h:373:14 (bitcoin-node+0x186c29f) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.8640511Z     #11 mp::ProxyServer<mp::ThreadMap>::makeThread(capnp::CallContext<mp::ThreadMap::MakeThreadParams, mp::ThreadMap::MakeThreadResults>)::$_0::operator()() const /home/runner/work/libmultiprocess/libmultiprocess/src/ipc/libmultiprocess/src/mp/proxy.cpp:423:34 (bitcoin-node+0x186c104) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.8646401Z     #12 std::__1::__invoke_result_impl<void, mp::ProxyServer<mp::ThreadMap>::makeThread(capnp::CallContext<mp::ThreadMap::MakeThreadParams, mp::ThreadMap::MakeThreadResults>)::$_0>::type std::__1::__invoke[abi:nqe220100]<mp::ProxyServer<mp::ThreadMap>::makeThread(capnp::CallContext<mp::ThreadMap::MakeThreadParams, mp::ThreadMap::MakeThreadResults>)::$_0>(mp::ProxyServer<mp::ThreadMap>::makeThread(capnp::CallContext<mp::ThreadMap::MakeThreadParams, mp::ThreadMap::MakeThreadResults>)::$_0&&) /tmp/libcxx-build/include/c++/v1/__type_traits/invoke.h:90:27 (bitcoin-node+0x186be12) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.8654150Z     #13 void std::__1::__thread_execute[abi:nqe220100]<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct>>, mp::ProxyServer<mp::ThreadMap>::makeThread(capnp::CallContext<mp::ThreadMap::MakeThreadParams, mp::ThreadMap::MakeThreadResults>)::$_0, 0ul>(std::__1::tuple<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct>>, mp::ProxyServer<mp::ThreadMap>::makeThread(capnp::CallContext<mp::ThreadMap::MakeThreadParams, mp::ThreadMap::MakeThreadResults>)::$_0>&, std::__1::__integer_sequence<unsigned long, 0ul>) /tmp/libcxx-build/include/c++/v1/__thread/thread.h:161:3 (bitcoin-node+0x186bd8a) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.8856247Z     #14 void* std::__1::__thread_proxy[abi:nqe220100]<std::__1::tuple<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct>>, mp::ProxyServer<mp::ThreadMap>::makeThread(capnp::CallContext<mp::ThreadMap::MakeThreadParams, mp::ThreadMap::MakeThreadResults>)::$_0>>(void*) /tmp/libcxx-build/include/c++/v1/__thread/thread.h:169:3 (bitcoin-node+0x186b8ad) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.8859457Z 
2026-03-12T20:39:21.8859738Z   Previous write of size 8 at 0x723c0000f000 by thread T2:
2026-03-12T20:39:21.8860719Z     #0 operator delete(void*, unsigned long) <null> (bitcoin-node+0x1d922c) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.8862418Z     #1 capnp::_::(anonymous namespace)::RpcConnectionState::RpcCallContext::~RpcCallContext() rpc.c++ (bitcoin-node+0x192bed9) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.8864794Z     #2 non-virtual thunk to capnp::_::(anonymous namespace)::RpcConnectionState::RpcCallContext::~RpcCallContext() rpc.c++ (bitcoin-node+0x192bf99) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.8866714Z     #3 kj::Refcounted::disposeImpl(void*) const <null> (bitcoin-node+0x1c7c564) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.8868623Z     #4 kj::Disposer::Dispose_<capnp::CallContextHook, true>::dispose(capnp::CallContextHook*, kj::Disposer const&) <null> (bitcoin-node+0x18aa971) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.8870772Z     #5 void kj::Disposer::dispose<capnp::CallContextHook>(capnp::CallContextHook*) const <null> (bitcoin-node+0x18aa8c5) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.8873079Z     #6 kj::Own<capnp::CallContextHook, std::nullptr_t>::dispose() <null> (bitcoin-node+0x18aa86e) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.8874817Z     #7 kj::Own<capnp::CallContextHook, std::nullptr_t>::~Own() <null> (bitcoin-node+0x18a2705) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.8876652Z     #8 kj::_::TupleElement<1u, kj::Own<capnp::CallContextHook, std::nullptr_t>>::~TupleElement() <null> (bitcoin-node+0x18ca3b5) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.8878881Z     #9 kj::_::TupleImpl<kj::_::Indexes<0ul, 1ul>, kj::Own<capnp::LocalClient, std::nullptr_t>, kj::Own<capnp::CallContextHook, std::nullptr_t>>::~TupleImpl() <null> (bitcoin-node+0x18ca31d) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.8881335Z     #10 kj::_::Tuple<kj::Own<capnp::LocalClient, std::nullptr_t>, kj::Own<capnp::CallContextHook, std::nullptr_t>>::~Tuple() <null> (bitcoin-node+0x18c9265) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.9147975Z     #11 kj::_::AttachmentPromiseNode<kj::_::Tuple<kj::Own<capnp::LocalClient, std::nullptr_t>, kj::Own<capnp::CallContextHook, std::nullptr_t>>>::~AttachmentPromiseNode() <null> (bitcoin-node+0x18c9a88) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.9151689Z     #12 void kj::dtor<kj::_::AttachmentPromiseNode<kj::_::Tuple<kj::Own<capnp::LocalClient, std::nullptr_t>, kj::Own<capnp::CallContextHook, std::nullptr_t>>>>(kj::_::AttachmentPromiseNode<kj::_::Tuple<kj::Own<capnp::LocalClient, std::nullptr_t>, kj::Own<capnp::CallContextHook, std::nullptr_t>>>&) <null> (bitcoin-node+0x18c9a25) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.9156497Z     #13 kj::_::FreePromiseNode<kj::_::AttachmentPromiseNode<kj::_::Tuple<kj::Own<capnp::LocalClient, std::nullptr_t>, kj::Own<capnp::CallContextHook, std::nullptr_t>>>, true>::free(kj::_::AttachmentPromiseNode<kj::_::Tuple<kj::Own<capnp::LocalClient, std::nullptr_t>, kj::Own<capnp::CallContextHook, std::nullptr_t>>>*) <null> (bitcoin-node+0x18c99d5) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.9161078Z     #14 void kj::_::freePromise<kj::_::AttachmentPromiseNode<kj::_::Tuple<kj::Own<capnp::LocalClient, std::nullptr_t>, kj::Own<capnp::CallContextHook, std::nullptr_t>>>>(kj::_::AttachmentPromiseNode<kj::_::Tuple<kj::Own<capnp::LocalClient, std::nullptr_t>, kj::Own<capnp::CallContextHook, std::nullptr_t>>>*) capability.c++ (bitcoin-node+0x1889635) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.9257793Z     #15 kj::_::AttachmentPromiseNode<kj::_::Tuple<kj::Own<capnp::LocalClient, std::nullptr_t>, kj::Own<capnp::CallContextHook, std::nullptr_t>>>::destroy() <null> (bitcoin-node+0x18c97c5) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.9261110Z     #16 kj::_::PromiseDisposer::dispose(kj::_::PromiseArenaMember*) /home/runner/work/libmultiprocess/libmultiprocess/depends/x86_64-pc-linux-gnu/include/kj/async-inl.h:354:11 (bitcoin-node+0xf3ea63) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.9495127Z     #17 kj::Own<kj::_::PromiseNode, kj::_::PromiseDisposer>::dispose() /home/runner/work/libmultiprocess/libmultiprocess/depends/x86_64-pc-linux-gnu/include/kj/memory.h:398:7 (bitcoin-node+0xf3e9a9) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.9497613Z     #18 kj::Own<kj::_::PromiseNode, kj::_::PromiseDisposer>::operator=(std::nullptr_t) <null> (bitcoin-node+0x1ad2e65) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.9499379Z     #19 kj::_::ForkHubBase::fire()::$_0::operator()() const async.c++ (bitcoin-node+0x1ac4e3d) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.9501493Z     #20 kj::Maybe<kj::Exception> kj::runCatchingExceptions<kj::_::ForkHubBase::fire()::$_0>(kj::_::ForkHubBase::fire()::$_0&&) async.c++ (bitcoin-node+0x1ab65d7) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.9504000Z     #21 kj::_::ForkHubBase::fire() <null> (bitcoin-node+0x1ab62f4) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.9505670Z     #22 non-virtual thunk to kj::_::ForkHubBase::fire() <null> (bitcoin-node+0x1ab6709) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.9507230Z     #23 kj::EventLoop::turn() <null> (bitcoin-node+0x1aafc55) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.9509485Z     #24 kj::_::waitImpl(kj::Own<kj::_::PromiseNode, kj::_::PromiseDisposer>&&, kj::_::ExceptionOrValue&, kj::WaitScope&, kj::SourceLocation)::$_2::operator()() const async.c++ (bitcoin-node+0x1ac3aa4) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.9513707Z     #25 void kj::WaitScope::runOnStackPool<kj::_::waitImpl(kj::Own<kj::_::PromiseNode, kj::_::PromiseDisposer>&&, kj::_::ExceptionOrValue&, kj::WaitScope&, kj::SourceLocation)::$_2>(kj::_::waitImpl(kj::Own<kj::_::PromiseNode, kj::_::PromiseDisposer>&&, kj::_::ExceptionOrValue&, kj::WaitScope&, kj::SourceLocation)::$_2&&) async.c++ (bitcoin-node+0x1ab1bc7) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.9517656Z     #26 kj::_::waitImpl(kj::Own<kj::_::PromiseNode, kj::_::PromiseDisposer>&&, kj::_::ExceptionOrValue&, kj::WaitScope&, kj::SourceLocation) <null> (bitcoin-node+0x1ab1741) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.9520836Z     #27 kj::Promise<unsigned long>::wait(kj::WaitScope&, kj::SourceLocation) /home/runner/work/libmultiprocess/libmultiprocess/depends/x86_64-pc-linux-gnu/include/kj/async-inl.h:1359:3 (bitcoin-node+0x186edd0) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.9759649Z     #28 mp::EventLoop::loop() /home/runner/work/libmultiprocess/libmultiprocess/src/ipc/libmultiprocess/src/mp/proxy.cpp:244:68 (bitcoin-node+0x1865b14) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.9762532Z     #29 ipc::capnp::(anonymous namespace)::CapnpProtocol::startLoop(char const*)::'lambda'()::operator()() const /home/runner/work/libmultiprocess/libmultiprocess/src/ipc/capnp/protocol.cpp:136:21 (bitcoin-node+0xf32132) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.9767171Z     #30 std::__1::__invoke_result_impl<void, ipc::capnp::(anonymous namespace)::CapnpProtocol::startLoop(char const*)::'lambda'()>::type std::__1::__invoke[abi:nqe220100]<ipc::capnp::(anonymous namespace)::CapnpProtocol::startLoop(char const*)::'lambda'()>(ipc::capnp::(anonymous namespace)::CapnpProtocol::startLoop(char const*)::'lambda'()&&) /tmp/libcxx-build/include/c++/v1/__type_traits/invoke.h:90:27 (bitcoin-node+0xf31ea2) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.9773708Z     #31 void std::__1::__thread_execute[abi:nqe220100]<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct>>, ipc::capnp::(anonymous namespace)::CapnpProtocol::startLoop(char const*)::'lambda'(), 0ul>(std::__1::tuple<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct>>, ipc::capnp::(anonymous namespace)::CapnpProtocol::startLoop(char const*)::'lambda'()>&, std::__1::__integer_sequence<unsigned long, 0ul>) /tmp/libcxx-build/include/c++/v1/__thread/thread.h:161:3 (bitcoin-node+0xf31e1a) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.9779178Z     #32 void* std::__1::__thread_proxy[abi:nqe220100]<std::__1::tuple<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct>>, ipc::capnp::(anonymous namespace)::CapnpProtocol::startLoop(char const*)::'lambda'()>>(void*) /tmp/libcxx-build/include/c++/v1/__thread/thread.h:169:3 (bitcoin-node+0xf31abd) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:21.9781398Z 
2026-03-12T20:39:21.9781647Z   Thread T14 (tid=9989, running) created by thread T2 at:
2026-03-12T20:39:22.0060788Z     #0 pthread_create <null> (bitcoin-node+0x152c1e) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0064035Z     #1 std::__1::__libcpp_thread_create[abi:nqe220100](unsigned long*, void* (*)(void*), void*) /tmp/libcxx-build/include/c++/v1/__thread/support/pthread.h:182:10 (bitcoin-node+0x239afa) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0068524Z     #2 std::__1::thread::thread[abi:nqe220100]<mp::ProxyServer<mp::ThreadMap>::makeThread(capnp::CallContext<mp::ThreadMap::MakeThreadParams, mp::ThreadMap::MakeThreadResults>)::$_0, 0>(mp::ProxyServer<mp::ThreadMap>::makeThread(capnp::CallContext<mp::ThreadMap::MakeThreadParams, mp::ThreadMap::MakeThreadResults>)::$_0&&) /tmp/libcxx-build/include/c++/v1/__thread/thread.h:218:16 (bitcoin-node+0x1868454) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0073526Z     #3 mp::ProxyServer<mp::ThreadMap>::makeThread(capnp::CallContext<mp::ThreadMap::MakeThreadParams, mp::ThreadMap::MakeThreadResults>) /home/runner/work/libmultiprocess/libmultiprocess/src/ipc/libmultiprocess/src/mp/proxy.cpp:416:17 (bitcoin-node+0x1867ff4) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0077401Z     #4 mp::ThreadMap::Server::dispatchCallInternal(unsigned short, capnp::CallContext<capnp::AnyPointer, capnp::AnyPointer>) /home/runner/work/libmultiprocess/libmultiprocess/build/src/ipc/libmultiprocess/include/mp/proxy.capnp.c++:602:9 (bitcoin-node+0x1861d5e) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0081140Z     #5 mp::ThreadMap::Server::dispatchCall(unsigned long, unsigned short, capnp::CallContext<capnp::AnyPointer, capnp::AnyPointer>) /home/runner/work/libmultiprocess/libmultiprocess/build/src/ipc/libmultiprocess/include/mp/proxy.capnp.c++:591:14 (bitcoin-node+0x1861bd1) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0242196Z     #6 virtual thunk to mp::ThreadMap::Server::dispatchCall(unsigned long, unsigned short, capnp::CallContext<capnp::AnyPointer, capnp::AnyPointer>) /home/runner/work/libmultiprocess/libmultiprocess/build/src/ipc/libmultiprocess/include/mp/proxy.capnp.c++ (bitcoin-node+0x1861ec7) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0245392Z     #7 capnp::LocalClient::callInternal(unsigned long, unsigned short, capnp::CallContextHook&) <null> (bitcoin-node+0x18c6dbd) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0247800Z     #8 capnp::LocalClient::call(unsigned long, unsigned short, kj::Own<capnp::CallContextHook, std::nullptr_t>&&, capnp::Capability::Client::CallHints)::'lambda'()::operator()() const <null> (bitcoin-node+0x18c680d) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0270071Z     #9 kj::Promise<void> kj::_::MaybeVoidCaller<kj::_::Void, kj::Promise<void>>::apply<capnp::LocalClient::call(unsigned long, unsigned short, kj::Own<capnp::CallContextHook, std::nullptr_t>&&, capnp::Capability::Client::CallHints)::'lambda'()>(capnp::LocalClient::call(unsigned long, unsigned short, kj::Own<capnp::CallContextHook, std::nullptr_t>&&, capnp::Capability::Client::CallHints)::'lambda'()&, kj::_::Void&&) <null> (bitcoin-node+0x18ce491) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0275087Z     #10 kj::_::TransformPromiseNode<kj::Promise<void>, kj::_::Void, capnp::LocalClient::call(unsigned long, unsigned short, kj::Own<capnp::CallContextHook, std::nullptr_t>&&, capnp::Capability::Client::CallHints)::'lambda'(), kj::_::PropagateException>::getImpl(kj::_::ExceptionOrValue&) <null> (bitcoin-node+0x18ce091) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0278405Z     #11 kj::_::TransformPromiseNodeBase::get(kj::_::ExceptionOrValue&)::$_0::operator()() const async.c++ (bitcoin-node+0x1ac4d13) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0281217Z     #12 kj::Maybe<kj::Exception> kj::runCatchingExceptions<kj::_::TransformPromiseNodeBase::get(kj::_::ExceptionOrValue&)::$_0>(kj::_::TransformPromiseNodeBase::get(kj::_::ExceptionOrValue&)::$_0&&) async.c++ (bitcoin-node+0x1ab51d7) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0515398Z     #13 kj::_::TransformPromiseNodeBase::get(kj::_::ExceptionOrValue&) <null> (bitcoin-node+0x1ab50cb) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0517027Z     #14 kj::_::ChainPromiseNode::fire() <null> (bitcoin-node+0x1ab70e4) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0518514Z     #15 non-virtual thunk to kj::_::ChainPromiseNode::fire() <null> (bitcoin-node+0x1ab7af9) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0519962Z     #16 kj::EventLoop::turn() <null> (bitcoin-node+0x1aafc55) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0521972Z     #17 kj::_::waitImpl(kj::Own<kj::_::PromiseNode, kj::_::PromiseDisposer>&&, kj::_::ExceptionOrValue&, kj::WaitScope&, kj::SourceLocation)::$_2::operator()() const async.c++ (bitcoin-node+0x1ac3aa4) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0525780Z     #18 void kj::WaitScope::runOnStackPool<kj::_::waitImpl(kj::Own<kj::_::PromiseNode, kj::_::PromiseDisposer>&&, kj::_::ExceptionOrValue&, kj::WaitScope&, kj::SourceLocation)::$_2>(kj::_::waitImpl(kj::Own<kj::_::PromiseNode, kj::_::PromiseDisposer>&&, kj::_::ExceptionOrValue&, kj::WaitScope&, kj::SourceLocation)::$_2&&) async.c++ (bitcoin-node+0x1ab1bc7) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0529133Z     #19 kj::_::waitImpl(kj::Own<kj::_::PromiseNode, kj::_::PromiseDisposer>&&, kj::_::ExceptionOrValue&, kj::WaitScope&, kj::SourceLocation) <null> (bitcoin-node+0x1ab1741) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0531868Z     #20 kj::Promise<unsigned long>::wait(kj::WaitScope&, kj::SourceLocation) /home/runner/work/libmultiprocess/libmultiprocess/depends/x86_64-pc-linux-gnu/include/kj/async-inl.h:1359:3 (bitcoin-node+0x186edd0) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0636278Z     #21 mp::EventLoop::loop() /home/runner/work/libmultiprocess/libmultiprocess/src/ipc/libmultiprocess/src/mp/proxy.cpp:244:68 (bitcoin-node+0x1865b14) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0639303Z     #22 ipc::capnp::(anonymous namespace)::CapnpProtocol::startLoop(char const*)::'lambda'()::operator()() const /home/runner/work/libmultiprocess/libmultiprocess/src/ipc/capnp/protocol.cpp:136:21 (bitcoin-node+0xf32132) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0824125Z     #23 std::__1::__invoke_result_impl<void, ipc::capnp::(anonymous namespace)::CapnpProtocol::startLoop(char const*)::'lambda'()>::type std::__1::__invoke[abi:nqe220100]<ipc::capnp::(anonymous namespace)::CapnpProtocol::startLoop(char const*)::'lambda'()>(ipc::capnp::(anonymous namespace)::CapnpProtocol::startLoop(char const*)::'lambda'()&&) /tmp/libcxx-build/include/c++/v1/__type_traits/invoke.h:90:27 (bitcoin-node+0xf31ea2) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0830809Z     #24 void std::__1::__thread_execute[abi:nqe220100]<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct>>, ipc::capnp::(anonymous namespace)::CapnpProtocol::startLoop(char const*)::'lambda'(), 0ul>(std::__1::tuple<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct>>, ipc::capnp::(anonymous namespace)::CapnpProtocol::startLoop(char const*)::'lambda'()>&, std::__1::__integer_sequence<unsigned long, 0ul>) /tmp/libcxx-build/include/c++/v1/__thread/thread.h:161:3 (bitcoin-node+0xf31e1a) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0836906Z     #25 void* std::__1::__thread_proxy[abi:nqe220100]<std::__1::tuple<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct>>, ipc::capnp::(anonymous namespace)::CapnpProtocol::startLoop(char const*)::'lambda'()>>(void*) /tmp/libcxx-build/include/c++/v1/__thread/thread.h:169:3 (bitcoin-node+0xf31abd) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0839537Z 
2026-03-12T20:39:22.0840321Z   Thread T2 'b-capnp-loop' (tid=9612, running) created by main thread at:
2026-03-12T20:39:22.0841552Z     #0 pthread_create <null> (bitcoin-node+0x152c1e) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0843814Z     #1 std::__1::__libcpp_thread_create[abi:nqe220100](unsigned long*, void* (*)(void*), void*) /tmp/libcxx-build/include/c++/v1/__thread/support/pthread.h:182:10 (bitcoin-node+0x239afa) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0847465Z     #2 std::__1::thread::thread[abi:nqe220100]<ipc::capnp::(anonymous namespace)::CapnpProtocol::startLoop(char const*)::'lambda'(), 0>(ipc::capnp::(anonymous namespace)::CapnpProtocol::startLoop(char const*)::'lambda'()&&) /tmp/libcxx-build/include/c++/v1/__thread/thread.h:218:16 (bitcoin-node+0xf317e6) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.0851416Z     #3 ipc::capnp::(anonymous namespace)::CapnpProtocol::startLoop(char const*) /home/runner/work/libmultiprocess/libmultiprocess/src/ipc/capnp/protocol.cpp:127:25 (bitcoin-node+0xf3161c) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.1120711Z     #4 ipc::capnp::(anonymous namespace)::CapnpProtocol::listen(int, char const*, interfaces::Init&) /home/runner/work/libmultiprocess/libmultiprocess/src/ipc/capnp/protocol.cpp:87:9 (bitcoin-node+0xf30e82) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.1124246Z     #5 ipc::(anonymous namespace)::IpcImpl::listenAddress(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>>&) /home/runner/work/libmultiprocess/libmultiprocess/src/ipc/interfaces.cpp:111:21 (bitcoin-node+0xf2a5d7) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.1127937Z     #6 AppInitMain(node::NodeContext&, interfaces::BlockAndHeaderTipInfo*) /home/runner/work/libmultiprocess/libmultiprocess/src/init.cpp:1505:22 (bitcoin-node+0x205c88) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.1130803Z     #7 AppInit(node::NodeContext&) /home/runner/work/libmultiprocess/libmultiprocess/src/bitcoind.cpp:242:43 (bitcoin-node+0x1db4c7) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.1133275Z     #8 main /home/runner/work/libmultiprocess/libmultiprocess/src/bitcoind.cpp:283:10 (bitcoin-node+0x1d9ef1) (BuildId: c2342a169a817ba8295d6726e1fdb3cfe82e4376)
2026-03-12T20:39:22.1134315Z 
2026-03-12T20:39:22.1136443Z SUMMARY: ThreadSanitizer: heap-use-after-free (virtual call vs free) /home/runner/work/libmultiprocess/libmultiprocess/depends/x86_64-pc-linux-gnu/include/capnp/capability.h:1129:16 in capnp::CallContext<ipc::capnp::messages::BlockTemplate::WaitNextParams, ipc::capnp::messages::BlockTemplate::WaitNextResults>::getParams()
2026-03-12T20:39:22.1139195Z ================== 
2026-03-12T20:39:22.1139428Z 

@Sjors Sjors marked this pull request as ready for review March 12, 2026 20:47
@maflcko
Copy link
Contributor

maflcko commented Mar 12, 2026

More likely to be brittleness in the test itself under high CPU pressure:

Does the test timeout not scale with --timeout-factor?

@Sjors
Copy link
Member Author

Sjors commented Mar 12, 2026

More likely to be brittleness in the test itself under high CPU pressure:

Does the test timeout not scale with --timeout-factor?

We should probably make waitoptions.timeout scale with that factor.

@Sjors
Copy link
Member Author

Sjors commented Mar 13, 2026

I opened #257 to see if #253 makes the error go away. Since the new PR can't use the cache from this PR, I noticed some mistakes in the build pipeline, which I'm fixing now.

@Sjors Sjors marked this pull request as draft March 13, 2026 09:26
@Sjors Sjors force-pushed the 2026/03/ci-core branch from 9cbb498 to 746beea Compare March 13, 2026 09:33
@Sjors Sjors marked this pull request as ready for review March 13, 2026 09:58
@Sjors
Copy link
Member Author

Sjors commented Mar 13, 2026

Unfortunately the TSan job doesn't reliably catch the known regression. I'd rather not make the job slower. Since it did catch it once, it would make sense to have longer runs on master. Let's add those in a followup.

enirox001 added a commit to enirox001/bitcoin that referenced this pull request Mar 13, 2026
The IPC mining tests (interface_ipc_mining.py) currently use
hardcoded timeouts (e.g., 1000ms, 60000ms) for operations like
waitTipChanged and waiting for block templates. In heavily
loaded CI environments, such as those running sanitizers with
high parallelism, these hardcoded timeouts can be too short,
leading to spurious test failures and brittleness.

This commit multiplies these timeout variables by the test
suite's global `self.options.timeout_factor`. This ensures that
the IPC wait conditions scale appropriately when the test suite
is run with a higher timeout factor, making the tests robust
against slow execution environments.

Addresses CI brittleness observed in bitcoin-core/libmultiprocess#253.
enirox001 added a commit to enirox001/bitcoin that referenced this pull request Mar 13, 2026
The IPC mining tests (interface_ipc_mining.py) currently use
hardcoded timeouts (e.g., 1000ms, 60000ms) for operations like
waitTipChanged and waiting for block templates. In heavily
loaded CI environments, such as those running sanitizers with
high parallelism, these hardcoded timeouts can be too short,
leading to spurious test failures and brittleness.

This commit multiplies these timeout variables by the test
suite's global `self.options.timeout_factor`. This ensures that
the IPC wait conditions scale appropriately when the test suite
is run with a higher timeout factor, making the tests robust
against slow execution environments.

Addresses CI brittleness observed in bitcoin-core/libmultiprocess#253.
@Sjors
Copy link
Member Author

Sjors commented Mar 13, 2026

I've been running TSan on an AMD Ryzen 9 7950X with 16 cores and 64 GB RAM. It's not that easy to hit any of the failures #249 fixes. Sometimes it finds one after a few minutes, other times it finds nothing for half an hour. So I'm not surprised CI on this PR doesn't consistently hit them.

For finding heap-use-after-free it seems to help (a lot) to throttle CPU a bit on Podman (e.g. --cpus 8).

@maflcko
Copy link
Contributor

maflcko commented Mar 13, 2026

If you feel fancy, you can try tsan-23 with the new adaptive delay feature (https://clang.llvm.org/docs/ThreadSanitizer.html#enabling-adaptive-delay). Though, tsan-23 isn't released yet, so up to you, if you want to compile it here in CI or locally.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

5 participants