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

theStack commented at 9:18 AM on July 22, 2020: member

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) 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

fanquake added the label Tests on Jul 22, 2020

in test/functional/p2p_feefilter.py:97 in 9a8dc4e2b5 outdated

  95 |          txids = [node1.sendtoaddress(node1.getnewaddress(), 1) for x in range(3)]
  96 |          assert allInvsMatch(txids, conn)
  97 |          conn.clear_invs()
  98 |  
  99 | -        # Set a filter of .15 sat/byte on test connection
 100 | +        self.log.info("Set a fee filter of .15 sat/byte on test connection")

jonatack commented at 11:23 AM on July 22, 2020:

I think you can leave this line as a code comment instead of logging it.

For the logging in general, would you mind prefixing the decimal values with 0? e.g. s/.15/0.15/

This is personal taste, so feel free to ignore, but I think it's unnecessarily verbose to add "that" after "Test..."

theStack commented at 3:11 PM on July 22, 2020:

Done.

in test/functional/p2p_feefilter.py:42 in 8f93aaf016 outdated

  36 | @@ -48,6 +37,12 @@ def on_inv(self, message):
  37 |              if (i.type == MSG_TX):
  38 |                  self.txinvs.append(hashToHex(i.hash))
  39 |  
  40 | +    def wait_for_invs(self, test_framework, invs_expected):
  41 | +        def invs_match():
  42 | +            return sorted(invs_expected) == sorted(self.txinvs)

jonatack commented at 11:26 AM on July 22, 2020:

could inline this with a lambda?

theStack commented at 3:12 PM on July 22, 2020:

Before I had done it using a lambda and an assignment, the the following way:

invs_match = lambda: sorted(invs_expected) == sorted(self.txinvs)
test_framework.wait_until(invs_match, timeout=60, lock=mininode_lock)

but then flake8 would give the following error: p2p_feefilter.py:41:9: E731 do not assign a lambda expression, use a def

Directly using the lambda on place of the parameter of wait_until works though, done.

in test/functional/p2p_feefilter.py:40 in 8f93aaf016 outdated

  36 | @@ -48,6 +37,12 @@ def on_inv(self, message):
  37 |              if (i.type == MSG_TX):
  38 |                  self.txinvs.append(hashToHex(i.hash))
  39 |  
  40 | +    def wait_for_invs(self, test_framework, invs_expected):

jonatack commented at 11:27 AM on July 22, 2020:

perhaps call this assert_invs_match or wait_for_invs_to_match

theStack commented at 3:12 PM on July 22, 2020:

Done, I chose wait_for_invs_to_match.

in test/functional/p2p_feefilter.py:62 in bde6920459 outdated

  56 | @@ -57,6 +57,9 @@ def set_test_params(self):
  57 |          # rounding down 3 places, leading to stranded transactions.
  58 |          # See issue #16499
  59 |          self.extra_args = [["-minrelaytxfee=0.00000100", "-mintxfee=0.00000100"]] * self.num_nodes
  60 | +        # whitelist all peers to speed up tx relay / mempool sync
  61 | +        for args in self.extra_args:
  62 | +            args.append("-whitelist=noban@127.0.0.1")

jonatack commented at 11:27 AM on July 22, 2020:

could just inline this arg with the others and put the comment above line 59

theStack commented at 3:12 PM on July 22, 2020:

Done.

jonatack commented at 11:29 AM on July 22, 2020: member

Concept ACK

Edit: verified the test runs significantly more quickly with the noban arg.

theStack force-pushed on Jul 22, 2020

theStack commented at 3:13 PM on July 22, 2020: member

Thans a lot for reviewing jonatack! Force-pushed with your suggested changes.

