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

ci: feature_proxy failing in MSVC job #29090

Open
fanquake opened this issue Dec 15, 2023 · 11 comments
Open

ci: feature_proxy failing in MSVC job #29090

fanquake opened this issue Dec 15, 2023 · 11 comments
Labels
CI failed Tests Windows

Comments

@fanquake
Copy link
Member

https://github.com/bitcoin/bitcoin/actions/runs/7219794888/job/19671475361?pr=29088#step:27:73:

288/288 - feature_proxy.py failed, Duration: 2410 s

stdout:
2023-12-15T08:53:02.026000Z TestFramework (INFO): PRNG seed is: 197024891591373016

2023-12-15T08:53:02.026000Z TestFramework (INFO): Initializing test directory D:\a\_temp\test_runner_₿_🏃_20231215_084456\feature_proxy_168

2023-12-15T09:33:11.259000Z TestFramework (ERROR): Assertion failed

Traceback (most recent call last):

  File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 556, in start_nodes

    node.wait_for_rpc_connection()

  File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 308, in wait_for_rpc_connection

    self._raise_assertion_error("Unable to connect to bitcoind after {}s".format(self.rpc_timeout))

  File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 182, in _raise_assertion_error

    raise AssertionError(self._node_msg(msg))

AssertionError: [node 0] Unable to connect to bitcoind after 2400s



During handling of the above exception, another exception occurred:



Traceback (most recent call last):

  File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 130, in main

    self.setup()

  File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 297, in setup

    self.setup_network()

  File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 391, in setup_network

    self.setup_nodes()

  File "D:\a\bitcoin\bitcoin/test/functional/feature_proxy.py", line 117, in setup_nodes

    self.start_nodes()

  File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 559, in start_nodes

    self.stop_nodes()

  File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 574, in stop_nodes

    node.stop_node(wait=wait, wait_until_stopped=False)

  File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 369, in stop_node

    self.stop(wait=wait)

    ^^^^^^^^^

  File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 199, in __getattr__

    assert self.rpc_connected and self.rpc is not None, self._node_msg("Error: no RPC connection")

AssertionError: [node 0] Error: no RPC connection

2023-12-15T09:33:11.314000Z TestFramework (INFO): Stopping nodes



stderr:
Traceback (most recent call last):

  File "D:\a\bitcoin\bitcoin/test/functional/feature_proxy.py", line 388, in <module>

    ProxyTest().main()

  File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 154, in main

    exit_code = self.shutdown()

                ^^^^^^^^^^^^^^^

  File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 313, in shutdown

    self.stop_nodes()

  File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 574, in stop_nodes

    node.stop_node(wait=wait, wait_until_stopped=False)

  File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 369, in stop_node

    self.stop(wait=wait)

    ^^^^^^^^^

  File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 199, in __getattr__

    assert self.rpc_connected and self.rpc is not None, self._node_msg("Error: no RPC connection")

AssertionError: [node 0] Error: no RPC connection



Combine the logs and print the last 99999999 lines ...

