Tests: speed up fundrawtransaction test #17340

jnewbery · 2019-11-01T14:27:33Z

Speed up rpc_fundrawtransaction.py

Most of the time in rpc_fundrawtransaction.py is spent waiting for
unconfirmed transactions to propagate. Net processing adds a poisson
random delay to the time it will INV transactions with a mean interval
of 5 seconds. Calls like the following:

self.nodes[2].sendrawtransaction(signedTx['hex'])
self.sync_all()
self.nodes[1].generate(1)

will therefore introduce a delay waiting for the mempools to sync.
Instead just generate the block on the node that sent the transaction:

self.nodes[2].sendrawtransaction(signedTx['hex'])
self.nodes[2].generate(1)

rpc_fundrawtransaction.py is not intended to be a test for transaction
relay, so it's ok to do this.

jnewbery · 2019-11-01T14:28:13Z

h/t to @jonatack for adding logging in #17327. It wouldn't have been obvious where the delays were being introduced without that PR.

jnewbery · 2019-11-01T14:29:49Z

Sample run before this PR:

 ./rpc_fundrawtransaction.py 
2019-11-01T14:11:43.898000Z TestFramework (INFO): Initializing test directory /tmp/user/1000/bitcoin_func_test__37epvjg
2019-11-01T14:11:45.270000Z TestFramework (INFO): Connect nodes, set fees, generate blocks, and sync
...
2019-11-01T14:12:41.473000Z TestFramework (INFO): Tests successful

(58 seconds)

after:

→ ./rpc_fundrawtransaction.py 
2019-11-01T14:20:14.757000Z TestFramework (INFO): Initializing test directory /tmp/user/1000/bitcoin_func_test_sel5qr1p
2019-11-01T14:20:15.609000Z TestFramework (INFO): Connect nodes, set fees, generate blocks, and sync
...
2019-11-01T14:20:27.072000Z TestFramework (INFO): Tests successful

(12 seconds)

jonatack

Run times in seconds for me:

ff22751: 62, 61, 52, 56, 61, 64

a8f7497a2335842dd357fa16ce1b38962a718b2a: 20, 22, 21, 21, 20, 22

promag · 2019-11-01T15:55:19Z

rpc_fundrawtransaction.py is not intended to be a test for transaction
relay

Concept ACK, nice speedup!

jonatack · 2019-11-01T16:50:02Z

In test_runner.py::BASE_SCRIPTS, rpc_fundrawtransaction.py could be moved down 3 groups to the upper part of Tests less than 30s.

achow101 · 2019-11-01T16:53:57Z

Are there other tests where we could make a similar improvement?

jnewbery · 2019-11-01T16:58:36Z

Are there other tests where we could make a similar improvement?

Yes. Anything that is sped up by #15881 could be individually sped up by changing how txs are relayed in that test. Alternatively, running the tests under a python profiler and checking which ones spend a lot of time in sync_mempools would show places that could be optimized.

maflcko · 2019-11-01T17:02:21Z

If you decide to re-sort the tests, could also include the ones that have been made faster here: #16613 (comment)

jnewbery · 2019-11-01T21:40:07Z

Made it faster

jnewbery · 2019-11-01T21:40:43Z

If you decide to re-sort the tests, could also include the ones that have been made faster here: #16613 (comment)

I think that could be done separately

maflcko · 2019-11-01T21:44:05Z

Rebase or force push to work around the GitHub bug?

jnewbery · 2019-11-01T21:45:27Z

Rebase or force push to work around the GitHub bug?

Done. Thanks!

jonatack · 2019-11-04T08:02:03Z

Run times in seconds for me:

ff22751: 62, 61, 52, 56, 61, 64

a8f7497: 20, 22, 21, 21, 20, 22

2919ad318a723c7b90147298d93dd95458c7715f: 20, 21, 22, 24, 21, 21 -> I'm not seeing improvement over a8f7497a2335842dd357fa16ce1b38962a718b2a

jonatack · 2019-11-04T09:49:17Z

test/functional/rpc_fundrawtransaction.py

s/127.0.01/127.0.0.1/ ?

Credit to @practicalswift who caught it in my PR ;)

Maybe also make it more specific: [email protected].