in test/functional/p2p_feefilter.py:41 in 302388ea66 outdated

  36 | @@ -48,6 +37,10 @@ def on_inv(self, message):
  37 |              if (i.type == MSG_TX):
  38 |                  self.txinvs.append(hashToHex(i.hash))
  39 |  
  40 | +    def wait_for_invs_to_match(self, test_framework, invs_expected):
  41 | +        test_framework.wait_until(lambda: sorted(invs_expected) == sorted(self.txinvs),

jonatack commented at 4:32 PM on July 22, 2020:

I wonder if we can eek some more perf by memoizing (untested):

        expected_txinvs = sorted(invs_expected)
        test_framework.wait_until(lambda: sorted(self.txinvs) == expected_txinvs),

theStack commented at 9:29 PM on August 4, 2020:

Yes, that makes sense to do the sorting of the txinvs to test for only once. Did it with in-place sort of the passed list.

in test/functional/p2p_feefilter.py:57 in 302388ea66 outdated

  53 | @@ -61,7 +54,9 @@ def set_test_params(self):
  54 |          # mempool and wallet feerate calculation based on GetFee
  55 |          # rounding down 3 places, leading to stranded transactions.
  56 |          # See issue #16499
  57 | -        self.extra_args = [["-minrelaytxfee=0.00000100", "-mintxfee=0.00000100"]] * self.num_nodes
  58 | +        # whitelist all peers to speed up tx relay / mempool sync

jonatack commented at 4:37 PM on July 22, 2020:

Sorry I didn't notice this earlier; I think we're now starting to call this s/whitelist all/grant noban permission to/ (or something similar)

theStack commented at 9:27 PM on August 4, 2020:

Thanks, done.

jonatack commented at 4:39 PM on July 22, 2020: member

LGTM, a couple more comments below.

theStack force-pushed on Aug 4, 2020

theStack commented at 9:32 PM on August 4, 2020: member

Rebased on master and added suggested changes by jonatack (only sort expected invs once, use correct terminology regarding noban permission terminology).

in test/functional/p2p_feefilter.py:96 in 2d43d84bd1 outdated

  96 | -        # Set a filter of .15 sat/byte on test connection
  97 | +        # Set a fee filter of 0.15 sat/byte on test connection
  98 |          conn.send_and_ping(msg_feefilter(150))
  99 |  
 100 | -        # Test that txs are still being received by test connection (paying .15 sat/byte)
 101 | +        self.log.info("Test txs paying 0.15 sat/byte are being received by test connection")

jonatack commented at 7:07 AM on August 5, 2020:

c063dce9 nit: if you have to retouch, can remove "being" here and in line 87.

jonatack commented at 7:10 AM on August 5, 2020: member

ACK 2d43d84

Restarted the stalled s390x Travis job.

DrahtBot commented at 7:54 PM on August 6, 2020: member

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

Conflicts

Reviewers, this pull request conflicts with the following ones:

#19674 (refactor: test: use throwaway _ variable for unused loop counters by theStack)

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.

DrahtBot added the label Needs rebase on Aug 11, 2020

theStack force-pushed on Aug 11, 2020

theStack commented at 10:20 AM on August 11, 2020: member

Rebased.

DrahtBot removed the label Needs rebase on Aug 11, 2020

jonatack commented at 8:15 AM on August 12, 2020: member

re-ACK ea74a3c per git range-diff ce3bdd0e 2d43d84 ea74a3c

laanwj requested review from MarcoFalke on Aug 12, 2020

laanwj requested review from instagibbs on Aug 12, 2020

in test/functional/p2p_feefilter.py:42 in ea74a3c680 outdated

  36 | @@ -48,6 +37,11 @@ def on_inv(self, message):
  37 |              if (i.type == MSG_TX) or (i.type == MSG_WTX):
  38 |                  self.txinvs.append(hashToHex(i.hash))
  39 |  
  40 | +    def wait_for_invs_to_match(self, test_framework, invs_expected):
  41 | +        invs_expected.sort()
  42 | +        test_framework.wait_until(lambda: invs_expected == sorted(self.txinvs),

MarcoFalke commented at 7:49 PM on August 12, 2020:

why not self.wait_until?

theStack commented at 11:44 PM on August 12, 2020:

Good idea, this makes the code a lot shorter -- test_framework doesn't have to be passed to the inv-wait function and also setting the lock parameter is not needed anymore. Done.

in test/functional/p2p_feefilter.py:60 in ea74a3c680 outdated

  54 | @@ -61,7 +55,9 @@ def set_test_params(self):
  55 |          # mempool and wallet feerate calculation based on GetFee
  56 |          # rounding down 3 places, leading to stranded transactions.
  57 |          # See issue #16499
  58 | -        self.extra_args = [["-minrelaytxfee=0.00000100", "-mintxfee=0.00000100"]] * self.num_nodes
  59 | +        # grant noban permission to all peers to speed up tx relay / mempool sync
  60 | +        self.extra_args = [["-minrelaytxfee=0.00000100", "-mintxfee=0.00000100",
  61 | +                            "-whitelist=noban@127.0.0.1"]] * self.num_nodes

MarcoFalke commented at 7:50 PM on August 12, 2020:

would be nice to either put all in one line or each in one new line

theStack commented at 11:45 PM on August 12, 2020:

Decided for the one-arg-per-line version. Done.

MarcoFalke approved

MarcoFalke commented at 7:50 PM on August 12, 2020: member

Looks fine, some style nits

4fbda7da50d508481d9a94b00e4dc994dad9465d

test: add logging for p2p_feefilter.py 6d941923c3

test: use wait_until for invs matching in p2p_feefilter.py

additionally:
    -> rename function with snake_case (s/allInvsMatch/wait_for_invs_to_match)
    -> move it from global namespace to the class FeefilterConn

fe3f0cc44e

test: speedup p2p_feefilter.py by whitelisting peers (immediate tx relay)

Most of the test time is spent in wait_for_invs() after sending to addresses,
i.e. the bottleneck is in relaying transactions. By whitelisting the peers via
-whitelist, the inventory is transmissioned immediately rather than on average
every 5 seconds, speeding up the test significantly:

before:
$ time ./p2p_feefilter.py
...
real    0m39.367s
user    0m1.227s
sys 0m0.571s

with this commit:
$ time ./p2p_feefilter.py
...
real    0m9.386s
user    0m1.120s
sys 0m0.577s

9e7894357e

theStack force-pushed on Aug 12, 2020

theStack commented at 11:48 PM on August 12, 2020: member

Thanks for reviewing Marco. Force-pushed with your suggestions and a small log-message change proposed by jonatack previously (https://github.com/bitcoin/bitcoin/pull/19564#discussion_r465517818).

instagibbs commented at 2:18 AM on August 13, 2020: member

code review ACK https://github.com/bitcoin/bitcoin/pull/19564/commits/9e7894357e296dbe0be775e1527654729dbb71b0

jonatack commented at 8:30 AM on August 16, 2020: member

re-ACK 9e78943 per git range-diff 3ab2582 ea74a3c 9e78943

MarcoFalke merged this on Aug 16, 2020

MarcoFalke closed this on Aug 16, 2020

sidhujag referenced this in commit 9f7e4e2bb0 on Aug 16, 2020

theStack deleted the branch on Dec 1, 2020

Fabcien referenced this in commit 021ed21795 on Sep 15, 2021

DrahtBot locked this on Feb 15, 2022