============
Combined log for D:\a\_temp/test_runner_₿_🏃_20231215_084456/feature_proxy_168:
============

 test  2023-12-15T08:53:02.026000Z TestFramework (INFO): PRNG seed is: 197024891591373016 
 test  2023-12-15T08:53:02.026000Z TestFramework (DEBUG): Setting up network thread 
 test  2023-12-15T08:53:02.026000Z TestFramework (INFO): Initializing test directory D:\a\_temp\test_runner_₿_🏃_20231215_084456\feature_proxy_168 
 test  2023-12-15T08:53:02.042000Z TestFramework.node0 (DEBUG): bitcoind started, waiting for RPC to come up 
 test  2023-12-15T08:53:02.042000Z TestFramework.node1 (DEBUG): bitcoind started, waiting for RPC to come up 
 test  2023-12-15T08:53:02.042000Z TestFramework.node2 (DEBUG): bitcoind started, waiting for RPC to come up 
 test  2023-12-15T08:53:02.042000Z TestFramework.node3 (DEBUG): bitcoind started, waiting for RPC to come up 
 test  2023-12-15T08:53:02.042000Z TestFramework.node4 (DEBUG): bitcoind started, waiting for RPC to come up 
 test  2023-12-15T09:33:11.259000Z TestFramework.node0 (DEBUG): Stopping node 
 test  2023-12-15T09:33:11.259000Z TestFramework (ERROR): Assertion failed 
                                   Traceback (most recent call last):
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 556, in start_nodes
                                       node.wait_for_rpc_connection()
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 308, in wait_for_rpc_connection
                                       self._raise_assertion_error("Unable to connect to bitcoind after {}s".format(self.rpc_timeout))
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 182, in _raise_assertion_error
                                       raise AssertionError(self._node_msg(msg))
                                   AssertionError: [node 0] Unable to connect to bitcoind after 2400s
                                   During handling of the above exception, another exception occurred:
                                   Traceback (most recent call last):
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 130, in main
                                       self.setup()
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 297, in setup
                                       self.setup_network()
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 391, in setup_network
                                       self.setup_nodes()
                                     File "D:\a\bitcoin\bitcoin/test/functional/feature_proxy.py", line 117, in setup_nodes
                                       self.start_nodes()
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 559, in start_nodes
                                       self.stop_nodes()
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 574, in stop_nodes
                                       node.stop_node(wait=wait, wait_until_stopped=False)
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 369, in stop_node
                                       self.stop(wait=wait)
                                       ^^^^^^^^^
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 199, in __getattr__
                                       assert self.rpc_connected and self.rpc is not None, self._node_msg("Error: no RPC connection")
                                   AssertionError: [node 0] Error: no RPC connection
 test  2023-12-15T09:33:11.259000Z TestFramework (DEBUG): Closing down network thread 
 test  2023-12-15T09:33:11.314000Z TestFramework (INFO): Stopping nodes 
 test  2023-12-15T09:33:11.314000Z TestFramework.node0 (DEBUG): Stopping node
@fanquake fanquake mentioned this issue Dec 15, 2023
Merged
@fanquake
Copy link
Member Author

Similar failure, different test: https://github.com/bitcoin/bitcoin/actions/runs/7249043694/job/19746211856#step:27:521.

@maflcko
Copy link
Member

maflcko commented Jan 24, 2024

Similar failure, different test: https://github.com/bitcoin/bitcoin/actions/runs/7249043694/job/19746211856#step:27:521.

Not sure. This one has

Error: 2023-12-18T14:15:31.391534Z [D:\a\bitcoin\bitcoin\src\logging.h:264] [error] ERROR: Commit: Failed to commit latest txindex state

in the log.

@maflcko maflcko mentioned this issue Jan 26, 2024
Closed
@fanquake
Copy link
Member Author

https://github.com/bitcoin/bitcoin/actions/runs/7667501768/job/20897463395

 ============
