test: bump mocktime only after node has received and sent bytes #30468

1. 
   stratospher commented at 10:45 am on July 17, 2024: contributor

   Fixes an intermittent failure for p2p_v2_misbehaving.py reported in #30420 (review).

   A different error message "socket no message in first %i seconds" will be displayed if m_last_send=0 or if m_last_recv is 0. Fix this by:

   1. mocktime bump is done after all the bytes are received. (m_last_recv is not 0 now)
   2. wait until bytes are sent by TestNode/bitcoind (m_last_send is not 0 now)

   See https://cirrus-ci.com/task/5359619151757312?logs=ci#L3935 for an example failure (I wasn’t able to reproduce the intermittent failure locally but I think the fix is logical)

2. 
   DrahtBot commented at 10:45 am on July 17, 2024: contributor

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

   Code Coverage

   For detailed information about the code coverage, see the test coverage report.

   Reviews

   See the guideline for information on the review process.

   Type	Reviewers
   ACK	maflcko

   If your review is incorrectly listed, please react with 👎 to this comment and the bot will ignore it on the next update.

3. DrahtBot added the label Tests on Jul 17, 2024
4. in test/functional/p2p_v2_misbehaving.py:153 in e6f4614ea5 outdated

   146@@ -147,9 +147,10 @@ def test_earlykeyresponse(self):
   147         peer1.v2_state.can_data_be_received = True
   148         self.wait_until(lambda: peer1.v2_state.ellswift_ours)
   149         peer1.send_raw_message(peer1.v2_state.ellswift_ours[4:] + peer1.v2_state.sent_garbage)
   150-        node0.bumpmocktime(3)
   151         # Ensure that the bytes sent after 4 bytes network magic are actually received.
   152         self.wait_until(lambda: node0.getpeerinfo()[-1]["bytesrecv"] > 4)
   153+        self.wait_until(lambda: node0.getpeerinfo()[-1]["bytessent"] > 0)
   154+        node0.bumpmocktime(3)
   

   ---

   ---

   

   maflcko commented at 11:43 am on July 17, 2024:

   This will be racy, no?

   The peer timeout is 3, which is also the bump, so the peer may be disconnected at any time, leading to a test failure if it is disconnected at the wrong time.

   Something like this should fail the test, no?

   0        node0.bumpmocktime(3); time.sleep(1);
   

   ---

   

   stratospher commented at 12:17 pm on July 17, 2024:

   I couldn’t reproduce it locally.

   since peer timeout is 3, InactivityCheck()(and hence disconnection) will happen when our time is > 3. so disconnection will only happen during the next bumpmocktime(1) I think.

   (Also see #30420 (review))

   ---

   

   maflcko commented at 12:23 pm on July 17, 2024:

   Ah, I see the check is <, not <=.

   However, what is the purpose of two immediately following bumpmocktime on the same node? Wouldn’t it be easier to just combine them into one (and use the sum of their arguments)?

   ---

   

   stratospher commented at 12:28 pm on July 17, 2024:

   true, done.
5. 
   maflcko commented at 12:24 pm on July 17, 2024: member

   review ACK e6f4614ea57dbd3d8690fdbed55ecf2612619070

   Looks good, feel free to ignore the nit.

6. stratospher force-pushed on Jul 17, 2024
7. test: bump mocktime after node has received and sent bytes

   a different error message "socket no message in first %i seconds"
   will be displayed if m_last_send=0 or if m_last_recv is 0. make
   the test robust by ensuring that they will not be 0 before
   bumping mocktime.

   c322bddd08
8. stratospher force-pushed on Jul 17, 2024
9. 
   maflcko commented at 12:32 pm on July 17, 2024: member

   reACK c322bddd08ed1f1f7f0c39768b659dd62d5e2dd5
10. fanquake merged this on Jul 17, 2024
11. fanquake closed this on Jul 17, 2024

    ---

12. stratospher deleted the branch on Jul 17, 2024

Contributors
stratospher DrahtBot maflcko

Labels
Tests