test: Intermittent issue in rpc_net.py #29030

issue maflcko opened this issue on December 8, 2023

maflcko commented at 12:14 PM on December 8, 2023: member

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 added this to the milestone 27.0 on Dec 8, 2023
maflcko added the label Tests on Dec 8, 2023
theStack commented at 5:36 PM on December 8, 2023: contributor

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 commented at 8:58 AM on December 9, 2023: member

Yes, I haven't looked at the code, but I presumed it was the same issue/fix.
theStack referenced this in commit ea00f982d2 on Dec 9, 2023
fanquake closed this on Dec 11, 2023
fanquake referenced this in commit 36fabb01b1 on Dec 11, 2023
bitcoin locked this on Dec 10, 2024

Contributors

maflcko

theStack

Labels

Tests

Milestone
27.0

Linked (view graph)

#29041 test: fix intermittent error in rpc_net.py (#29030)