Combined log for D:\a\_temp/test_runner_₿_🏃_20240126_113602/feature_index_prune_293:
============

 test  2024-01-26T11:36:28.165000Z TestFramework (INFO): PRNG seed is: 8852427722333217080 
 test  2024-01-26T11:36:28.165000Z TestFramework (DEBUG): Setting up network thread 
 test  2024-01-26T11:36:28.212000Z TestFramework (INFO): Initializing test directory D:\a\_temp\test_runner_₿_🏃_20240126_113602\feature_index_prune_293 
 test  2024-01-26T11:36:28.212000Z TestFramework (DEBUG): Copy cache directory D:\a\bitcoin\bitcoin\test\cache\node0 to node 0 
 test  2024-01-26T11:36:28.227000Z TestFramework (DEBUG): Copy cache directory D:\a\bitcoin\bitcoin\test\cache\node0 to node 1 
 test  2024-01-26T11:36:28.274000Z TestFramework (DEBUG): Copy cache directory D:\a\bitcoin\bitcoin\test\cache\node0 to node 2 
 test  2024-01-26T11:36:28.290000Z TestFramework (DEBUG): Copy cache directory D:\a\bitcoin\bitcoin\test\cache\node0 to node 3 
 test  2024-01-26T11:36:28.337000Z TestFramework.node0 (DEBUG): bitcoind started, waiting for RPC to come up 
 test  2024-01-26T11:36:28.337000Z TestFramework.node1 (DEBUG): bitcoind started, waiting for RPC to come up 
 test  2024-01-26T11:36:28.337000Z TestFramework.node2 (DEBUG): bitcoind started, waiting for RPC to come up 
 test  2024-01-26T11:36:28.337000Z TestFramework.node3 (DEBUG): bitcoind started, waiting for RPC to come up 
 test  2024-01-26T12:18:05.036000Z TestFramework.node0 (DEBUG): Stopping node 
 test  2024-01-26T12:18:05.036000Z TestFramework (ERROR): Assertion failed 
                                   Traceback (most recent call last):
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 556, in start_nodes
                                       node.wait_for_rpc_connection()
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 308, in wait_for_rpc_connection
                                       self._raise_assertion_error("Unable to connect to bitcoind after {}s".format(self.rpc_timeout))
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 182, in _raise_assertion_error
                                       raise AssertionError(self._node_msg(msg))
                                   AssertionError: [node 0] Unable to connect to bitcoind after 2400s
                                   During handling of the above exception, another exception occurred:
                                   Traceback (most recent call last):
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 130, in main
                                       self.setup()
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 297, in setup
                                       self.setup_network()
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 391, in setup_network
                                       self.setup_nodes()
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 413, in setup_nodes
                                       self.start_nodes()
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 559, in start_nodes
                                       self.stop_nodes()
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 574, in stop_nodes
                                       node.stop_node(wait=wait, wait_until_stopped=False)
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 369, in stop_node
                                       self.stop(wait=wait)
                                       ^^^^^^^^^
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 199, in __getattr__
                                       assert self.rpc_connected and self.rpc is not None, self._node_msg("Error: no RPC connection")
                                   AssertionError: [node 0] Error: no RPC connection
 test  2024-01-26T12:18:05.036000Z TestFramework (DEBUG): Closing down network thread 
 test  2024-01-26T12:18:05.090000Z TestFramework (INFO): Stopping nodes 
 test  2024-01-26T12:18:05.090000Z TestFramework.node0 (DEBUG): Stopping node

@m3dwards
Copy link
Contributor

I have been unable to replicate this on my Windows 11 box after over 200 full suite runs.

I did get a bunch of RPC timeouts when the tests tried to shut bitcoind down until I upgraded python from 3.11 to 3.12 and that seemed to fix that for me.

The CI job specifies python 3 (py -3) and on the hosted CI test runner since roughly October 2023 this will default to 3.12. No idea if this issue has anything to do with Python version but it's just to say all these failures would have been on the same version I am running stably.

@maflcko
Copy link
Member

maflcko commented Feb 28, 2024

The CI job specifies python 3 (py -3) and on the hosted CI test runner since roughly October 2023 this will default to 3.12.

I think it would be useful if the task printed the python version to the CI log, if that isn't already done.

@m3dwards
Copy link
Contributor

@hebasto also suggested printing the python version. I couldn't see it in the logs, I'll add it to the workflow.

@m3dwards
Copy link
Contributor

PR to print python version on windows ci job: #29504

@fanquake
Copy link
Member Author

fanquake commented Mar 8, 2024

