test: poll more frequently in sync helpers and RPC connection wait #36439

ViniciusCestarii commented at 3:27 PM on October 5, 2026: contributor

Tested on my x86-64 machine:

Wall time (-j=18): 110.8s to 96.4s (−13%)
Accumulated: 1715s to 1369s (−20%)

Also compared the CI on my fork (time for test_runner.py runtime):

macOS native: 1287s to 1175s (-9%)
32 bit ARM: 776s to 690s (-11%)
Windows native, VS: 1456s to 1252s (-14%)
previous releases: 930s to 786s (-15%)
No wallet: 614s to 572s (-7%)
Alpine (musl): 1958s to 1970s (+0.6%)

Sanitizer jobs are left out because they vary too much between runs.

Alpine (musl) uses --usecli, so more frequent poll creates a new bitcoin-cli process each time, making it not faster with these changes. Also tried locally with --usecli: from 2060s to 2051s accumulated.

DrahtBot added the label Tests on Oct 5, 2026

DrahtBot commented at 3:28 PM on October 5, 2026: contributor

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

External sites

Code coverage & benchmarks: https://corecheck.dev/bitcoin/bitcoin/pulls/36439
Ralph review <img src=https://review.fish.foo/assets/bitcoin/bitcoin/36439.png alt="Ralph review status"> https://git.fish.foo/bitcoin/bitcoin/pulls/36439#author-ralph

Reviews

See the guideline and AI policy for information on the review process.

Type	Reviewers
ACK	maflcko

If your review is incorrectly listed, please copy-paste <code></code> into the comment that the bot should ignore.

in test/functional/test_framework/test_node.py:357 in 12caa3325d outdated

 352 | @@ -353,8 +353,8 @@ def create_new_rpc_connection(self, *, mode="AUTO", client_timeout=None):
 353 |  
 354 |      def wait_for_rpc_connection(self, *, wait_for_import=True):
 355 |          """Sets up an RPC connection to the bitcoind process. Returns False if unable to connect."""
 356 | -        # Poll at a rate of four times per second
 357 | -        poll_per_s = 4
 358 | +        # Poll at a rate of twenty times per second
 359 | +        poll_per_s = 20

maflcko commented at 7:24 AM on October 6, 2026:

nit: Use a deadline time here as well?

ViniciusCestarii commented at 12:41 PM on October 6, 2026:

Makes sense, Done in 88d40ec15510a8d029c1eaffbae9c068da18f5f9

in test/functional/test_framework/test_framework.py:720 in 12caa3325d outdated

 716 | @@ -717,7 +717,7 @@ def sync_blocks(self, nodes=None, wait=1, timeout=60):
 717 |              "".join("\n  {!r}".format(b) for b in best_hash),
 718 |          ))
 719 |  
 720 | -    def sync_mempools(self, nodes=None, wait=1, timeout=60, flush_scheduler=True):
 721 | +    def sync_mempools(self, nodes=None, wait=0.05, timeout=60, flush_scheduler=True):

maflcko commented at 7:24 AM on October 6, 2026:

Pretty sure I tried this one in the past, but it didn't result in a speed-up. I guess back then the trickle relay was used, and dominated. Now, the immediate tx relay is used for most tests and it can help.

ViniciusCestarii commented at 1:23 PM on October 6, 2026:

Interesting, makes sense.

maflcko commented at 7:27 AM on October 6, 2026: member

haven't tested this, but it seems fine. I wonder if someone wants to create some plots to show this is an improvement (and to see the performance plot around the values). Also, I think functional tests are run at double saturation (2*nproc) sometimes, so it would be good to check this doesn't regress either.

ViniciusCestarii force-pushed on Oct 6, 2026

ViniciusCestarii commented at 1:20 PM on October 6, 2026: contributor

Thanks @maflcko for reviewing. Force-pushed 88d40ec15510a8d029c1eaffbae9c068da18f5f9 addressing #36439 (review)

I think functional tests are run at double saturation (2*nproc) sometimes, so it would be good to check this doesn't regress either.

By what I found, only the job "test ancestor commits" does it. Agree it's worth checking.

create some plots to show this is an improvement (and to see the performance plot around the values)

Will do.

ViniciusCestarii commented at 7:08 PM on October 6, 2026: contributor

I benchmarked these changes on my x86-64 machine with 20 logic processors:

master is the baseline and w0.05 is this PR.
rpc20 is only the wait_for_rpc_connection change, sync0.05 is only the sync changes.
w0.X sets both the sync wait and the RPC connection poll interval to X seconds.
Wall time is how long the whole suite took, running the tests in parallel.
The sum is the total of each test's own wall-clock duration, measured while running in parallel.

Most of the gain comes from the sync change and RPC poll change adds a smaller one on top. Below 0.05 there is no further improvement and at -j40 polling faster (w0.01) starts to cost more than it saves, so 0.05 looks like the right value.

It'd be great if others could run it too.

I measured this with this script: https://gist.github.com/ViniciusCestarii/72216066d3707b41b3b5b2292b07055b usign the command:

python3 pollbench.py --jobs 20,40 --runs 5 --variants master=1:4,w0.25=0.25:4,w0.1=0.1:10,w0.05=0.05:20,w0.025=0.025:40,w0.01=0.01:100,sync0.05=0.05:4,rpc20=1:20

I used AI to help me make this benchmark script and plot the data.

