tests: Improve runtime of some tests when --enable-debug
#26656
Merged
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
|
The following sections might be updated with supplementary metadata relevant to reviewers and maintainers. ReviewsSee the guideline for information on the review process.
If your review is incorrectly listed, please react with 👎 to this comment and the bot will ignore it on the next update. ConflictsReviewers, this pull request conflicts with the following ones:
If you consider this pull request important, please also help to review the conflicting pull requests. Ideally, start with the one that should be merged first. |
achow101
force-pushed
the
faster-test-runner-when-debug
branch
from
e40194e
to
5dac98e
Compare
|
Concept ACK - seeing significant speedup when running the modified tests under |
achow101
force-pushed
the
faster-test-runner-when-debug
branch
2 times, most recently
from
0844fa4
to
de57981
Compare
This was referenced Dec 8, 2022
Generating blocks is slow, especially when --enable-debug. There is no need to generate a new block for each transaction, so avoid doing that to improve this test's runtime.
feature_fee_estimation has a lot of loops that hit the RPC many times in succession in order to setup scenarios. Using batched requests for these can reduce the test's runtime without effecting the test's behavior.
The sigops draining script in feature_taproot's block_submit was initialized with a list that would end up always being iterated by CScript's constructor. Since this list is very large, a lot of time would be wasted. By creating and passing a bytes object initialized from that list, we can avoid this iteration and dramatically improve the runtime of feature_taproot.
The work queue exceeded test in interface_rpc.py would repeatedly call an RPC until the error was achieved. However hitting this error is dependent on the processing speed of the computer and the optimization level of the binary. Configurations that result in slower processing would result in the RPC used being processed before the error could be hit, resulting the test's runtime having a high variance. Switching the RPC to waitfornewblock allows it to run in a much more consistent time that is still fairly fast. waitfornewblock forces the RPC server to allocate a thread and wait, occupying a spot in the work queue. This is perfect for this test because the slower the RPC, the more likely we will achieve the race condition necessary to pass the test. Using a timeout of 500 ms appears to work reliably without causing the test to take too long.
test_submit_child_with_parents creates a p2p connection which waits for the node to announce transactions to it. By whitelisting this connection, we can reduce the amount of time spent waiting for this announcement which improves the test runtime and runtime variance.
The logest running tests should be at the front of the list in test_runner.py. Since compiling with --enable-debug can have a significant effect on test runtime, the order is based on the runtime with that option configured.
achow101
force-pushed
the
faster-test-runner-when-debug
branch
from
de57981
to
1647a11
Compare
|
Concept ACK! This is great to see and is something that has been bothering me for quite some time. Without this PR tests for me were taking 268 seconds to run, where:
After this PR my total test time reduced to 171 seconds, where:
This leaves me with the following tests taking over 1 minute runtime: |
willcl-ark
approved these changes
Dec 16, 2022
There was a problem hiding this comment.
ACK 1647a11
The final tests to finish for me with --enable-debug and 50 jobs are generally:
245/255 - feature_coinstatsindex.py passed, Duration: 25 s
246/255 - p2p_headers_sync_with_minchainwork.py passed, Duration: 93 s
247/255 - wallet_taproot.py --descriptors passed, Duration: 94 s
248/255 - feature_config_args.py passed, Duration: 35 s
249/255 - p2p_blockfilters.py passed, Duration: 105 s
250/255 - feature_assumevalid.py passed, Duration: 105 s
251/255 - p2p_segwit.py passed, Duration: 107 s
252/255 - mempool_updatefromblock.py passed, Duration: 116 s
253/255 - feature_taproot.py passed, Duration: 155 s
254/255 - feature_block.py passed, Duration: 175 s
255/255 - feature_fee_estimation.py passed, Duration: 209 s
So the new ordering of the list feels pretty good.
Sign up for free
to subscribe to this conversation on GitHub.
Already have an account?
Sign in.
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
When configured with
--enable-debug, many tests become dramatically slower. These slow downs are particularly noticed in tests that generate a lot of blocks in separate calls, make a lot of RPC calls, or send a lot of data from the test framework's P2P connection. This PR aims to improve the runtime of some of the slower tests and improve the overall runtime of the test runner. This has improved the runtime of the test runner from ~400s to ~140s on my computer.The slowest test by far was
wallet_import_rescan.py. This was taking ~320s. Most of that time was spent waiting for blocks to be mined and then synced to the other nodes. It was generating a new block for every new transaction it was creating in a setup loop. However it is not necessary to have one tx per block. By mining a block only every 10 txs, the runtime is improved to ~61s.The second slowest test was
feature_fee_estimation.py. This test spends most of its time waiting for RPCs to respond. I was able to improve its runtime by batching RPC requests. This has improved the runtime from ~201s to ~140s.In
feature_taproot.py, the test was constructing a PythonCScriptusing a very large list ofOP_CHECKSIGs. The constructor for the Python implementation ofCScriptwas iterating this list in order to create abytesfrom it even though abytescould be created from it without iterating. By making thebytesbefore passing it into the constructor, we are able to improve this test's runtime from ~131s to ~106s.Although
interface_rpc.pywas not typically a slow test, I found that it would occasionally have a super long runtime. It typically takes ~7s, but I have observed it taking >400s to run on occasion. This longer runtime occurs more often when--enable-debug. This long runtime was caused by the "exceeding work queue" test which is really just trying to trigger a race condition. In this test, it would create a few threads and try an RPC in a loop in the hopes that eventually one of the RPCs would be added to the work queue while another was processing. It usedgetrpcinfofor this, but this function is fairly fast. I believe what was happening was that with--enable-debug, all of the code for receiving the RPC would often take longer to run than the RPC itself, so the majority of the requests would succeed, until we got lucky after 10's of thousands of requests. By changing this to use a slow RPC, the race condition can be triggered more reliably, and much sooner as well. I've usedwaitfornewblockwith a 500ms timeout. This improves the runtime to ~3s consistently.The last test I've changed was
rpc_packages.py. This test was one of the higher runtime variability tests. The main source of this variation appears to be waiting for the test node to relay a transaction to the test framework's P2P connection. By whitelisting that peer, the variability is reduced to nearly 0.Lastly, I've reordered the tests in
test_runner.pyto account for the slower runtimes when configured with--enable-debug. Some of the slow tests I've looked at were listed as being fast which was causing overalltest_runner.pyruntime to be extended. This change makes the test runner's runtime be bounded by the slowest test (currentlyfeature_fee_estimation.pywith my usual config (-j 60).