~~You could also add -whitebind to cover both inbound and outbound, however for some reason this requires you to specify a port, so you'd have to tweak the test suite for that.~~

Afaik whitelist only works for inbound connections. Not sure if that matters here.

Fixed. Thanks!

Sjors

ACK 2919ad3 modulo IP typo (I ran with that corrected).

Tested on macOS 10.15 with --enable-debug. Before: 72 seconds. After: 38 seconds.

Sjors · 2019-11-04T17:28:40Z

test/functional/rpc_fundrawtransaction.py

Maybe also make it more specific: [email protected].

~~You could also add -whitebind to cover both inbound and outbound, however for some reason this requires you to specify a port, so you'd have to tweak the test suite for that.~~

Afaik whitelist only works for inbound connections. Not sure if that matters here.

Most of the time in rpc_fundrawtransaction.py is spent waiting for unconfirmed transactions to propagate. Net processing adds a poisson random delay to the time it will INV transactions with a mean interval of 5 seconds. Calls like the following: ``` self.nodes[2].sendrawtransaction(signedTx['hex']) self.sync_all() self.nodes[1].generate(1) ```` will therefore introduce a delay waiting for the mempools to sync. Instead just generate the block on the node that sent the transaction: ``` self.nodes[2].sendrawtransaction(signedTx['hex']) self.nodes[2].generate(1) ``` rpc_fundrawtransaction.py is not intended to be a test for transaction relay, so it's ok to do this.

jnewbery · 2019-11-04T18:41:12Z

I'm not seeing improvement over a8f7497

I see at least a second saved on average from not having to stop-start the nodes. I think not stop-starting when unnecessary makes a cleaner test in any case.

jonatack

ACK ae6fd926d0b49f69dec4b63e0d5cc2a639408892 happy to re-ACK for the simple change below

jonatack · 2019-11-06T10:43:08Z

test/functional/rpc_fundrawtransaction.py

Could do

def set_test_params(self): - self.num_nodes = 4 + num_nodes = 4 + self.num_nodes = num_nodes self.setup_clean_chain = True # This test isn't testing tx relay. Set whitelist on the peers for # instant tx relay. - self.extra_args = [['-whitelist=127.0.0.1']] * 4 + self.extra_args = [['-whitelist=127.0.0.1']] * num_nodes

even better, just:

self.extra_args = [['-whitelist=127.0.0.1']] * self.num_nodes

which I've now done.

Yes, even better; doing the same in wallet_avoidreuse.py

Makes tx relay faster

This was only added in c1dde3a to match behaviour when `encryptwallet` would restart the node. It's not required for the test (and slows things down).

maflcko · 2019-11-06T20:16:05Z

ACK af7bae7 🛴

Show signature and timestamp

Signature:

Timestamp of file with hash 1ecd30be3396a80fa3c5142b61bd557f16f7db00e6f86414f9df50183d6462cf -

af7bae7 [tests] Don't stop-start unnecessarily in rpc_fundrawtransaction.py (John Newbery) 9a85052 [tests] Use -whitelist in rpc_fundrawtransaction.py (John Newbery) 646b593 [tests] Speed up rpc_fundrawtransaction.py (John Newbery) Pull request description: Speed up rpc_fundrawtransaction.py Most of the time in rpc_fundrawtransaction.py is spent waiting for unconfirmed transactions to propagate. Net processing adds a poisson random delay to the time it will INV transactions with a mean interval of 5 seconds. Calls like the following: ``` self.nodes[2].sendrawtransaction(signedTx['hex']) self.sync_all() self.nodes[1].generate(1) ```` will therefore introduce a delay waiting for the mempools to sync. Instead just generate the block on the node that sent the transaction: ``` self.nodes[2].sendrawtransaction(signedTx['hex']) self.nodes[2].generate(1) ``` rpc_fundrawtransaction.py is not intended to be a test for transaction relay, so it's ok to do this. ACKs for top commit: MarcoFalke: ACK af7bae7 🛴 Tree-SHA512: db3407d871bfdc99a02e7304b07239dd3585ac47f27f020f1a70608b7f6386b134343c01f3e4d1c246ce734676755897671999695068d6388602fb042d178780

promag · 2019-11-06T20:42:36Z

