Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

test: Intermittent issue in rpc_net.py #29030

Closed
maflcko opened this issue Dec 8, 2023 · 2 comments · Fixed by #29041
Closed

test: Intermittent issue in rpc_net.py #29030

maflcko opened this issue Dec 8, 2023 · 2 comments · Fixed by #29041
Labels
Tests
Milestone
27.0

Comments

@maflcko
Copy link
Member

maflcko commented Dec 8, 2023

https://drahtbot.space/temp_scratch/rpc_net_1408.tar.xz

 test  2023-12-08T12:02:27.339000Z TestFramework (INFO): Check getpeerinfo output before a version message was sent 
 node0 2023-12-08T12:02:27.341389Z [http] [httpserver.cpp:306] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:55486 
 node0 2023-12-08T12:02:27.342184Z [httpworker.0] [rpc/request.cpp:187] [parse] [rpc] ThreadRPCServer method=setmocktime user=__cookie__ 
 test  2023-12-08T12:02:27.346000Z TestFramework.p2p (DEBUG): Connecting to Bitcoin Node: 127.0.0.1:12680 
 test  2023-12-08T12:02:27.349000Z TestFramework.p2p (DEBUG): Connected & Listening: 127.0.0.1:12680 
 node0 2023-12-08T12:02:27.361824Z (mocktime: 2023-12-08T12:02:27Z) [net] [net.cpp:3704] [CNode] [net] Added connection peer=2 
 node0 2023-12-08T12:02:27.538605Z (mocktime: 2023-12-08T12:02:27Z) [net] [net.cpp:1825] [CreateNodeFromAcceptedSocket] [net] connection from 127.0.0.1:54834 accepted 
 node0 2023-12-08T12:02:27.540196Z (mocktime: 2023-12-08T12:02:27Z) [http] [httpserver.cpp:306] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:55486 
 node0 2023-12-08T12:02:27.541363Z (mocktime: 2023-12-08T12:02:27Z) [httpworker.2] [rpc/request.cpp:187] [parse] [rpc] ThreadRPCServer method=setmocktime user=__cookie__ 
 node0 2023-12-08T12:02:27.546132Z [http] [httpserver.cpp:306] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:55486 
 node0 2023-12-08T12:02:27.546901Z [httpworker.1] [rpc/request.cpp:187] [parse] [rpc] ThreadRPCServer method=getpeerinfo user=__cookie__ 
 test  2023-12-08T12:02:27.561000Z TestFramework (ERROR): Unexpected exception caught during testing 
                                   Traceback (most recent call last):
                                     File "/ci_container_base/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/test_framework/test_framework.py", line 131, in main
                                       self.run_test()
                                     File "/ci_container_base/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/rpc_net.py", line 62, in run_test
                                       self.test_getpeerinfo()
                                     File "/ci_container_base/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/rpc_net.py", line 116, in test_getpeerinfo
                                       peer_info = self.nodes[0].getpeerinfo()[no_version_peer_id]
                                                   ~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^
                                   IndexError: list index out of range
@maflcko maflcko added this to the 27.0 milestone Dec 8, 2023
@maflcko maflcko added the Tests label Dec 8, 2023
@theStack
Copy link
Contributor

theStack commented Dec 8, 2023 •
edited
Loading

Seems like asserting for the debug log message "Added connection peer=" is insufficient for ensuring that this new connection will show up in a following getpeerinfo() call, as the debug message is written in the CNode ctor, which means it hasn't been added to CConnman.m_nodes at this point yet. If I'm not missing anything, then using the newly introduced wait_for_new_peer helper instead of asserting the debug log should fix that.

@maflcko
Copy link
Member Author

maflcko commented Dec 9, 2023

Yes, I haven't looked at the code, but I presumed it was the same issue/fix.

theStack added a commit to theStack/bitcoin that referenced this issue Dec 9, 2023
@theStack
test: fix intermittent error in rpc_net.py (bitcoin#29030)
ea00f98 
Asserting for the debug log message "Added connection peer=" is
insufficient for ensuring that this new connection will show up in a
following getpeerinfo() call, as the debug message is written in the
CNode ctor, which means it hasn't necessarily been added to
CConnman.m_nodes at this point.

Solve this by using the recently introduced `wait_for_new_peer`
helper, which is more robust.

Fixes bitcoin#29030.
@theStack theStack mentioned this issue Dec 9, 2023
Merged
fanquake added a commit that referenced this issue Dec 11, 2023
@fanquake
Merge #29041: test: fix intermittent error in rpc_net.py (#29030)
36fabb0 
ea00f98 test: fix intermittent error in rpc_net.py (#29030) (Sebastian Falbesoner)

Pull request description:

  Asserting for the debug log message "Added connection peer=" is insufficient for ensuring that this new connection will show up in a following getpeerinfo() call, as the debug message is written in the CNode ctor, which means it hasn't necessarily been added to CConnman.m_nodes at this point.

  Solve this by using the recently introduced `wait_for_new_peer` helper (see #29006,  commit 00e0658), which is more robust.

  Fixes #29030.

ACKs for top commit:
  maflcko:
    lgtm ACK ea00f98

Tree-SHA512: dda307949a466fb3b24408a8c213d307e0af2155f2e8b4e52c836a22397f9d218bf9d8c54ca55bae62a96d7566f27167db9311dd8801785c327234783af5ed00
@bitcoin bitcoin locked and limited conversation to collaborators Dec 10, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
Tests
Projects
None yet
Milestone
27.0
Development

Successfully merging a pull request may close this issue.

test: fix intermittent error in rpc_net.py (#29030) theStack/bitcoin
2 participants
@theStack @maflcko