test: Refactor addr_relay.py addr generation, increase mocktime #23720

mzumsande commented at 12:15 AM on December 9, 2021: member

Fixes #22449 by increasing the mocktime jump (just as in https://github.com/bitcoin/bitcoin/commit/6168eb06b2044f00f18727b955b672fc91c60bd7), which prevents failures due to rare Poisson timer events, or at least makes them a lot more unlikely.

The second commit combines the addr generation helper functions setup_addr_msg and setup_rand_addr_msg. It also changes the way addr.time is filled to random, because before, if too many addresses (>600) were created in a batch, they would stop being relayed because their timestamp would be too far in the future.

DrahtBot added the label Tests on Dec 9, 2021

in test/functional/p2p_addr_relay.py:101 in f8ff552aa0 outdated

  99 | -            addr.time = self.mocktime + i
 100 | +            addr.time = self.mocktime + random.randrange(-100, 100)
 101 |              addr.nServices = P2P_SERVICES
 102 | -            addr.ip = f"123.123.123.{self.counter % 256}"
 103 | +            if deterministic_ips:
 104 | +                addr.ip = f"123.123.123.{self.counter % 256}"

jnewbery commented at 1:40 PM on December 9, 2021:

It's a bit of a shame that this wraps based on a global counter. Perhaps:

                assert self.counter < 256 ** 2  # Don't allow the returned ip addresses to wrap.
                addr.ip = f"123.123.{self.counter // 256}.{self.counter % 256}"

mzumsande commented at 11:08 PM on December 13, 2021:

Done as suggested. I also moved the incrementation of the counter into the sequential_ips conditional because it is only used there.

in test/functional/p2p_addr_relay.py:94 in f8ff552aa0 outdated

  90 | @@ -91,13 +91,16 @@ def run_test(self):
  91 |          self.blocksonly_mode_tests()
  92 |          self.rate_limit_tests()
  93 |  
  94 | -    def setup_addr_msg(self, num):
  95 | +    def setup_addr_msg(self, num, deterministic_ips=True):

jnewbery commented at 1:41 PM on December 9, 2021:

nit: to bikeshed, I'd suggest calling this parameter sequential_ips, since even the "random" ips are deterministic based on the random seed set at the start of the test.

mzumsande commented at 10:31 PM on December 13, 2021:

done

in test/functional/p2p_addr_relay.py:280 in f8ff552aa0 outdated

 271 | @@ -282,7 +272,7 @@ def getaddr_tests(self):
 272 |          block_relay_peer.send_and_ping(msg_getaddr())
 273 |          inbound_peer.send_and_ping(msg_getaddr())
 274 |  
 275 | -        self.mocktime += 5 * 60
 276 | +        self.mocktime += 10 * 60

jnewbery commented at 2:21 PM on December 9, 2021:

This is a bit of a magic number. Perhaps it's worth a comment?

diff --git a/test/functional/p2p_addr_relay.py b/test/functional/p2p_addr_relay.py
index 5f75670739..1502038b2d 100755
--- a/test/functional/p2p_addr_relay.py
+++ b/test/functional/p2p_addr_relay.py
@@ -272,6 +272,10 @@ class AddrTest(BitcoinTestFramework):
         block_relay_peer.send_and_ping(msg_getaddr())
         inbound_peer.send_and_ping(msg_getaddr())
 
+        # `addr` messages are sent on an exponential distribution with mean interval
+        # of 30s. Setting the mocktime 600s forward and waiting for 60s for the
+        # addr message gives a probability of (1 - e^-(660/30)) that the event will
+        # occur (i.e. this fails less than one in 3 billion repeats).
         self.mocktime += 10 * 60
         self.nodes[0].setmocktime(self.mocktime)
         inbound_peer.wait_until(lambda: inbound_peer.addr_received() is True)

Incidentally, I don't like the name PoissonNextSend since people often refer to it incorrectly as a "Poisson distribution", whereas it is in fact an exponential distribution, which gives the probability distribution of the time between events in a Poisson point process (https://en.wikipedia.org/wiki/Exponential_distribution).

mzumsande commented at 10:31 PM on December 13, 2021:

I added a comment for that - I think we can't count the last 60s because afaik once we set the mocktime once, the internal time won't progress by waiting.