Here we go 🦉

af7bae7 [tests] Don't stop-start unnecessarily in rpc_fundrawtransaction.py (John Newbery) 9a85052 [tests] Use -whitelist in rpc_fundrawtransaction.py (John Newbery) 646b593 [tests] Speed up rpc_fundrawtransaction.py (John Newbery) Pull request description: Speed up rpc_fundrawtransaction.py Most of the time in rpc_fundrawtransaction.py is spent waiting for unconfirmed transactions to propagate. Net processing adds a poisson random delay to the time it will INV transactions with a mean interval of 5 seconds. Calls like the following: ``` self.nodes[2].sendrawtransaction(signedTx['hex']) self.sync_all() self.nodes[1].generate(1) ```` will therefore introduce a delay waiting for the mempools to sync. Instead just generate the block on the node that sent the transaction: ``` self.nodes[2].sendrawtransaction(signedTx['hex']) self.nodes[2].generate(1) ``` rpc_fundrawtransaction.py is not intended to be a test for transaction relay, so it's ok to do this. ACKs for top commit: MarcoFalke: ACK af7bae7 🛴 Tree-SHA512: db3407d871bfdc99a02e7304b07239dd3585ac47f27f020f1a70608b7f6386b134343c01f3e4d1c246ce734676755897671999695068d6388602fb042d178780

0e7c90e test: speed up wallet_avoidreuse.py (Jon Atack) 6d50b26 test: add logging to wallet_avoidreuse.py (Jon Atack) Pull request description: Inspired by PRs #17340 and #15881. - add logging - pass -whitelist in `set_test_params` to speed up transaction relay `wallet_avoidreuse.py` is not intended to test P2P transaction relay/timing, so it should be fine to do this here. This reduces test run time variability and speeds up the test by 2-3 times on average. Test run times in seconds: - before: 20, 24, 22, 17, 27, 40, 30 - after: 10, 10, 8, 9, 10, 7, 8 ACKs for top commit: MarcoFalke: ACK 0e7c90e 🐊 fanquake: ACK 0e7c90e Tree-SHA512: 6d954a0aaf402c9594201626b59d29263479059e68fa5155bb44ed973cd0c3347729dd78b78b4d5a2275e45da365dc1afb4cc7e3293dea33fcc2e3e83a39faf5

… speedup) 9e78943 test: speedup p2p_feefilter.py by whitelisting peers (immediate tx relay) (Sebastian Falbesoner) fe3f0cc test: use wait_until for invs matching in p2p_feefilter.py (Sebastian Falbesoner) 6d94192 test: add logging for p2p_feefilter.py (Sebastian Falbesoner) Pull request description: This PR gives some love to the functional test `p2p_feefilter.py` by introducing the following changes: * add missing log messages for the `test_feefilter` subtest (the main one) * deduplicate code by using the utility function `wait_until` (already using the [recently introduced version](12410b1)) instead of a manual condition checking loop with `time.sleep` * improve naming of the function `matchAllInvs` (more expressive name, snake_case) and moving it from global namespace to the connection class `FeefilterConn` * speeding up the test significantly by the good ol' method of activating immediate tx relay (as seen on e.g. #17121, #17124, #17340, #17362, ...): ``` master branch: $ time ./p2p_feefilter.py ... real 0m39.367s user 0m1.227s sys 0m0.571s PR branch: $ time ./p2p_feefilter.py ... real 0m9.386s user 0m1.120s sys 0m0.577s ``` ACKs for top commit: instagibbs: code review ACK 9e78943 jonatack: re-ACK 9e78943 per `git range-diff 3ab2582 ea74a3c 9e78943` Tree-SHA512: fe21c1c5413df9165fea916b5d5f609d3ba33e7b5c3364b38eb824fcc55d9e6abddf27116cbc0b325913d451a73c44542040fb916aec9c46f805c6e12f6f10cf