New failure in feature_proxy: https://github.com/bitcoin/bitcoin/actions/runs/8205349524/job/22441996383?pr=29600#step:27:511

 test  2024-03-08T16:22:27.604000Z TestFramework (ERROR): Assertion failed 
                                   Traceback (most recent call last):
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 556, in start_nodes
                                       node.wait_for_rpc_connection()
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 316, in wait_for_rpc_connection
                                       self._raise_assertion_error("Unable to connect to bitcoind after {}s".format(self.rpc_timeout))
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 190, in _raise_assertion_error
                                       raise AssertionError(self._node_msg(msg))
                                   AssertionError: [node 2] Unable to connect to bitcoind after 2400s
                                   During handling of the above exception, another exception occurred:
                                   Traceback (most recent call last):
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 130, in main
                                       self.setup()
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 297, in setup
                                       self.setup_network()
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 391, in setup_network
                                       self.setup_nodes()
                                     File "D:\a\bitcoin\bitcoin/test/functional/feature_proxy.py", line 117, in setup_nodes
                                       self.start_nodes()
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 559, in start_nodes
                                       self.stop_nodes()
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 574, in stop_nodes
                                       node.stop_node(wait=wait, wait_until_stopped=False)
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 377, in stop_node
                                       self.stop(wait=wait)
                                       ^^^^^^^^^
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 207, in __getattr__
                                       assert self.rpc_connected and self.rpc is not None, self._node_msg("Error: no RPC connection")
                                   AssertionError: [node 2] Error: no RPC connection
 test  2024-03-08T16:22:27.604000Z TestFramework (DEBUG): Closing down network thread 
 node0 2024-03-08T16:22:27.606153Z [D:\a\bitcoin\bitcoin\src\httpserver.cpp:306] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:54744

@fanquake
Copy link
Member Author

Looks like the same failure, but in mining_basic.py (https://github.com/bitcoin/bitcoin/actions/runs/8248318114/job/22558373371#step:27:373):

  test  2024-03-12T12:59:23.285000Z TestFramework.node0 (DEBUG): Stopping node 
 test  2024-03-12T12:59:23.285000Z TestFramework.node1 (DEBUG): Stopping node 
 test  2024-03-12T12:59:23.285000Z TestFramework (ERROR): Assertion failed 
                                   Traceback (most recent call last):
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 560, in start_nodes
                                       node.wait_for_rpc_connection()
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 314, in wait_for_rpc_connection
                                       self._raise_assertion_error("Unable to connect to bitcoind after {}s".format(self.rpc_timeout))
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 188, in _raise_assertion_error
                                       raise AssertionError(self._node_msg(msg))
                                   AssertionError: [node 1] Unable to connect to bitcoind after 2400s
                                   During handling of the above exception, another exception occurred:
                                   Traceback (most recent call last):
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 130, in main
                                       self.setup()
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 301, in setup
                                       self.setup_network()
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 395, in setup_network
                                       self.setup_nodes()
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 417, in setup_nodes
                                       self.start_nodes()
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 563, in start_nodes
                                       self.stop_nodes()
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 578, in stop_nodes
                                       node.stop_node(wait=wait, wait_until_stopped=False)
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 375, in stop_node
                                       self.stop(wait=wait)
                                       ^^^^^^^^^
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 205, in __getattr__
                                       assert self.rpc_connected and self.rpc is not None, self._node_msg("Error: no RPC connection")
                                   AssertionError: [node 1] Error: no RPC connection
 test  2024-03-12T12:59:23.285000Z TestFramework (DEBUG): Closing down network thread 
 node0 2024-03-12T12:59:23.287013Z [D:\a\bitcoin\bitcoin\src\httpserver.cpp:306] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:59120

@fanquake
Copy link
Member Author

https://github.com/bitcoin/bitcoin/actions/runs/8690581373/job/23830847391:

  test  2024-04-15T15:06:28.426000Z TestFramework.node3 (DEBUG): Stopping node 
 test  2024-04-15T15:06:28.426000Z TestFramework (ERROR): Assertion failed 
                                   Traceback (most recent call last):
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 565, in start_nodes
                                       node.wait_for_rpc_connection()
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 314, in wait_for_rpc_connection
                                       self._raise_assertion_error("Unable to connect to bitcoind after {}s".format(self.rpc_timeout))
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 188, in _raise_assertion_error
                                       raise AssertionError(self._node_msg(msg))
                                   AssertionError: [node 3] Unable to connect to bitcoind after 2400s
                                   During handling of the above exception, another exception occurred:

@maflcko
Copy link
Member

maflcko commented Apr 16, 2024

Maybe related to the races seen in #29871 (comment) ?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
CI failed Tests Windows
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@fanquake @m3dwards @maflcko