I think it would make sense to document this feature of PoissonNextSend in net, since this has confused me before as well (and others, see e.g. #23347).

jnewbery commented at 10:17 AM on December 14, 2021:

I think we can't count the last 60s because afaik once we set the mocktime once, the internal time won't progress by waiting.

Ah yes. I think you're right.

I think it would make sense to document this feature of PoissonNextSend

I'll have a crack at this.

jnewbery commented at 10:57 AM on December 14, 2021:

I have a branch here: https://github.com/jnewbery/bitcoin/tree/2021-12-rename-poisson that renames the poisson functions, expands the comments and moves them to more appropriate places. Let me know what you think.

jnewbery commented at 2:21 PM on December 9, 2021: member

ACK f8ff552aa05686d5b08c9b03bb798804039b738d

A few comments inline for your entertainment. Nothing blocking.

shaavan commented at 12:35 PM on December 10, 2021: contributor

Concept ACK

Increasing mocktime would exponentially decrease the chance of getting a timeout before receiving the addr message. So I agree with that!

I think it makes sense to combine the setup_addr_msg and setup_rand_addr_msg function in the second commit because it makes the code cleaner and avoids two different functions for similar functionality. I had one Suggestion and one Doubt considering the second commit:

Suggestion:

I suggest you should add the following part of the PR description…

The second commit combines the addr generation helper functions setup_addr_msg and setup_rand_addr_msg. It also changes the way addr.time is filled to random, because before, if too many addresses (>600) were created in a batch, they would stop being relayed because their timestamp would be too far in the future.

In the commit message itself. This would make it easier for future reviewers to understand the reasoning behind this particular patch.

Doubt:

In setup_rand_addr_msg, the master’s branch, the value of addr.port remains unchanged for each iteration.

for i in range(num):
            addr = CAddress()
            addr.time = self.mocktime + i
            addr.nServices = P2P_SERVICES
            addr.ip = f"{random.randrange(128,169)}.{random.randrange(1,255)}.{random.randrange(1,255)}.{random.randrange(1,255)}"
            addr.port = 8333
            addrs.append(addr)

While in the PR’s setup_addr_msg(self, num, deterministic_ips=False): the value of addr.port get updated with each iteration, irrespective of if the ips generated are deterministic or random.

for i in range(num):
            addr = CAddress()
            addr.time = self.mocktime + i
            addr.time = self.mocktime + random.randrange(-100, 100)
            addr.nServices = P2P_SERVICES
            addr.ip = f"123.123.123.{self.counter % 256}"
            if deterministic_ips:
                addr.ip = f"123.123.123.{self.counter % 256}"
            else:
                addr.ip = f"{random.randrange(128,169)}.{random.randrange(1,255)}.{random.randrange(1,255)}.{random.randrange(1,255)}"
            addr.port = 8333 + i

In case my observation is erroneous, please kindly correct me, but I think this might lead to unexpected behavioral change.

mzumsande force-pushed on Dec 13, 2021

mzumsande commented at 10:58 PM on December 13, 2021: member

Thanks for the reviews @jnewbery @shaavan

I suggest you should add the following part of the PR description…

Done, thanks

In setup_rand_addr_msg, the master’s branch, the value of addr.port remains unchanged for each iteration. (...) While in the PR’s setup_addr_msg(self, num, deterministic_ips=False): the value of addr.port get updated with each iteration, irrespective of if the ips generated are deterministic or random.

Right, good obsevation! I agree that this is a small change in behavior of the test, but I don't think it's problematic. Adding a bit more variety in terms of ports to the addrs used in send_addrs_and_test_rate_limiting should not affect the outcome of this test, and with ongoing efforts to allow more port variety (e.g. #23542) it makes sense to have that variety reflected here too.

mzumsande force-pushed on Dec 13, 2021

jnewbery commented at 11:02 AM on December 14, 2021: member

ACK 030089d77aca0f3c8b01afa87e78818e28f4c40f

in test/functional/p2p_addr_relay.py:279 in 030089d77a outdated

 275 | @@ -282,7 +276,8 @@ def getaddr_tests(self):
 276 |          block_relay_peer.send_and_ping(msg_getaddr())
 277 |          inbound_peer.send_and_ping(msg_getaddr())
 278 |  
 279 | -        self.mocktime += 5 * 60
 280 | +        # invoke m_next_addr_send timer, see above for rationale

shaavan commented at 12:19 PM on December 15, 2021:

This line does not clearly explain where to look for the rationale. Maybe mentioning the function name (where it has been described) might help.

        # invoke m_next_addr_send timer, see the rationale under definition of send_addr_msg() function

mzumsande commented at 12:44 PM on December 16, 2021:

done

shaavan commented at 12:19 PM on December 15, 2021: contributor

Changes since my last review:

Added the rationale behind increasing mocktime in the function send_addr_msg() and getaddr_tests().
The variable deterministic_ips has been renamed to sequential_ips.
The fixed part in the sequential_ips has been changed from 123.123.123. to 123.123. This is done to prevent the wrapping of IP addresses.
The self.counter is now only moved forward in the case when sequential_ips == true.

I agree with the changes added to this PR. I had one suggestion, though.

josibake commented at 2:13 PM on December 15, 2021: member

ACK https://github.com/bitcoin/bitcoin/commit/030089d77aca0f3c8b01afa87e78818e28f4c40f

rebased on master and ran the test a few times, looks good. +1 for the comments in the code; made it easy for me to follow the rationale for the change.

test: Fix intermittent issue in p2p_addr_relay.py

by increasing the mocktime bump for m_next_addr_send, which is on a
Poisson timer, and explain why. Closes #22449

aeeccd9aa6

test: Combine addr generation helper functions

This combines the addr generation helper functions setup_addr_msg
and setup_rand_addr_msg.
It also changes the way addr.time is filled to random, because before,
if too many addresses (>600) were created in a batch, they would stop
being relayed because their timestamp would be too far in the future.

261dddb924

mzumsande force-pushed on Dec 16, 2021

josibake commented at 1:02 PM on December 16, 2021: member

reACK https://github.com/bitcoin/bitcoin/pull/23720/commits/261dddb92460f57d9a1e2409e7292da598787398

jnewbery commented at 1:38 PM on December 16, 2021: member

utACK 261dddb92460f57d9a1e2409e7292da598787398

Only change was in the code comment.

MarcoFalke merged this on Dec 16, 2021

MarcoFalke closed this on Dec 16, 2021

sidhujag referenced this in commit a9f42782e9 on Dec 16, 2021

mzumsande deleted the branch on Dec 16, 2021

DrahtBot locked this on Dec 16, 2022