…toring, speedup) 9e78943 test: speedup p2p_feefilter.py by whitelisting peers (immediate tx relay) (Sebastian Falbesoner) fe3f0cc test: use wait_until for invs matching in p2p_feefilter.py (Sebastian Falbesoner) 6d94192 test: add logging for p2p_feefilter.py (Sebastian Falbesoner) Pull request description: This PR gives some love to the functional test `p2p_feefilter.py` by introducing the following changes: * add missing log messages for the `test_feefilter` subtest (the main one) * deduplicate code by using the utility function `wait_until` (already using the [recently introduced version](bitcoin@12410b1)) instead of a manual condition checking loop with `time.sleep` * improve naming of the function `matchAllInvs` (more expressive name, snake_case) and moving it from global namespace to the connection class `FeefilterConn` * speeding up the test significantly by the good ol' method of activating immediate tx relay (as seen on e.g. bitcoin#17121, bitcoin#17124, bitcoin#17340, bitcoin#17362, ...): ``` master branch: $ time ./p2p_feefilter.py ... real 0m39.367s user 0m1.227s sys 0m0.571s PR branch: $ time ./p2p_feefilter.py ... real 0m9.386s user 0m1.120s sys 0m0.577s ``` ACKs for top commit: instagibbs: code review ACK bitcoin@9e78943 jonatack: re-ACK 9e78943 per `git range-diff 3ab2582 ea74a3c 9e78943` Tree-SHA512: fe21c1c5413df9165fea916b5d5f609d3ba33e7b5c3364b38eb824fcc55d9e6abddf27116cbc0b325913d451a73c44542040fb916aec9c46f805c6e12f6f10cf

Summary: > [tests] Speed up rpc_fundrawtransaction.py > > Most of the time in rpc_fundrawtransaction.py is spent waiting for > unconfirmed transactions to propagate. Net processing adds a poisson > random delay to the time it will INV transactions with a mean interval > of 5 seconds. > > Instead just generate the block on the node that sent the transaction: > > rpc_fundrawtransaction.py is not intended to be a test for transaction > relay, so it's ok to do this. > [tests] Use -whitelist in rpc_fundrawtransaction.py > > Makes tx relay faster > [tests] Don't stop-start unnecessarily in rpc_fundrawtransaction.py > > This was only added in c1dde3a949b36ce9c2155777b3fa1372e7ed97d8 to match > behaviour when `encryptwallet` would restart the node. It's not required > for the test (and slows things down). This is a backport of Core [[bitcoin/bitcoin#17340 | PR17340]] Test Plan: ``` $ ninja && test/functional/test_runner.py rpc_fundrawtransaction ... rpc_fundrawtransaction.py passed, Duration: 86 s $ git cherry-pick 646b593bbd0db113c6e45ab92177b8f5251e8710 $ ninja && test/functional/test_runner.py rpc_fundrawtransaction ... rpc_fundrawtransaction.py passed, Duration: 64 s $ git cherry-pick 9a8505299ba392acbab4647963113b0c29495f1d $ ninja && test/functional/test_runner.py rpc_fundrawtransaction ... rpc_fundrawtransaction.py passed, Duration: 44 s $ git cherry-pick af7bae734089f6af0029b0887932ccd9a469e12e $ ninja && test/functional/test_runner.py rpc_fundrawtransaction ... rpc_fundrawtransaction.py passed, Duration: 42 s ``` Reviewers: O1 Bitcoin ABC, #bitcoin_abc, majcosta Reviewed By: O1 Bitcoin ABC, #bitcoin_abc, majcosta Differential Revision: https://reviews.bitcoinabc.org/D8260

af7bae7 [tests] Don't stop-start unnecessarily in rpc_fundrawtransaction.py (John Newbery) 9a85052 [tests] Use -whitelist in rpc_fundrawtransaction.py (John Newbery) 646b593 [tests] Speed up rpc_fundrawtransaction.py (John Newbery) Pull request description: Speed up rpc_fundrawtransaction.py Most of the time in rpc_fundrawtransaction.py is spent waiting for unconfirmed transactions to propagate. Net processing adds a poisson random delay to the time it will INV transactions with a mean interval of 5 seconds. Calls like the following: ``` self.nodes[2].sendrawtransaction(signedTx['hex']) self.sync_all() self.nodes[1].generate(1) ```` will therefore introduce a delay waiting for the mempools to sync. Instead just generate the block on the node that sent the transaction: ``` self.nodes[2].sendrawtransaction(signedTx['hex']) self.nodes[2].generate(1) ``` rpc_fundrawtransaction.py is not intended to be a test for transaction relay, so it's ok to do this. ACKs for top commit: MarcoFalke: ACK af7bae7 🛴 Tree-SHA512: db3407d871bfdc99a02e7304b07239dd3585ac47f27f020f1a70608b7f6386b134343c01f3e4d1c246ce734676755897671999695068d6388602fb042d178780