in test/functional/test_framework/test_framework.py:698 in 88d40ec155

 694 | @@ -695,7 +695,7 @@ def create_outpoints(self, node, *, outputs):
 695 |              utxos.append({"txid": send_res["txid"], "vout": vout})
 696 |          return utxos
 697 |  
 698 | -    def sync_blocks(self, nodes=None, wait=1, timeout=60):
 699 | +    def sync_blocks(self, nodes=None, wait=0.05, timeout=60):

maflcko commented at 12:03 PM on October 14, 2026:

    def sync_blocks(self, nodes=None, *, wait=0.05, timeout=60):

nit: force named kwargs while touching this line? Same below

ViniciusCestarii commented at 1:26 PM on October 14, 2026:

kwargs are nice, done on 0b928e01df34e46e1604a3e9c88acc7b5910b82f

ViniciusCestarii force-pushed on Oct 14, 2026

maflcko commented at 8:56 AM on October 15, 2026: member

I used AI to help me make this benchmark script and plot the data.

Nice. I asked an LLM bot to run a few benches on my Travel Laptop (155H cpu).

It seems that 0.05 is ideal when running tests stand-alone (-j1) on this weaker CPU. On your machine I expect for -j1, that w0.025 may be faster (but not significantly).
For saturated runs (with or without valgrind), on the 155H machine 0.1 was faster. But I don't really run the tests often on this machine, and there was a lot of noise anyway.
The valgrind test runs failed (probably due to a small --timeout-factor )

So I think the takeaway is that 0.05 is a valid choice.

I wonder if some sanitizer-heavy CIs (tsan, msan, asan) will also benefit from this, or is the variance too high to see something here?

in test/functional/test_framework/test_node.py:366 in 0b928e01df

 364 |              suppressed_errors[category] += 1
 365 |              return (category, repr(e))
 366 |  
 367 | -        for _ in range(poll_per_s * self.rpc_timeout):
 368 | +        stop_time = time.time() + self.rpc_timeout
 369 | +        while time.time() <= stop_time:

maflcko commented at 8:57 AM on October 15, 2026:

<details><summary>nit from the Ralph LLM to use monotonic time.</summary>

Use a monotonic clock for the RPC startup deadline (test/functional/test_framework/test_node.py:365, head)

time.time() can jump during startup polling: a forward adjustment can make the loop fail before rpc_timeout elapses, while a backward adjustment can extend the wait. Use time.monotonic() for both deadline creation and comparison. No actual host-clock adjustment during startup was identified, so the impact is conditional on that trigger.

</details>

ViniciusCestarii commented at 10:53 AM on October 15, 2026:

Done in 8898f832d9d86d5a6a8ad8719e1009c702bbf4bd. There are also other tests that use time.time() for measuring duration instead of monotonic that could also be changed, but I guess clock jumping is not common so it is a non issue today.

maflcko commented at 9:00 AM on October 15, 2026: member

Lgtm. Just curious about the sanitizer CI, but not a blocker.

review ACK 0b928e01df34e46e1604a3e9c88acc7b5910b82f 📗

<details><summary>Show signature</summary>

Signature:

untrusted comment: signature from minisign secret key on empty file; verify via: minisign -Vm "${path_to_any_empty_file}" -P RWTRmVTMeKV5noAMqVlsMugDDCyyTSbA3Re5AkUrhvLVln0tSaFWglOw -x "${path_to_this_whole_four_line_signature_blob}"
RUTRmVTMeKV5npGrKx1nqXCw5zeVHdtdYURB/KlyA/LMFgpNCs+SkW9a8N95d+U4AP1RJMi+krxU1A3Yux4bpwZNLvVBKy0wLgM=
trusted comment: review ACK 0b928e01df34e46e1604a3e9c88acc7b5910b82f 📗
0IXqiylZQjxuuk6J4C7wqmmSdT8AVA47WEeDErc3gRB7ImQUDzovFJuxaJx4jadY9vJeNQ3eGB8UaLjServ9DQ==

</details>

test: poll more frequently in sync helpers and RPC connection wait 8898f832d9

ViniciusCestarii force-pushed on Oct 15, 2026

maflcko commented at 11:44 AM on October 15, 2026: member

The latest Ralph Review is hallucinated AI slop (https://review.fish.foo/traces/36439-8898f832d9d86d5a6a8ad8719e1009c702bbf4bd-804-4.html). cc @willcl-ark for awareness, but seems fine to just ignore.

Only change is addressing the prior Ralph Review nit.

review ACK 8898f832d9d86d5a6a8ad8719e1009c702bbf4bd 👪

<details><summary>Show signature</summary>

Signature:

untrusted comment: signature from minisign secret key on empty file; verify via: minisign -Vm "${path_to_any_empty_file}" -P RWTRmVTMeKV5noAMqVlsMugDDCyyTSbA3Re5AkUrhvLVln0tSaFWglOw -x "${path_to_this_whole_four_line_signature_blob}"
RUTRmVTMeKV5npGrKx1nqXCw5zeVHdtdYURB/KlyA/LMFgpNCs+SkW9a8N95d+U4AP1RJMi+krxU1A3Yux4bpwZNLvVBKy0wLgM=
trusted comment: review ACK 8898f832d9d86d5a6a8ad8719e1009c702bbf4bd 👪
14xsoD5byMfCVUC6Zz159xzCmz5IFtA3/d5pz3EanTOQ9XUI6lwhMh1Cc7X5EUgdyAb2O4WdAMhMdqJYgVEVCQ==

</details>

DrahtBot added the label CI failed on Oct 16, 2026

DrahtBot removed the label CI failed on Oct 16, 2026

fanquake merged this on Oct 16, 2026

fanquake closed this on Oct 16, 2026