f19f0a2e5a test: Run framework unit tests in parallel (tdb3)
Pull request description:
Functional test framework unit tests are currently run prior to all other functional tests.
This PR enables execution of the test framework unit tests in parallel with the functional tests, rather than before the functional tests, saving runtime and more efficiently using available cores.
This is a follow up to https://github.com/bitcoin/bitcoin/pull/29470#issuecomment-1962313977
### New behavior:
1) When running all tests, the framework unit tests are run in parallel with the other tests (unless explicitly skipped with `--exclude`). This parallelization introduces marginal time savings when running all tests, depending on the machine used. As an example, a 2-3% time savings (9 seconds) was observed on a machine using `--jobs=18` (with 18 available cores).
2) When running specific functional tests, framework unit tests are now skipped by default. Framework unit tests can be added by including `feature_framework_unit_tests.py` in the list of specific tests being executed. The rationale for skipping by default is that if the tester is running specific functional tests, there is a conscious decision to focus testing, and choosing to run all tests (where unit tests are run by default) would be a next step.
3) The `--skipunit` option is now removed since unit tests are parallelized (they no longer delay other tests). Unit tests are treated equally as functional tests.
### Implementation notes:
Since `TextTestRunner` can be noisy (even with verbosity=0, and therefore trigger job failure through the presence of non-failure stderr output), the approach taken was to send output to stdout, and forward test result (as determined by `TestResult` returned). This aligns with the previous check for unit test failure (`if not result.wasSuccessful():`).
This approach was tested by inserting `self.assertEquals(True, False)` into test_framework/address.py and seeing specifics of the failure reported.
```
135/302 - feature_framework_unit_tests.py failed, Duration: 0 s
stdout:
.F
======================================================================
FAIL: test_bech32_decode (test_framework.address.TestFrameworkScript.test_bech32_decode)
----------------------------------------------------------------------
Traceback (most recent call last):
File "/home/dev/myrepos/bitcoin/test/functional/test_framework/address.py", line 228, in test_bech32_decode
self.assertEqual(True, False)
AssertionError: True != False
----------------------------------------------------------------------
Ran 2 tests in 0.003s
FAILED (failures=1)
stderr:
```
There was an initial thought to parallelize the execution of the unit tests themselves (i.e. run the 12 unit test files in parallel), however, this is not anticipated to further reduce runtime meaningfully and is anticipated to add unnecessary complexity.
ACKs for top commit:
maflcko:
ACK f19f0a2e5a🌽
achow101:
ACK f19f0a2e5a
kevkevinpal:
Approach ACK f19f0a2e5a
Tree-SHA512: ab9f82c30371b2242bc7a263ea0e25d35e68e2ddf223d2a55498ad940d1e5b73bba76cce8b264d71e2ed31b753430d8ef8d57efc1e4fd9ced7fb845e27f4f47e
3e9c736a26 test: fix accurate multisig sigop count (BIP16), add unit test (Sebastian Falbesoner)
Pull request description:
In the course of reviewing #29589 I noticed the following buggy call-site of `CScriptOp.decode_op_n` in the CScript's `GetSigOpCount` method:
4cc99df44a/test/functional/test_framework/script.py (L591-L593)
This should be `lastOpcode` rather than `opcode`. The latter is either OP_CHECKMULTISIG or OP_CHECKMULTISIGVERIFY at this point, so `decode_op_n` would result in an error. Also, in `CScript.raw_iter`, we have to return the op as `CScriptOp` type instead of a bare integer, otherwise we can't call the decode method on it. To prevent this in the future, add some simple unit tests for `GetSigOpCount`.
Note that this was unnoticed, as the code part was never hit so far in the test framework.
ACKs for top commit:
achow101:
ACK 3e9c736a26
Christewart:
ACK 3e9c736a26
rkrux:
tACK [3e9c736](3e9c736a26)
hernanmarino:
tACK 3e9c736a26
Tree-SHA512: 51647bb6d462fbd101effd851afdbd6ad198c0567888cd4fdcac389a9fb4bd3d7e648095c6944fd8875d36272107ebaabdc62d0e2423289055588c12294d05a7
c4f857cc30 test: Extends wait_for_getheaders so a specific block hash can be checked (Sergi Delgado Segura)
Pull request description:
Fixes https://github.com/bitcoin/bitcoin/issues/18614
Previously, `wait_for_getheaders` would check whether a node had received **any** getheaders message. This implied that, if a test needed to check for a specific block hash within a headers message, it had to make sure that it was checking the desired message. This normally involved having to manually clear `last_message`. This method, apart from being too verbose, was error-prone, given an undesired `getheaders` would make tests pass.
This adds the ability to check for a specific block_hash within the last `getheaders` message.
ACKs for top commit:
achow101:
ACK c4f857cc30
BrandonOdiwuor:
crACK c4f857cc30
cbergqvist:
ACK c4f857cc30
stratospher:
tested ACK c4f857c. went through all getheaders messages sent in the tests and checked that it's the one we want.
Tree-SHA512: afc9a31673344dfaaefcf692ec2ab65958c3d4c005f5f3af525e9960f0622d8246d5311e59aba06cfd5c9e0ef9eb90a7fc8e210f030bfbe67b897c061efdeed1
3bf4f8db66 lint: scripted-diff verification also requires GNU grep (Sjors Provoost)
Pull request description:
I noticed while trying to verify all historical `scripted-diff:` commits on macOS that some scripts require GNU sed.
For example 0d6d2b650d uses `git grep --perl-regexp`.
ACKs for top commit:
hernanmarino:
cr ACK 3bf4f8db66
maflcko:
utACK 3bf4f8db66
achow101:
ACK 3bf4f8db66
alfonsoromanz:
Tested ACK 3bf4f8db66
kristapsk:
cr utACK 3bf4f8db66
Tree-SHA512: 09a060ab1bafad03df60d0f20c3dd1451850868dbd66ea38b18178b6230c1f06cf48622db82d9c51422d5689962ee0cd7aae0a31f84bd6d878215e6d73c1d47e
fa6ab0d020 rpc: Reword SighashFromStr error message (MarcoFalke)
Pull request description:
Put quotes around the parameter. In theory, `std::quoted` should be used, but that seems overkill.
This should avoid error messages such as `A valid sighash parameter is not a valid sighash parameter. (code -8)`.
Also, it should fix fuzz false positives when searching for internal bugs in the `rpc` fuzz target. For example, `ZGVzY3JpcHRvcnByb2Nlc3Nwc2J0XP9ce1tdXOVJbnRlcm5hbCBidWcgZGV0ZWN0ZWQAXQ0AHfcAXQ1p7TJv`.
ACKs for top commit:
dergoegge:
ACK fa6ab0d020
brunoerg:
utACK fa6ab0d020
Tree-SHA512: e2c0cc0126de61873a863af38b7b0a23d2dadd596ca0418dae2ad091e8acfb6a9d657c376d59187bb008989dc78c6b44fe518590e5217e4049a867b220c9fb18
Reorganize functional test framework unit tests to run in parallel
with other functional tests.
The option `skipunit` is removed, since unit tests no longer delay
functional test execution.
Unit tests are run by default when running all tests, and can be
run explicitly with `feature_framework_unit_tests.py` when running
a subset of tests.
4357158c47 wallet: return and display signer error (Sjors Provoost)
dc55531087 wallet: compare address returned by displayaddress (Sjors Provoost)
6c1a2cc09a test: use h marker for external signer mock (Sjors Provoost)
Pull request description:
* HWI returns the requested address: as a sanity check, we now compare that to what we expected
* external signer documentation now reflects that HWI alternatives must implement this check
* both RPC and GUI will now return an error text, rather than just fail (the GUI even failed silently in some cases)
ACKs for top commit:
brunoerg:
ACK 4357158c47
achow101:
ACK 4357158c47
Tree-SHA512: 4f56edf3846745c8e7d08ef55cf29e8bb468256457149377c5f02da097931f9ca0c06bdbd856dc2385cde4fd11e4dc3b634c5a48814ff27f5562c8a25d43da93
e30e8625bb test: remove duplicated ban test (brunoerg)
Pull request description:
Test the ban list is preserved through restart has been done by both `rpc_setban` and `p2p_disconnect_ban`. Since `p2p_disconnect_ban` does it in a more elegant way, we can keep only it and remove the other one.
bf1b6383db/test/functional/p2p_disconnect_ban.py (L74-L110)
ACKs for top commit:
achow101:
ACK e30e8625bb
tdb3:
ACK for e30e8625bb.
hernanmarino:
tested ACK e30e8625bb
BrandonOdiwuor:
ACK e30e8625bb
alfonsoromanz:
ACK e30e8625bb
Tree-SHA512: e89624f23011e6ffd76c31b2933b8386711e1d2c03366d6b3ea850484a4fd571f69971cdbc75ce2f546d541cb3fc7f4d495a5a011217d879746414e3286ac111
6d91cb781c test: add unit tests for `calculate_input_weight` (Sebastian Falbesoner)
f81fad5e0f test: introduce and use `calculate_input_weight` helper (Sebastian Falbesoner)
Pull request description:
Rather than manually estimating an input's weight by adding up all the involved components (fixed-size skeleton, compact-serialized lengths, and the actual scriptSig / witness stack items) we can simply take use of the serialization classes `CTxIn` / `CTxInWitness` instead, to achieve the same with significantly less code.
The new helper is used in the functional tests rpc_psbt.py and wallet_send.py, where the previous manual estimation code was
duplicated. Unit tests are added in the second commit.
ACKs for top commit:
kevkevinpal:
tACK [6d91cb7](6d91cb781c)
QureshiFaisal:
tACK [6d91cb7](6d91cb781c)
achow101:
ACK 6d91cb781c
AngusP:
tACK 6d91cb781c
rkrux:
tACK [6d91cb7](6d91cb781c)
Tree-SHA512: 04424e4d94d0e13745a9c11df2dd3697c98552bbb0e792c4af67ecbb66060adc3cc0cefc202cdee2d9db0baf85b8bedf2eb339ac4b316d986b5f10f6b70c5a33
fa6c300a99 test: Fix intermittent timeout in p2p_tx_download.py (MarcoFalke)
Pull request description:
Currently the test passes, but may fail during shutdown, because blocks and transactions are synced with `NUM_INBOUND` * `self.num_nodes` peers, which may take a long time.
There is no need for this test to have this amount of inbounds.
So avoid the extraneous inbounds to speed up the test and avoid the intermittent test failures.
ACKs for top commit:
instagibbs:
ACK fa6c300a99
fjahr:
Thanks, ACK fa6c300a99
achow101:
ACK fa6c300a99
theStack:
ACK fa6c300a99
Tree-SHA512: 0a480fd1db293ed8571ae629557cf81d5a79ec883e9e635f22c8a7cf48427161249ad2180b66c67661306f696c977b8e06ad520bd11911f119c9c95b3ffc9134
6b02c11d66 test: Fix intermittent issue in p2p_handshake.py (stratospher)
Pull request description:
When establishing outbound connections [`TestNode` --------> `P2PConnection`], `P2PConnection` listens for a single connection from `TestNode` on a [port which is fixed based on `p2p_idx`](312f54278f/test/functional/test_framework/p2p.py (L746)).
If we reuse the same port when disconnecting and establishing connections again, we might hit this scenario where:
- disconnection is done on python side for `P2PConnection`
- disconnection not complete on c++ side for `TestNode`
- we're trying to establish a new connection on same port again
Prevent this scenario from happening by ensuring disconnection on c++ side for TestNode as well.
One way to reproduce this on master would be adding a sleep statement before disconnection happens on c++ side.
```diff
diff --git a/src/net.cpp b/src/net.cpp
index e388f05b03..62507d1f39 100644
--- a/src/net.cpp
+++ b/src/net.cpp
@@ -2112,6 +2112,7 @@ void CConnman::SocketHandlerConnected(const std::vector<CNode*>& nodes,
if (!pnode->fDisconnect) {
LogPrint(BCLog::NET, "socket closed for peer=%d\n", pnode->GetId());
}
+ std::this_thread::sleep_for(std::chrono::milliseconds(1000));
pnode->CloseSocketDisconnect();
}
else if (nBytes < 0)
```
ACKs for top commit:
maflcko:
lgtm ACK 6b02c11d66
mzumsande:
Tested ACK 6b02c11d66
BrandonOdiwuor:
Tested ACK 6b02c11d66
theStack:
Tested ACK 6b02c11d66
glozow:
ACK 6b02c11d66
Tree-SHA512: 69509edb61ba45739fd585b6cc8a254f412975c124a5b5a52688288ecaaffd264dd76019b8290cc34c26c3ac2dfe477965ee5a11d7aabdd8e4d2a75229a4a068
21d0e6c7b7 doc: release notes for PR 27679 (Matthew Zipkin)
791dea204e test: cover unix sockets in zmq interface (Matthew Zipkin)
c87b0a0ff4 zmq: accept unix domain socket address for notifier (Matthew Zipkin)
Pull request description:
This is a follow-up to https://github.com/bitcoin/bitcoin/pull/27375, allowing ZMQ notifications to be published to a UNIX domain socket.
Fortunately, libzmq handles unix sockets already, all we really have to do to support it is allow the format in the actual option.
[libzmq](https://libzmq.readthedocs.io/en/latest/zmq_ipc.html) uses the prefix `ipc://` as opposed to `unix:` which is [used by Tor](https://gitlab.torproject.org/tpo/core/tor/-/blob/main/doc/man/tor.1.txt?ref_type=heads#L1475) and now also by [bitcoind](a85e5a7c9a/doc/release-notes-27375.md?plain=1#L5) so we need to switch that internally.
As far as I can tell, [LND](d20a764486/zmq.go (L38)) supports `ipc://` and `unix://` (notice the double slashes).
With this patch, LND can connect to bitcoind using unix sockets:
Example:
*bitcoin.conf*:
```
zmqpubrawblock=unix:/tmp/zmqsb
zmqpubrawtx=unix:/tmp/zmqst
```
*lnd.conf*:
```
bitcoind.zmqpubrawblock=ipc:///tmp/zmqsb
bitcoind.zmqpubrawtx=ipc:///tmp/zmqst
```
ACKs for top commit:
laanwj:
Code review ACK 21d0e6c7b7
tdb3:
crACK for 21d0e6c7b7. Changes lgtm. Will follow up with some testing within the next few days as time allows.
achow101:
ACK 21d0e6c7b7
guggero:
Tested and code review ACK 21d0e6c7b7
Tree-SHA512: ffd50222e80dd029d903e5ddde37b83f72dfec1856a3f7ce49da3b54a45de8daaf80eea1629a30f58559f4b8ded0b29809548c0638cd1c2811b2736ad8b73030
60ca5d5508 test: p2p: add test for rejected tx request logic (`m_recent_rejects` filter) (Sebastian Falbesoner)
e9dc511a7e fixup: get all utxos up front in fill_mempool, discourage wallet mixing (glozow)
Pull request description:
Motivated by the discussion in #28970 (https://github.com/bitcoin/bitcoin/pull/28970#discussion_r1553911167), this PR adds test coverage for the logic around the `m_recent_rejects` filter, in particular that the filter is cleared after a new block comes in:
f0794cbd40/src/net_processing.cpp (L2199-L2206)
As expected, the second part of the test fails if the following patch is applied:
```diff
diff --git a/src/net_processing.cpp b/src/net_processing.cpp
index 6996af38cb..5cb1090e70 100644
--- a/src/net_processing.cpp
+++ b/src/net_processing.cpp
@@ -2202,7 +2202,7 @@ bool PeerManagerImpl::AlreadyHaveTx(const GenTxid& gtxid)
// or a double-spend. Reset the rejects filter and give those
// txs a second chance.
hashRecentRejectsChainTip = m_chainman.ActiveChain().Tip()->GetBlockHash();
- m_recent_rejects.reset();
+ //m_recent_rejects.reset();
}
const uint256& hash = gtxid.GetHash();
```
I'm still not sure in which file this test fits best, and if there is already test coverage for the first part of the test somewhere. Happy for any suggestions.
ACKs for top commit:
maflcko:
ACK 60ca5d5508🍳
glozow:
code review ACK 60ca5d5508
instagibbs:
ACK 60ca5d5508
Tree-SHA512: 9cab43858e8f84db04a708151e6775c9cfc68c20ff53096220eac0b2c406f31aaf9223e8e04be345e95bf0a3f6dd15efac50b0ebeb1582a48a4560b3ab0bcba5
If we reuse the same port when disconnecting and establishing connections
again, we might hit this scenario:
- disconnection is done on python side for P2PConnection
- disconnection is not complete on c++ side for TestNode
- we're trying to establish a new connection on same port again
Prevent this scenario from happening by ensuring disconnection on c++
side for TestNode as well.
1ae5b208d3 test: fix intermittent failure in p2p_compactblocks_hb.py (Martin Zumsande)
Pull request description:
Fixes#29860
As a result of node1 receiving a block, it sends out SENDCMPCT messages to some of its peers to update the high-bandwidth status. We need to wait until those are received and processed by the peers to avoid intermittent failures. Before, we'd only wait until all peers have synced with the new block (within `generate`) which is not sufficient.
I could reproduce the failure by adding a `std::this_thread::sleep_for(std::chrono::milliseconds(1000));` sleep to the [net_processing code](c7567d9223/src/net_processing.cpp (L3763)) that processes `NetMsgType::SENDCMPCT`.
ACKs for top commit:
instagibbs:
ACK 1ae5b208d3
alfonsoromanz:
Tested ACK 1ae5b208d3
glozow:
ACK 1ae5b208d3
Tree-SHA512: 47c29616e73a5e0ff966fc231e4f672c1a6892511e5c10a3905b30ad6b2a3d1267fa0a88bd8f64b523fe580199d22a43545c84e361879e5096483152065c4b9a
b7ba60f81a test: add coverage for -reindex and assumeutxo (Martin Zumsande)
e57f951805 init, validation: Fix -reindex option with an existing snapshot (Martin Zumsande)
Pull request description:
In c711ca186f logic was introduced that `-reindex` and `-reindex-chainstate` will delete the snapshot chainstate.
This doesn't work currently, instead of deleting the snapshot chainstate the node crashes with an assert (this can be triggered by applying the added test commit on master).
Fix this, and another bug that would prevent the new active chainstate from having a mempool after `-reindex` has deleted the snapshot (also covered by the test).
ACKs for top commit:
fjahr:
re-ACK b7ba60f81a
hernanmarino:
crACK b7ba60f81a . Good fix
BrandonOdiwuor:
re-ACK b7ba60f81a
byaye:
Tested ACK b7ba60f81a
Tree-SHA512: c168f36997d7677d590af37b10427870f5d30123abf1c76032a16661e486735373bfa7e049e6aca439526fbcb6d619f970bf9d042196c851bf058a75a32fafdc
As a result of node1 receiving a block, it sends out
SENDCMPCT messages to its peers to update the status.
We need to wait until those are received and
processed by the peers to avoid intermittent failures.
Both RPC and GUI now render a useful error message instead of (silently) failing.
Replace bool with util::Result<void> to clarify that this either succeeds or returns an error message.
c2e0489b71 [rpc, bugfix] Enforce maximum value for setmocktime (dergoegge)
Pull request description:
The maximum value for our mocktime must be representable in nanoseconds, otherwise we end up with negative values returned from `NodeClock::now()`.
Found through fuzzing:
```
$ echo "c2V0bW9ja3RpbWVcZTptYf9w/3NldG3///////////////9p////ZP///ymL//////89////Nv9L////////LXkBAABpAA==" | base64 --decode > rpc-8cab9148ab4418ebd1923c213e9d3fe9c9b49b39.crash
$ FUZZ=rpc ./src/test/fuzz/fuzz rpc-8cab9148ab4418ebd1923c213e9d3fe9c9b49b39.crash
fuzz_libfuzzer: util/time.cpp:28: static NodeClock::time_point NodeClock::now(): Assertion `ret > 0s' failed.
```
ACKs for top commit:
maflcko:
re-ACK c2e0489b71
brunoerg:
crACK c2e0489b71
glozow:
ACK c2e0489b71
Tree-SHA512: d7e237ca37bedd74a6b085fb6e726a142705371044c77488f593f35afe70aeca756fdba86920294b1d322c7a9b2cde9ce4e1b7d410a6ccc1fd7c6f3a6e77200a
4ba1d0b553 fuzz: Add coverage for client_maxfeerate (Greg Sanders)
91d7d8f22a AcceptMultipleTransactions: Fix workspace client_maxfeerate (Greg Sanders)
f3aa5bd5eb fill_mempool: assertions and docsctring update (Greg Sanders)
a3da63e8fe Move fill_mempool to util function (Greg Sanders)
73b68bd8b4 fill_mempool: remove subtest-specific comment (Greg Sanders)
Pull request description:
Bug causes an `Assume()` failure due to the expectation that the individual result should be invalid when done over `submitpackage` via rpc.
Bug introduced by https://github.com/bitcoin/bitcoin/pull/28950 , and I discovered it rebasing https://github.com/bitcoin/bitcoin/pull/28984 since it's easier to hit in that test scenario.
Tests in place were only checking `AcceptSingleTransaction`-level checks due to package evaluation only triggering when minfee is too high for the parent transaction.
Added test along with fix, moving the fill_mempool utility into a common area for re-use.
ACKs for top commit:
glozow:
reACK 4ba1d0b553
theStack:
ACK 4ba1d0b553
ismaelsadeeq:
re-ACK 4ba1d0b553 via [diff](4fe7d150eb..4ba1d0b553)
Tree-SHA512: 3729bdf7f25d04e232f173ccee04ddbb2afdaafa3d04292a01cecf58fb11b3b2bc133e8490277f1a67622b62d17929c242dc980f9bb647896beea4332ee35306
d5a715536e build: remove boost::process dependency for building external signer support (Sebastian Falbesoner)
70434b1c44 external_signer: replace boost::process with cpp-subprocess (Sebastian Falbesoner)
cc8b9875b1 Add `cpp-subprocess` header-only library (Hennadii Stepanov)
Pull request description:
Closes https://github.com/bitcoin/bitcoin/issues/24907.
This PR is based on **theStack**'s [work](https://github.com/bitcoin/bitcoin/issues/24907#issuecomment-1466087049).
The `subprocess.hpp` header has been sourced from the [upstream repo](https://github.com/arun11299/cpp-subprocess) with the only modification being the removal of convenience functions, which are not utilized in our codebase.
Windows-related changes will be addressed in subsequent follow-ups.
ACKs for top commit:
achow101:
reACK d5a715536e
Sjors:
re-tACK d5a715536e
theStack:
Light re-ACK d5a715536e
fanquake:
ACK d5a715536e - with the expectation that this code is going to be maintained as our own. Next PRs should:
Tree-SHA512: d7fb6fecc3f5792496204190afb7d85b3e207b858fb1a75efe483c05260843b81b27d14b299323bb667c990e87a07197059afea3796cf218ed8b614086bd3611
47cedee776 fuzz: Introduce `BITCOINFUZZ` environment variable (Hennadii Stepanov)
1573e9a11e fuzz, refactor: Deduplicate fuzz binary path creation (Hennadii Stepanov)
Pull request description:
These changes are split from https://github.com/bitcoin/bitcoin/pull/29774 and can be beneficial on their own.
The new `BITCOINFUZZ` environment variable complements the already existing set of variables used by tests: b5d21182e5/test/functional/test_framework/test_framework.py (L238-L243)
ACKs for top commit:
maflcko:
lgtm ACK 47cedee776
davidgumberg:
utACK 47cedee776
Tree-SHA512: 45809cfd13dc4a45c44cc433184352e84726cb95bea80fd8f581c59a0b8b0a5495260ff66922f9c57c38adbdbdd102439238f370fd49d6ea27a241a5e6249895
d4e36ae80d test: Update --tmpdir doc string to say directory must not exist (kevkevin)
Pull request description:
The error message given if passing an existing dir to --tmpdir is confusing so this makes it clear that the directory must not already exist
This change is motivated by this comment https://github.com/bitcoin/bitcoin/pull/29335#issuecomment-1960913020
ACKs for top commit:
maflcko:
lgtm ACK d4e36ae80d
davidgumberg:
ACK d4e36ae80d
Tree-SHA512: fb31fd079767abbf94076615817943f35f5c9262fc97e65c631a18d33b3a343fe6a2d151613256e632d2b372ab2de0435f4712309b4a77ed3c663fd93a7dcdd1
93fae5ae7c test: remove immediate tx relay workaround in wallet_groups.py (Sebastian Falbesoner)
Pull request description:
Reverts commit ab4efad51b (PR #26970). This workaround is not needed anymore, as since #27114 the test sets the noban permission for both in- and outbound connections via the `noban_tx_relay` setting, and we don't have to rely on this topology hack anymore. See commit c985eb854c (kudos to brunoerg!).
Can be tested by executing `$ time ./test/functional/wallet_groups.py` both on master and PR and verifying that the execution time is roughly equal.
ACKs for top commit:
maflcko:
lgtm ACK 93fae5ae7c
brunoerg:
utACK 93fae5ae7c
Tree-SHA512: b949fd05b4308815ba02d0ee4d1318f642b930288dd03223f46db7db745177af1c070bc7058743ac27963c5ad90564089867cc12f31fee94812a16919c353bab
49c0b8b228 test: Bump timeouts in feature_index_prune and wallet_importdescriptors (Christopher Bergqvist)
Pull request description:
Timeout issues where encountered when running functional tests with `--jobs=16 --extended`.
Note that running `--extended` without `--jobs=16` does not trigger the issues.
Tested under NixOS on a Xeon CPU with 16 logical cores.
(A few tests are skipped locally as I haven't enabled BPF and a few other things).
## Measurements
Line in `feature_index_prune.py` took 101.6s, 96.6s, 103.0s across 3 runs on my machine.
Default limit is 60, suggested to increase limit to 150 seconds.
Line in the `wallet_importdescriptors.py --descriptors` took 5.4s, 5.7s, 6.0s across 3 runs.
Suggested to increase from 5 to 10 seconds.
## Logs
Output slightly modified by separate change that lets code run past given timeouts and the provides more information - "Took 101.6 seconds to complete, 69.4% over the given limit.".
<details>
<summary>
Click to expand.
</summary>
### feature_index_prune.py
```
52/305 - feature_index_prune.py failed, Duration: 250 s
stdout:
2024-04-01T22:25:24.010000Z TestFramework (INFO): PRNG seed is: 990421162716295219
2024-04-01T22:25:24.014000Z TestFramework (INFO): Initializing test directory /mnt/tmp/test_runner_₿_🏃_20240402_002516/feature_index_prune_302
2024-04-01T22:25:24.913000Z TestFramework (INFO): check if we can access blockfilters and coinstats when pruning is enabled but no blocks are actually pruned
2024-04-01T22:26:48.417000Z TestFramework (INFO): prune some blocks
2024-04-01T22:26:48.460000Z TestFramework (INFO): check if we can access the tips blockfilter and coinstats when we have pruned some blocks
2024-04-01T22:26:48.483000Z TestFramework (INFO): check if we can access the blockfilter and coinstats of a pruned block
2024-04-01T22:26:59.175000Z TestFramework (INFO): make sure trying to access the indices throws errors
2024-04-01T22:27:50.422000Z TestFramework (INFO): prune exactly up to the indices best blocks while the indices are disabled
2024-04-01T22:27:52.596000Z TestFramework (INFO): make sure that we can continue with the partially synced indices after having pruned up to the index height
2024-04-01T22:29:34.242000Z TestFramework.utils (ERROR): wait_until() failed. Predicate: '''
self.wait_until(lambda: self.nodes[1].getindexinfo() == expected_stats)#, timeout=150)
'''
2024-04-01T22:29:34.244000Z TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
File "/home/chris/Documents/Code/bitcoin-core/test/functional/test_framework/test_framework.py", line 132, in main
self.run_test()
File "/home/chris/Documents/Code/bitcoin-core/test/functional/feature_index_prune.py", line 117, in run_test
self.sync_index(height=1500)
File "/home/chris/Documents/Code/bitcoin-core/test/functional/feature_index_prune.py", line 34, in sync_index
self.wait_until(lambda: self.nodes[1].getindexinfo() == expected_stats)#, timeout=150)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/chris/Documents/Code/bitcoin-core/test/functional/test_framework/test_framework.py", line 780, in wait_until
return wait_until_helper_internal(test_function, timeout=timeout, timeout_factor=self.options.timeout_factor)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/chris/Documents/Code/bitcoin-core/test/functional/test_framework/util.py", line 305, in wait_until_helper_internal
raise AssertionError(m)
AssertionError: Predicate '''
self.wait_until(lambda: self.nodes[1].getindexinfo() == expected_stats)#, timeout=150)
''' not true after 60 seconds. Took 101.6 seconds to complete, 69.4% over the given limit.
2024-04-01T22:29:34.298000Z TestFramework (INFO): Stopping nodes
2024-04-01T22:29:34.511000Z TestFramework (WARNING): Not cleaning up dir /mnt/tmp/test_runner_₿_🏃_20240402_002516/feature_index_prune_302
2024-04-01T22:29:34.511000Z TestFramework (ERROR): Test failed. Test logging available at /mnt/tmp/test_runner_₿_🏃_20240402_002516/feature_index_prune_302/test_framework.log
2024-04-01T22:29:34.511000Z TestFramework (ERROR):
2024-04-01T22:29:34.512000Z TestFramework (ERROR): Hint: Call /home/chris/Documents/Code/bitcoin-core/test/functional/combine_logs.py '/mnt/tmp/test_runner_₿_🏃_20240402_002516/feature_index_prune_302' to consolidate all logs
2024-04-01T22:29:34.512000Z TestFramework (ERROR):
2024-04-01T22:29:34.512000Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log.
2024-04-01T22:29:34.512000Z TestFramework (ERROR): https://github.com/bitcoin/bitcoin/issues
2024-04-01T22:29:34.512000Z TestFramework (ERROR):
stderr:
53/305 - p2p_blockfilters.py passed, Duration: 130 s
```
### wallet_importdescriptors.py --descriptors
```
297/305 - wallet_importdescriptors.py --descriptors failed, Duration: 76 s
stdout:
2024-04-01T22:48:27.663000Z TestFramework (INFO): PRNG seed is: 8528678505617325332
2024-04-01T22:48:27.664000Z TestFramework (INFO): Initializing test directory /mnt/tmp/test_runner_₿_🏃_20240402_004231/wallet_importdescriptors_98
2024-04-01T22:48:28.021000Z TestFramework (INFO): Setting up wallets
2024-04-01T22:48:28.100000Z TestFramework (INFO): Mining coins
2024-04-01T22:48:29.714000Z TestFramework (INFO): Import should fail if a descriptor is not provided
2024-04-01T22:48:29.725000Z TestFramework (INFO): Should import a p2pkh descriptor
2024-04-01T22:48:29.740000Z TestFramework (INFO): Test can import same descriptor with public key twice
2024-04-01T22:48:29.760000Z TestFramework (INFO): Test can update descriptor label
2024-04-01T22:48:29.785000Z TestFramework (INFO): Internal addresses cannot have labels
2024-04-01T22:48:29.788000Z TestFramework (INFO): Internal addresses should be detected as such
2024-04-01T22:48:29.854000Z TestFramework (INFO): Should not import a p2sh-p2wpkh descriptor without checksum
2024-04-01T22:48:29.855000Z TestFramework (INFO): Should not import a p2sh-p2wpkh descriptor that has range specified
2024-04-01T22:48:29.858000Z TestFramework (INFO): Should not import a p2sh-p2wpkh descriptor and have it set to active
2024-04-01T22:48:29.860000Z TestFramework (INFO): Should import a (non-active) p2sh-p2wpkh descriptor
2024-04-01T22:48:29.984000Z TestFramework (INFO): Should import a 1-of-2 bare multisig from descriptor
2024-04-01T22:48:30.002000Z TestFramework (INFO): Should not treat individual keys from the imported bare multisig as watchonly
2024-04-01T22:48:30.005000Z TestFramework (INFO): Ranged descriptors cannot have labels
2024-04-01T22:48:30.014000Z TestFramework (INFO): Private keys required for private keys enabled wallet
2024-04-01T22:48:30.027000Z TestFramework (INFO): Ranged descriptor import should warn without a specified range
2024-04-01T22:48:30.065000Z TestFramework (INFO): Should not import a ranged descriptor that includes xpriv into a watch-only wallet
2024-04-01T22:48:30.070000Z TestFramework (INFO): Should not import a descriptor with hardened derivations when private keys are disabled
2024-04-01T22:48:30.108000Z TestFramework (INFO): Verify we can only extend descriptor's range
2024-04-01T22:48:30.364000Z TestFramework (INFO): Check we can change descriptor internal flag
2024-04-01T22:48:30.536000Z TestFramework (INFO): Key ranges should be imported in order
2024-04-01T22:48:30.708000Z TestFramework (INFO): Check we can change next_index
2024-04-01T22:48:30.838000Z TestFramework (INFO): Check imported descriptors are not active by default
2024-04-01T22:48:30.870000Z TestFramework (INFO): Check can activate inactive descriptor
2024-04-01T22:48:30.903000Z TestFramework (INFO): Check can deactivate active descriptor
2024-04-01T22:48:30.924000Z TestFramework (INFO): Verify activation state is persistent
2024-04-01T22:48:30.973000Z TestFramework (INFO): Should import a descriptor with a WIF private key as spendable
2024-04-01T22:48:30.987000Z TestFramework (INFO): Test can import same descriptor with private key twice
2024-04-01T22:48:32.173000Z TestFramework (INFO): Test that multisigs can be imported, signed for, and getnewaddress'd
2024-04-01T22:48:43.803000Z TestFramework (INFO): Multisig with distributed keys
2024-04-01T22:48:48.895000Z TestFramework (INFO): We can create and use a huge multisig under P2WSH
2024-04-01T22:49:05.628000Z TestFramework (INFO): Under P2SH, multisig are standard with up to 15 compressed keys
2024-04-01T22:49:20.258000Z TestFramework (INFO): Amending multisig with new private keys
2024-04-01T22:49:23.306000Z TestFramework (INFO): Combo descriptors cannot be active
2024-04-01T22:49:23.313000Z TestFramework (INFO): Descriptors with no type cannot be active
2024-04-01T22:49:23.348000Z TestFramework (INFO): Test importing a descriptor to an encrypted wallet
2024-04-01T22:49:43.957000Z TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
File "/home/chris/Documents/Code/bitcoin-core/test/functional/test_framework/test_framework.py", line 132, in main
self.run_test()
File "/home/chris/Documents/Code/bitcoin-core/test/functional/wallet_importdescriptors.py", line 691, in run_test
with self.nodes[0].assert_debug_log(expected_msgs=["Rescan started from block 0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206... (slow variant inspecting all blocks)"], timeout=5):#10):
File "/nix/store/rac8pxbi1vapwrlqzbrkycbyg521djzw-python3-3.11.6/lib/python3.11/contextlib.py", line 144, in __exit__
next(self.gen)
File "/home/chris/Documents/Code/bitcoin-core/test/functional/test_framework/test_node.py", line 493, in assert_debug_log
self._raise_assertion_error(f'Expected messages "{expected_msgs}" found too late, took {now - start:.1f} seconds, {((now - start) / (time_end - start)) - 1:.1%} over the given limit. Log:\n\n{print_log}\n\n')
File "/home/chris/Documents/Code/bitcoin-core/test/functional/test_framework/test_node.py", line 188, in _raise_assertion_error
raise AssertionError(self._node_msg(msg))
AssertionError: [node 0] Expected messages "['Rescan started from block 0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206... (slow variant inspecting all blocks)']" found too late, took 5.4 seconds, 8.9% over the given limit. Log:
- 2024-04-01T22:49:33.066512Z [http] [httpserver.cpp:306] [http_request_cb] [http] Received a POST request for /wallet/encrypted_wallet from 127.0.0.1:47658
- 2024-04-01T22:49:33.066668Z [httpworker.0] [rpc/request.cpp:187] [parse] [rpc] ThreadRPCServer method=importdescriptors user=__cookie__
- 2024-04-01T22:49:33.070999Z [httpworker.0] [wallet/sqlite.cpp:57] [TraceSqlCallback] [/mnt/tmp/test_runner_₿_🏃_20240402_004231/wallet_importdescriptors_98/node0/regtest/wallets/encrypted_wallet/wallet.dat] SQLite Statement: INSERT INTO main VALUES(?, ?)
- 2024-04-01T22:49:33.071061Z [httpworker.0] [wallet/sqlite.cpp:57] [TraceSqlCallback] [/mnt/tmp/test_runner_₿_🏃_20240402_004231/wallet_importdescriptors_98/node0/regtest/wallets/encrypted_wallet/wallet.dat] SQLite Statement: DELETE FROM main WHERE key = ?
- 2024-04-01T22:49:33.071137Z [httpworker.0] [wallet/sqlite.cpp:57] [TraceSqlCallback] [/mnt/tmp/test_runner_₿_🏃_20240402_004231/wallet_importdescriptors_98/node0/regtest/wallets/encrypted_wallet/wallet.dat] SQLite Statement: BEGIN TRANSACTION
- 2024-04-01T22:49:33.074190Z [httpworker.0] [wallet/sqlite.cpp:57] [TraceSqlCallback] [/mnt/tmp/test_runner_₿_🏃_20240402_004231/wallet_importdescriptors_98/node0/regtest/wallets/encrypted_wallet/wallet.dat] SQLite Statement: INSERT or REPLACE into main values(?, ?)
- 2024-04-01T22:49:33.075564Z [httpworker.0] [wallet/sqlite.cpp:57] [TraceSqlCallback] [/mnt/tmp/test_runner_₿_🏃_20240402_004231/wallet_importdescriptors_98/node0/regtest/wallets/encrypted_wallet/wallet.dat] SQLite Statement: INSERT or REPLACE into main values(?, ?)
...<thousands of almost identical lines>...
- 2024-04-01T22:49:38.416139Z [httpworker.0] [wallet/sqlite.cpp:57] [TraceSqlCallback] [/mnt/tmp/test_runner_₿_🏃_20240402_004231/wallet_importdescriptors_98/node0/regtest/wallets/encrypted_wallet/wallet.dat] SQLite Statement: INSERT or REPLACE into main values(?, ?)
- 2024-04-01T22:49:38.416528Z [httpworker.0] [wallet/sqlite.cpp:57] [TraceSqlCallback] [/mnt/tmp/test_runner_₿_🏃_20240402_004231/wallet_importdescriptors_98/node0/regtest/wallets/encrypted_wallet/wallet.dat] SQLite Statement: INSERT or REPLACE into main values(?, ?)
- 2024-04-01T22:49:38.427946Z [httpworker.0] [wallet/sqlite.cpp:57] [TraceSqlCallback] [/mnt/tmp/test_runner_₿_🏃_20240402_004231/wallet_importdescriptors_98/node0/regtest/wallets/encrypted_wallet/wallet.dat] SQLite Statement: COMMIT TRANSACTION
- 2024-04-01T22:49:38.429778Z [httpworker.0] [wallet/sqlite.cpp:57] [TraceSqlCallback] [/mnt/tmp/test_runner_₿_🏃_20240402_004231/wallet_importdescriptors_98/node0/regtest/wallets/encrypted_wallet/wallet.dat] SQLite Statement: INSERT or REPLACE into main values(?, ?)
- 2024-04-01T22:49:38.429916Z [httpworker.0] [wallet/sqlite.cpp:57] [TraceSqlCallback] [/mnt/tmp/test_runner_₿_🏃_20240402_004231/wallet_importdescriptors_98/node0/regtest/wallets/encrypted_wallet/wallet.dat] SQLite Statement: INSERT or REPLACE into main values(?, ?)
- 2024-04-01T22:49:38.430001Z [httpworker.0] [wallet/wallet.h:933] [WalletLogPrintf] [encrypted_wallet] Setting spkMan to active: id = c6149b35399517457b0b1d8ccdd7efda25a2f20fc7f8167adda8e79b10e260b7, type = legacy, internal = false
- 2024-04-01T22:49:38.430134Z [httpworker.0] [wallet/wallet.h:933] [WalletLogPrintf] [encrypted_wallet] RescanFromTime: Rescanning last 329 blocks
- 2024-04-01T22:49:38.430170Z [httpworker.0] [wallet/wallet.h:933] [WalletLogPrintf] [encrypted_wallet] Rescan started from block 0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206... (slow variant inspecting all blocks)
- 2024-04-01T22:49:38.441914Z [httpworker.0] [wallet/scriptpubkeyman.h:258] [WalletLogPrintf] [encrypted_wallet] MarkUnusedAddresses: Detected a used keypool item at index 4000, mark all keypool items up to this item as used
2024-04-01T22:49:44.029000Z TestFramework (INFO): Stopping nodes
2024-04-01T22:49:44.132000Z TestFramework (WARNING): Not cleaning up dir /mnt/tmp/test_runner_₿_🏃_20240402_004231/wallet_importdescriptors_98
2024-04-01T22:49:44.132000Z TestFramework (ERROR): Test failed. Test logging available at /mnt/tmp/test_runner_₿_🏃_20240402_004231/wallet_importdescriptors_98/test_framework.log
2024-04-01T22:49:44.132000Z TestFramework (ERROR):
2024-04-01T22:49:44.133000Z TestFramework (ERROR): Hint: Call /home/chris/Documents/Code/bitcoin-core/test/functional/combine_logs.py '/mnt/tmp/test_runner_₿_🏃_20240402_004231/wallet_importdescriptors_98' to consolidate all logs
2024-04-01T22:49:44.133000Z TestFramework (ERROR):
2024-04-01T22:49:44.133000Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log.
2024-04-01T22:49:44.133000Z TestFramework (ERROR): https://github.com/bitcoin/bitcoin/issues
2024-04-01T22:49:44.133000Z TestFramework (ERROR):
stderr:
Remaining jobs: [feature_pruning.py, feature_dbcrash.py, feature_assumeutxo.py, rpc_scantxoutset.py, feature_coinstatsindex.py, p2p_node_network_limited.py --v1transport, p2p_node_network_limited.py --v2transport, feature_config_args.py]
298/305 - p2p_node_network_limited.py --v1transport passed, Duration: 24 s
```
</details>
## Related
Almost identical timeout in `feature_index_prune.py` in #27091 on MacOS, and for `wallet_importdescriptors.py --descriptors` in #27282 on Alpine & CI.
ACKs for top commit:
maflcko:
lgtm ACK 49c0b8b228
tdb3:
ACK for 49c0b8b228
itornaza:
approach ACK 49c0b8b228
BrandonOdiwuor:
crACK 49c0b8b228
Tree-SHA512: f62ade74701588d76bfe838b7e7bbda1db38fd98688fd5d13c2c008064027add2ee9d053dee602d84919fab4c9bf53183c31819d94a6174066f237d0f6a62086
Reverts commit ab4efad51b (PR #26970).
This workaround is not needed anymore, as since #27114 the test sets
the noban permission for both in- and outbound connections via the
`noban_tx_relay` setting, and we don't have to rely on these topology
hacks anymore. See commit c985eb854c.
The `BITCOINFUZZ` environment variable allows to override the default
path to the fuzz binary.
It complements the already existing set of variables used by tests:
- BITCOIND
- BITCOINCLI
- BITCOINUTIL
- BITCOINWALLET
Rather than manually estimating an input's weight by adding up all the
involved components (fixed-size skeleton, compact-serialized lengths,
and the actual scriptSig / witness stack items) we can simply take use
of the serialization classes `CTxIn` / `CTxInWitness` instead, to
achieve the same with significantly less code.
The new helper is used in the functional tests rpc_psbt.py and
wallet_send.py, where the previous manual estimation code was
duplicated.
Previously, `wait_for_getheaders` would check whether a node had received **any**
getheaders message. This implied that, if a test needed to check for a specific block
hash within a headers message, it had to make sure that it was checking the desired message.
This normally involved having to manually clear `last_message`. This method, apart from being
too verbose, was error prone, given an undesired `getheaders` would make tests pass.
This adds the ability to check for a specific block_hash within the last `getheaders` message.
merge-script