jonatack reviewed Nov 1, 2019

View reviewed changes

fanquake added the Tests label Nov 1, 2019

jnewbery force-pushed the 2019-11-speed-up-fundrawtransaction-test branch from 6f4705f to 2919ad3 Compare November 1, 2019 21:45

jonatack mentioned this pull request Nov 4, 2019

test: speed up wallet_avoidreuse, add logging #17362

Merged

jonatack reviewed Nov 4, 2019

View reviewed changes

Sjors approved these changes Nov 4, 2019

View reviewed changes

jnewbery force-pushed the 2019-11-speed-up-fundrawtransaction-test branch from 2919ad3 to ae6fd92 Compare November 4, 2019 18:39

jonatack reviewed Nov 6, 2019

View reviewed changes

jnewbery added 2 commits November 6, 2019 14:56

[tests] Use -whitelist in rpc_fundrawtransaction.py

9a85052

Makes tx relay faster

[tests] Don't stop-start unnecessarily in rpc_fundrawtransaction.py

af7bae7

This was only added in c1dde3a to match behaviour when `encryptwallet` would restart the node. It's not required for the test (and slows things down).

jnewbery force-pushed the 2019-11-speed-up-fundrawtransaction-test branch from ae6fd92 to af7bae7 Compare November 6, 2019 19:56

maflcko merged commit af7bae7 into bitcoin:master Nov 6, 2019

jnewbery deleted the 2019-11-speed-up-fundrawtransaction-test branch November 6, 2019 20:22

MarkLTZ mentioned this pull request Apr 4, 2020

Bitcoin PR tracking litecoinz-core/litecoinz#14

Closed

theStack mentioned this pull request Jul 22, 2020

test: p2p_feefilter improvements (logging, refactoring, speedup) #19564

Merged

bitcoin locked as resolved and limited conversation to collaborators Dec 16, 2021

Tests: speed up fundrawtransaction test #17340

Tests: speed up fundrawtransaction test #17340

Uh oh!

Conversation

jnewbery commented Nov 1, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

jnewbery commented Nov 1, 2019

Uh oh!

jnewbery commented Nov 1, 2019

Uh oh!

jonatack left a comment

Choose a reason for hiding this comment

Uh oh!

promag commented Nov 1, 2019

Uh oh!

jonatack commented Nov 1, 2019

Uh oh!

achow101 commented Nov 1, 2019

Uh oh!

jnewbery commented Nov 1, 2019

Uh oh!

maflcko commented Nov 1, 2019

Uh oh!

jnewbery commented Nov 1, 2019

Uh oh!

jnewbery commented Nov 1, 2019

Uh oh!

maflcko commented Nov 1, 2019

Uh oh!

jnewbery commented Nov 1, 2019

Uh oh!

jonatack commented Nov 4, 2019

Uh oh!

jonatack Nov 4, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Sjors Nov 4, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

jnewbery Nov 4, 2019

Choose a reason for hiding this comment

Uh oh!

Sjors left a comment

Choose a reason for hiding this comment

Uh oh!

Sjors Nov 4, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

jnewbery commented Nov 4, 2019

Uh oh!

jonatack left a comment

Choose a reason for hiding this comment

Uh oh!

jonatack Nov 6, 2019

Choose a reason for hiding this comment

Uh oh!

jnewbery Nov 6, 2019

Choose a reason for hiding this comment

Uh oh!

jonatack Nov 7, 2019

Choose a reason for hiding this comment

Uh oh!

maflcko commented Nov 6, 2019

Uh oh!

promag commented Nov 6, 2019

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

7 participants

jnewbery commented Nov 1, 2019 •

edited

Loading

jonatack Nov 4, 2019 •

edited

Loading

Sjors Nov 4, 2019 •

edited

Loading

Sjors Nov 4, 2019 •

edited

Loading