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 Failure] test_rclcpp / test_n_nodes__rmw_zenoh_cpp deadlock #329

Closed
YuanYuYuan opened this issue Dec 5, 2024 · 3 comments
Closed

[Test Failure] test_rclcpp / test_n_nodes__rmw_zenoh_cpp deadlock #329

YuanYuYuan opened this issue Dec 5, 2024 · 3 comments
Assignees
@Yadunund

Comments

@YuanYuYuan
Copy link
Contributor

To reproduce

➜ colcon test --event-handlers console_cohesion+ console_direct+ --packages-select test_rclcpp --ctest-args -R test_n_nodes__rmw_zenoh_cpp
Starting >>> test_rclcpp
UpdateCTestConfiguration  from :/workspace/build/test_rclcpp/CTestConfiguration.ini
Parse Config file:/workspace/build/test_rclcpp/CTestConfiguration.ini
   Site: nitro-an515
   Build name: (empty)
 Add coverage exclude regular expressions.
Create new tag: 20241015-0335 - Experimental
UpdateCTestConfiguration  from :/workspace/build/test_rclcpp/CTestConfiguration.ini
Parse Config file:/workspace/build/test_rclcpp/CTestConfiguration.ini
Test project /workspace/build/test_rclcpp
Constructing a list of tests
Done constructing a list of tests
Updating test list for fixtures
Added 0 tests to meet fixture requirements
Checking test dependency graph...
Checking test dependency graph end
test 74
    Start 74: test_n_nodes__rmw_zenoh_cpp

74: Test command: /usr/bin/python3 "-u" "/opt/ros/rolling/share/ament_cmake_test/cmake/run_test.py" "/workspace/build/test_rclcpp/test_results/test_rclcpp/test_n_nodes__rmw_zenoh_cpp.xunit.xml" "--package-name" "test_rclcpp" "--output-file" "/workspace/build/test_rclcpp/launch_test/test_n_nodes__rmw_zenoh_cpp.txt" "--env" "PYTHONDONTWRITEBYTECODE=1" "RMW_IMPLEMENTATION=rmw_zenoh_cpp" "--append-env" "LD_LIBRARY_PATH=/workspace/build/test_rclcpp" "--command" "/usr/bin/python3" "-m" "launch_testing.launch_test" "/workspace/build/test_rclcpp/test_n_nodes__rmw_zenoh_cpp_Release.py" "--junit-xml=/workspace/build/test_rclcpp/test_results/test_rclcpp/test_n_nodes__rmw_zenoh_cpp.xunit.xml" "--package-name=test_rclcpp"
74: Working Directory: /workspace/build/test_rclcpp
74: Test timeout computed to be: 60
74: -- run_test.py: extra environment variables:
74:  - PYTHONDONTWRITEBYTECODE=1
74:  - RMW_IMPLEMENTATION=rmw_zenoh_cpp
74: -- run_test.py: extra environment variables to append:
74:  - LD_LIBRARY_PATH+=/workspace/build/test_rclcpp
74: -- run_test.py: invoking following command in '/workspace/build/test_rclcpp':
74:  - /usr/bin/python3 -m launch_testing.launch_test /workspace/build/test_rclcpp/test_n_nodes__rmw_zenoh_cpp_Release.py --junit-xml=/workspace/build/test_rclcpp/test_results/test_rclcpp/test_n_nodes__rmw_zenoh_cpp.xunit.xml --package-name=test_rclcpp
74: [INFO] [launch]: All log files can be found below /home/ubuntu/.ros/log/2024-10-15-03-35-46-396754-nitro-an515-61430
74: [INFO] [launch]: Default logging verbosity is set to INFO
74: test_10_nodes (test_rclcpp.TestNNodes.test_10_nodes) ... [INFO] [node_with_name_0-1]: process started with pid [61434]
74: [INFO] [node_with_name_1-2]: process started with pid [61435]
74: [INFO] [node_with_name_2-3]: process started with pid [61436]
74: [INFO] [node_with_name_3-4]: process started with pid [61437]
74: [INFO] [node_with_name_4-5]: process started with pid [61438]
74: [INFO] [node_with_name_5-6]: process started with pid [61439]
74: [INFO] [node_with_name_6-7]: process started with pid [61440]
74: [INFO] [node_with_name_7-8]: process started with pid [61441]
74: [INFO] [node_with_name_8-9]: process started with pid [61442]
74: [INFO] [node_with_name_9-10]: process started with pid [61443]
74: [INFO] [node_check_names-11]: process started with pid [61444]
74: [node_with_name_0-1] [INFO] [1728963347.045792226] [rmw_zenoh_cpp]: Successfully connected to a Zenoh router with id d17196edff77c46c1b55801974c5c8e2.
74: [node_with_name_2-3] [INFO] [1728963347.052136533] [rmw_zenoh_cpp]: Successfully connected to a Zenoh router with id d17196edff77c46c1b55801974c5c8e2.
74: [node_with_name_1-2] [INFO] [1728963347.062232065] [rmw_zenoh_cpp]: Successfully connected to a Zenoh router with id d17196edff77c46c1b55801974c5c8e2.
74: [node_with_name_6-7] [INFO] [1728963347.066721450] [rmw_zenoh_cpp]: Successfully connected to a Zenoh router with id d17196edff77c46c1b55801974c5c8e2.
74: [node_with_name_7-8] [INFO] [1728963347.079107085] [rmw_zenoh_cpp]: Successfully connected to a Zenoh router with id d17196edff77c46c1b55801974c5c8e2.
74: [node_with_name_4-5] [INFO] [1728963347.096269317] [rmw_zenoh_cpp]: Successfully connected to a Zenoh router with id d17196edff77c46c1b55801974c5c8e2.
74: [node_with_name_3-4] [INFO] [1728963347.099423603] [rmw_zenoh_cpp]: Successfully connected to a Zenoh router with id d17196edff77c46c1b55801974c5c8e2.
74: [node_check_names-11] [INFO] [1728963347.101002624] [rmw_zenoh_cpp]: Successfully connected to a Zenoh router with id d17196edff77c46c1b55801974c5c8e2.
74: [node_with_name_5-6] [INFO] [1728963347.101107332] [rmw_zenoh_cpp]: Successfully connected to a Zenoh router with id d17196edff77c46c1b55801974c5c8e2.
74: [node_with_name_9-10] [INFO] [1728963347.105726692] [rmw_zenoh_cpp]: Successfully connected to a Zenoh router with id d17196edff77c46c1b55801974c5c8e2.
74: [node_with_name_8-9] [INFO] [1728963347.107766323] [rmw_zenoh_cpp]: Successfully connected to a Zenoh router with id d17196edff77c46c1b55801974c5c8e2.
74: FAIL
74:
74: ======================================================================
74: FAIL: test_10_nodes (test_rclcpp.TestNNodes.test_10_nodes)
74: ----------------------------------------------------------------------
74: Traceback (most recent call last):
74:   File "/workspace/build/test_rclcpp/test_n_nodes__rmw_zenoh_cpp_Release.py", line 48, in test_10_nodes
74:     proc_info.assertWaitForShutdown(checking_process, timeout=10)
74:   File "/opt/ros/rolling/lib/python3.12/site-packages/launch_testing/proc_info_handler.py", line 141, in assertWaitForShutdown
74:     assert success, "Timed out waiting for process '{}' to finish".format(process)
74:            ^^^^^^^
74: AssertionError: Timed out waiting for process '<launch.actions.execute_process.ExecuteProcess object at 0x773f824cee70>' to finish
74:
74: ----------------------------------------------------------------------
74: Ran 1 test in 10.002s
74:
74: FAILED (failures=1)
74: [INFO] [node_check_names-11]: sending signal 'SIGINT' to process[node_check_names-11]
74: [INFO] [node_with_name_9-10]: sending signal 'SIGINT' to process[node_with_name_9-10]
74: [INFO] [node_with_name_8-9]: sending signal 'SIGINT' to process[node_with_name_8-9]
74: [INFO] [node_with_name_7-8]: sending signal 'SIGINT' to process[node_with_name_7-8]
74: [INFO] [node_with_name_6-7]: sending signal 'SIGINT' to process[node_with_name_6-7]
74: [INFO] [node_with_name_5-6]: sending signal 'SIGINT' to process[node_with_name_5-6]
74: [INFO] [node_with_name_4-5]: sending signal 'SIGINT' to process[node_with_name_4-5]
74: [INFO] [node_with_name_3-4]: sending signal 'SIGINT' to process[node_with_name_3-4]
74: [INFO] [node_with_name_2-3]: sending signal 'SIGINT' to process[node_with_name_2-3]
74: [INFO] [node_with_name_1-2]: sending signal 'SIGINT' to process[node_with_name_1-2]
74: [INFO] [node_with_name_0-1]: sending signal 'SIGINT' to process[node_with_name_0-1]
74: [node_check_names-11] [INFO] [1728963356.419097723] [rclcpp]: signal_handler(signum=2)
74: [node_with_name_9-10] [INFO] [1728963356.420424001] [rclcpp]: signal_handler(signum=2)
74: [node_with_name_8-9] [INFO] [1728963356.421790459] [rclcpp]: signal_handler(signum=2)
74: [node_with_name_7-8] [INFO] [1728963356.424171428] [rclcpp]: signal_handler(signum=2)
74: [node_with_name_6-7] [INFO] [1728963356.425976036] [rclcpp]: signal_handler(signum=2)
74: [node_with_name_5-6] [INFO] [1728963356.428940533] [rclcpp]: signal_handler(signum=2)
74: [node_with_name_4-5] [ERROR] [1728963356.431654805] [rmw_zenoh_cpp]: topic name /parameter_events not found in topic_map. Report this.
74: [node_with_name_4-5] [INFO] [1728963356.431848551] [rclcpp]: signal_handler(signum=2)
74: [node_with_name_4-5] [ERROR] [1728963356.431882157] [rmw_zenoh_cpp]: topic name /parameter_events not found in topic_map. Report this.
74: [node_with_name_4-5] [ERROR] [1728963356.431941043] [rmw_zenoh_cpp]: topic name /node_with_name/list_parameters not found in topic_map. Report this.
74: [node_with_name_4-5] [ERROR] [1728963356.432087130] [rmw_zenoh_cpp]: topic name /node_with_name/get_type_description not found in topic_map. Report this.
74: [node_with_name_3-4] [INFO] [1728963356.432487293] [rclcpp]: signal_handler(signum=2)
74: [node_with_name_2-3] [INFO] [1728963356.434317720] [rclcpp]: signal_handler(signum=2)
74: [node_with_name_1-2] [INFO] [1728963356.435896330] [rclcpp]: signal_handler(signum=2)
74: [node_with_name_0-1] [INFO] [1728963356.437897800] [rclcpp]: signal_handler(signum=2)
74: [INFO] [node_with_name_9-10]: process has finished cleanly [pid 61443]
74: [INFO] [node_with_name_7-8]: process has finished cleanly [pid 61441]
74: [INFO] [node_with_name_8-9]: process has finished cleanly [pid 61442]
74: [INFO] [node_with_name_2-3]: process has finished cleanly [pid 61436]
74: [INFO] [node_with_name_0-1]: process has finished cleanly [pid 61434]
74: [ERROR] [node_check_names-11]: process[node_check_names-11] failed to terminate '5' seconds after receiving 'SIGINT', escalating to 'SIGTERM'
74: [ERROR] [node_with_name_6-7]: process[node_with_name_6-7] failed to terminate '5' seconds after receiving 'SIGINT', escalating to 'SIGTERM'
74: [ERROR] [node_with_name_5-6]: process[node_with_name_5-6] failed to terminate '5' seconds after receiving 'SIGINT', escalating to 'SIGTERM'
74: [ERROR] [node_with_name_4-5]: process[node_with_name_4-5] failed to terminate '5' seconds after receiving 'SIGINT', escalating to 'SIGTERM'
74: [ERROR] [node_with_name_3-4]: process[node_with_name_3-4] failed to terminate '5' seconds after receiving 'SIGINT', escalating to 'SIGTERM'
74: [ERROR] [node_with_name_1-2]: process[node_with_name_1-2] failed to terminate '5' seconds after receiving 'SIGINT', escalating to 'SIGTERM'
74: [INFO] [node_check_names-11]: sending signal 'SIGTERM' to process[node_check_names-11]
74: [INFO] [node_with_name_6-7]: sending signal 'SIGTERM' to process[node_with_name_6-7]
74: [INFO] [node_with_name_5-6]: sending signal 'SIGTERM' to process[node_with_name_5-6]
74: [INFO] [node_with_name_4-5]: sending signal 'SIGTERM' to process[node_with_name_4-5]
74: [INFO] [node_with_name_3-4]: sending signal 'SIGTERM' to process[node_with_name_3-4]
74: [INFO] [node_with_name_1-2]: sending signal 'SIGTERM' to process[node_with_name_1-2]
74: [node_check_names-11] [INFO] [1728963361.429203055] [rclcpp]: signal_handler(signum=15)
74: [node_with_name_6-7] [INFO] [1728963361.430711288] [rclcpp]: signal_handler(signum=15)
74: [node_with_name_5-6] [INFO] [1728963361.431947967] [rclcpp]: signal_handler(signum=15)
74: [node_with_name_4-5] [INFO] [1728963361.433184899] [rclcpp]: signal_handler(signum=15)
74: [node_with_name_3-4] [INFO] [1728963361.434370878] [rclcpp]: signal_handler(signum=15)
74: [node_with_name_1-2] [INFO] [1728963361.435685182] [rclcpp]: signal_handler(signum=15)
74: [ERROR] [node_check_names-11]: process[node_check_names-11] failed to terminate '10.0' seconds after receiving 'SIGTERM', escalating to 'SIGKILL'
74: [ERROR] [node_with_name_6-7]: process[node_with_name_6-7] failed to terminate '10.0' seconds after receiving 'SIGTERM', escalating to 'SIGKILL'
74: [ERROR] [node_with_name_5-6]: process[node_with_name_5-6] failed to terminate '10.0' seconds after receiving 'SIGTERM', escalating to 'SIGKILL'
74: [ERROR] [node_with_name_4-5]: process[node_with_name_4-5] failed to terminate '10.0' seconds after receiving 'SIGTERM', escalating to 'SIGKILL'
74: [ERROR] [node_with_name_3-4]: process[node_with_name_3-4] failed to terminate '10.0' seconds after receiving 'SIGTERM', escalating to 'SIGKILL'
74: [ERROR] [node_with_name_1-2]: process[node_with_name_1-2] failed to terminate '10.0' seconds after receiving 'SIGTERM', escalating to 'SIGKILL'
74: [INFO] [node_check_names-11]: sending signal 'SIGKILL' to process[node_check_names-11]
74: [INFO] [node_with_name_6-7]: sending signal 'SIGKILL' to process[node_with_name_6-7]
74: [INFO] [node_with_name_5-6]: sending signal 'SIGKILL' to process[node_with_name_5-6]
74: [INFO] [node_with_name_4-5]: sending signal 'SIGKILL' to process[node_with_name_4-5]
74: [ERROR] [node_check_names-11]: process has died [pid 61444, exit code -9, cmd '/workspace/build/test_rclcpp/node_check_names 10'].
74: [INFO] [node_with_name_3-4]: sending signal 'SIGKILL' to process[node_with_name_3-4]
74: [ERROR] [node_with_name_6-7]: process has died [pid 61440, exit code -9, cmd '/workspace/build/test_rclcpp/node_with_name'].
74: [ERROR] [node_with_name_5-6]: process has died [pid 61439, exit code -9, cmd '/workspace/build/test_rclcpp/node_with_name'].
74: [INFO] [node_with_name_1-2]: sending signal 'SIGKILL' to process[node_with_name_1-2]
74: [ERROR] [node_with_name_4-5]: process has died [pid 61438, exit code -9, cmd '/workspace/build/test_rclcpp/node_with_name'].
74: [ERROR] [node_with_name_3-4]: process has died [pid 61437, exit code -9, cmd '/workspace/build/test_rclcpp/node_with_name'].
74: [ERROR] [node_with_name_1-2]: process has died [pid 61435, exit code -9, cmd '/workspace/build/test_rclcpp/node_with_name'].
74: test_10_nodes (test_rclcpp.TestNNodesAfterShutdown.test_10_nodes) ... FAIL
74:
74: ======================================================================
74: FAIL: test_10_nodes (test_rclcpp.TestNNodesAfterShutdown.test_10_nodes)
74: ----------------------------------------------------------------------
74: Traceback (most recent call last):
74:   File "/workspace/build/test_rclcpp/test_n_nodes__rmw_zenoh_cpp_Release.py", line 55, in test_10_nodes
74:     launch_testing.asserts.assertExitCodes(
74:   File "/opt/ros/rolling/lib/python3.12/site-packages/launch_testing/asserts/assert_exit_codes.py", line 62, in assertExitCodes
74:     assert info.returncode in allowable_exit_codes, 'Proc {} exited with code {}'.format(
74:            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
74: AssertionError: Proc node_check_names-11 exited with code -9
74:
74: ----------------------------------------------------------------------
74: Ran 1 test in 0.000s
74:
74: FAILED (failures=1)
74: -- run_test.py: return code 1
74: -- run_test.py: verify result file '/workspace/build/test_rclcpp/test_results/test_rclcpp/test_n_nodes__rmw_zenoh_cpp.xunit.xml'
1/1 Test #74: test_n_nodes__rmw_zenoh_cpp ......***Failed   20.46 sec

0% tests passed, 1 tests failed out of 1

Label Time Summary:
launch_test    =  20.46 sec*proc (1 test)

Total Test time (real) =  20.47 sec

The following tests FAILED:
         74 - test_n_nodes__rmw_zenoh_cpp (Failed)
Errors while running CTest
Output from these tests are in: /workspace/build/test_rclcpp/Testing/Temporary/LastTest.log
Use "--rerun-failed --output-on-failure" to re-run the failed cases verbosely.
--- output: test_rclcpp
UpdateCTestConfiguration  from :/workspace/build/test_rclcpp/CTestConfiguration.ini
Parse Config file:/workspace/build/test_rclcpp/CTestConfiguration.ini
   Site: nitro-an515
   Build name: (empty)
 Add coverage exclude regular expressions.
Create new tag: 20241015-0335 - Experimental
UpdateCTestConfiguration  from :/workspace/build/test_rclcpp/CTestConfiguration.ini
Parse Config file:/workspace/build/test_rclcpp/CTestConfiguration.ini
Test project /workspace/build/test_rclcpp
Constructing a list of tests
Done constructing a list of tests
Updating test list for fixtures
Added 0 tests to meet fixture requirements
Checking test dependency graph...
Checking test dependency graph end
test 74
    Start 74: test_n_nodes__rmw_zenoh_cpp

74: Test command: /usr/bin/python3 "-u" "/opt/ros/rolling/share/ament_cmake_test/cmake/run_test.py" "/workspace/build/test_rclcpp/test_results/test_rclcpp/test_n_nodes__rmw_zenoh_cpp.xunit.xml" "--package-name" "test_rclcpp" "--output-file" "/workspace/build/test_rclcpp/launch_test/test_n_nodes__rmw_zenoh_cpp.txt" "--env" "PYTHONDONTWRITEBYTECODE=1" "RMW_IMPLEMENTATION=rmw_zenoh_cpp" "--append-env" "LD_LIBRARY_PATH=/workspace/build/test_rclcpp" "--command" "/usr/bin/python3" "-m" "launch_testing.launch_test" "/workspace/build/test_rclcpp/test_n_nodes__rmw_zenoh_cpp_Release.py" "--junit-xml=/workspace/build/test_rclcpp/test_results/test_rclcpp/test_n_nodes__rmw_zenoh_cpp.xunit.xml" "--package-name=test_rclcpp"
74: Working Directory: /workspace/build/test_rclcpp
74: Test timeout computed to be: 60
74: -- run_test.py: extra environment variables:
74:  - PYTHONDONTWRITEBYTECODE=1
74:  - RMW_IMPLEMENTATION=rmw_zenoh_cpp
74: -- run_test.py: extra environment variables to append:
74:  - LD_LIBRARY_PATH+=/workspace/build/test_rclcpp
74: -- run_test.py: invoking following command in '/workspace/build/test_rclcpp':
74:  - /usr/bin/python3 -m launch_testing.launch_test /workspace/build/test_rclcpp/test_n_nodes__rmw_zenoh_cpp_Release.py --junit-xml=/workspace/build/test_rclcpp/test_results/test_rclcpp/test_n_nodes__rmw_zenoh_cpp.xunit.xml --package-name=test_rclcpp
74: [INFO] [launch]: All log files can be found below /home/ubuntu/.ros/log/2024-10-15-03-35-46-396754-nitro-an515-61430
74: [INFO] [launch]: Default logging verbosity is set to INFO
74: test_10_nodes (test_rclcpp.TestNNodes.test_10_nodes) ... [INFO] [node_with_name_0-1]: process started with pid [61434]
74: [INFO] [node_with_name_1-2]: process started with pid [61435]
74: [INFO] [node_with_name_2-3]: process started with pid [61436]
74: [INFO] [node_with_name_3-4]: process started with pid [61437]
74: [INFO] [node_with_name_4-5]: process started with pid [61438]
74: [INFO] [node_with_name_5-6]: process started with pid [61439]
74: [INFO] [node_with_name_6-7]: process started with pid [61440]
74: [INFO] [node_with_name_7-8]: process started with pid [61441]
74: [INFO] [node_with_name_8-9]: process started with pid [61442]
74: [INFO] [node_with_name_9-10]: process started with pid [61443]
74: [INFO] [node_check_names-11]: process started with pid [61444]
74: [node_with_name_0-1] [INFO] [1728963347.045792226] [rmw_zenoh_cpp]: Successfully connected to a Zenoh router with id d17196edff77c46c1b55801974c5c8e2.
74: [node_with_name_2-3] [INFO] [1728963347.052136533] [rmw_zenoh_cpp]: Successfully connected to a Zenoh router with id d17196edff77c46c1b55801974c5c8e2.
74: [node_with_name_1-2] [INFO] [1728963347.062232065] [rmw_zenoh_cpp]: Successfully connected to a Zenoh router with id d17196edff77c46c1b55801974c5c8e2.
74: [node_with_name_6-7] [INFO] [1728963347.066721450] [rmw_zenoh_cpp]: Successfully connected to a Zenoh router with id d17196edff77c46c1b55801974c5c8e2.
74: [node_with_name_7-8] [INFO] [1728963347.079107085] [rmw_zenoh_cpp]: Successfully connected to a Zenoh router with id d17196edff77c46c1b55801974c5c8e2.
74: [node_with_name_4-5] [INFO] [1728963347.096269317] [rmw_zenoh_cpp]: Successfully connected to a Zenoh router with id d17196edff77c46c1b55801974c5c8e2.
74: [node_with_name_3-4] [INFO] [1728963347.099423603] [rmw_zenoh_cpp]: Successfully connected to a Zenoh router with id d17196edff77c46c1b55801974c5c8e2.
74: [node_check_names-11] [INFO] [1728963347.101002624] [rmw_zenoh_cpp]: Successfully connected to a Zenoh router with id d17196edff77c46c1b55801974c5c8e2.
74: [node_with_name_5-6] [INFO] [1728963347.101107332] [rmw_zenoh_cpp]: Successfully connected to a Zenoh router with id d17196edff77c46c1b55801974c5c8e2.
74: [node_with_name_9-10] [INFO] [1728963347.105726692] [rmw_zenoh_cpp]: Successfully connected to a Zenoh router with id d17196edff77c46c1b55801974c5c8e2.
74: [node_with_name_8-9] [INFO] [1728963347.107766323] [rmw_zenoh_cpp]: Successfully connected to a Zenoh router with id d17196edff77c46c1b55801974c5c8e2.
74: FAIL
74:
74: ======================================================================
74: FAIL: test_10_nodes (test_rclcpp.TestNNodes.test_10_nodes)
74: ----------------------------------------------------------------------
74: Traceback (most recent call last):
74:   File "/workspace/build/test_rclcpp/test_n_nodes__rmw_zenoh_cpp_Release.py", line 48, in test_10_nodes
74:     proc_info.assertWaitForShutdown(checking_process, timeout=10)
74:   File "/opt/ros/rolling/lib/python3.12/site-packages/launch_testing/proc_info_handler.py", line 141, in assertWaitForShutdown
74:     assert success, "Timed out waiting for process '{}' to finish".format(process)
74:            ^^^^^^^
74: AssertionError: Timed out waiting for process '<launch.actions.execute_process.ExecuteProcess object at 0x773f824cee70>' to finish
74:
74: ----------------------------------------------------------------------
74: Ran 1 test in 10.002s
74:
74: FAILED (failures=1)
74: [INFO] [node_check_names-11]: sending signal 'SIGINT' to process[node_check_names-11]
74: [INFO] [node_with_name_9-10]: sending signal 'SIGINT' to process[node_with_name_9-10]
74: [INFO] [node_with_name_8-9]: sending signal 'SIGINT' to process[node_with_name_8-9]
74: [INFO] [node_with_name_7-8]: sending signal 'SIGINT' to process[node_with_name_7-8]
74: [INFO] [node_with_name_6-7]: sending signal 'SIGINT' to process[node_with_name_6-7]
74: [INFO] [node_with_name_5-6]: sending signal 'SIGINT' to process[node_with_name_5-6]
74: [INFO] [node_with_name_4-5]: sending signal 'SIGINT' to process[node_with_name_4-5]
74: [INFO] [node_with_name_3-4]: sending signal 'SIGINT' to process[node_with_name_3-4]
74: [INFO] [node_with_name_2-3]: sending signal 'SIGINT' to process[node_with_name_2-3]
74: [INFO] [node_with_name_1-2]: sending signal 'SIGINT' to process[node_with_name_1-2]
74: [INFO] [node_with_name_0-1]: sending signal 'SIGINT' to process[node_with_name_0-1]
74: [node_check_names-11] [INFO] [1728963356.419097723] [rclcpp]: signal_handler(signum=2)
74: [node_with_name_9-10] [INFO] [1728963356.420424001] [rclcpp]: signal_handler(signum=2)
74: [node_with_name_8-9] [INFO] [1728963356.421790459] [rclcpp]: signal_handler(signum=2)
74: [node_with_name_7-8] [INFO] [1728963356.424171428] [rclcpp]: signal_handler(signum=2)
74: [node_with_name_6-7] [INFO] [1728963356.425976036] [rclcpp]: signal_handler(signum=2)
74: [node_with_name_5-6] [INFO] [1728963356.428940533] [rclcpp]: signal_handler(signum=2)
74: [node_with_name_4-5] [ERROR] [1728963356.431654805] [rmw_zenoh_cpp]: topic name /parameter_events not found in topic_map. Report this.
74: [node_with_name_4-5] [INFO] [1728963356.431848551] [rclcpp]: signal_handler(signum=2)
74: [node_with_name_4-5] [ERROR] [1728963356.431882157] [rmw_zenoh_cpp]: topic name /parameter_events not found in topic_map. Report this.
74: [node_with_name_4-5] [ERROR] [1728963356.431941043] [rmw_zenoh_cpp]: topic name /node_with_name/list_parameters not found in topic_map. Report this.
74: [node_with_name_4-5] [ERROR] [1728963356.432087130] [rmw_zenoh_cpp]: topic name /node_with_name/get_type_description not found in topic_map. Report this.
74: [node_with_name_3-4] [INFO] [1728963356.432487293] [rclcpp]: signal_handler(signum=2)
74: [node_with_name_2-3] [INFO] [1728963356.434317720] [rclcpp]: signal_handler(signum=2)
74: [node_with_name_1-2] [INFO] [1728963356.435896330] [rclcpp]: signal_handler(signum=2)
74: [node_with_name_0-1] [INFO] [1728963356.437897800] [rclcpp]: signal_handler(signum=2)
74: [INFO] [node_with_name_9-10]: process has finished cleanly [pid 61443]
74: [INFO] [node_with_name_7-8]: process has finished cleanly [pid 61441]
74: [INFO] [node_with_name_8-9]: process has finished cleanly [pid 61442]
74: [INFO] [node_with_name_2-3]: process has finished cleanly [pid 61436]
74: [INFO] [node_with_name_0-1]: process has finished cleanly [pid 61434]
74: [ERROR] [node_check_names-11]: process[node_check_names-11] failed to terminate '5' seconds after receiving 'SIGINT', escalating to 'SIGTERM'
74: [ERROR] [node_with_name_6-7]: process[node_with_name_6-7] failed to terminate '5' seconds after receiving 'SIGINT', escalating to 'SIGTERM'
74: [ERROR] [node_with_name_5-6]: process[node_with_name_5-6] failed to terminate '5' seconds after receiving 'SIGINT', escalating to 'SIGTERM'
74: [ERROR] [node_with_name_4-5]: process[node_with_name_4-5] failed to terminate '5' seconds after receiving 'SIGINT', escalating to 'SIGTERM'
74: [ERROR] [node_with_name_3-4]: process[node_with_name_3-4] failed to terminate '5' seconds after receiving 'SIGINT', escalating to 'SIGTERM'
74: [ERROR] [node_with_name_1-2]: process[node_with_name_1-2] failed to terminate '5' seconds after receiving 'SIGINT', escalating to 'SIGTERM'
74: [INFO] [node_check_names-11]: sending signal 'SIGTERM' to process[node_check_names-11]
74: [INFO] [node_with_name_6-7]: sending signal 'SIGTERM' to process[node_with_name_6-7]
74: [INFO] [node_with_name_5-6]: sending signal 'SIGTERM' to process[node_with_name_5-6]
74: [INFO] [node_with_name_4-5]: sending signal 'SIGTERM' to process[node_with_name_4-5]
74: [INFO] [node_with_name_3-4]: sending signal 'SIGTERM' to process[node_with_name_3-4]
74: [INFO] [node_with_name_1-2]: sending signal 'SIGTERM' to process[node_with_name_1-2]
74: [node_check_names-11] [INFO] [1728963361.429203055] [rclcpp]: signal_handler(signum=15)
74: [node_with_name_6-7] [INFO] [1728963361.430711288] [rclcpp]: signal_handler(signum=15)
74: [node_with_name_5-6] [INFO] [1728963361.431947967] [rclcpp]: signal_handler(signum=15)
74: [node_with_name_4-5] [INFO] [1728963361.433184899] [rclcpp]: signal_handler(signum=15)
74: [node_with_name_3-4] [INFO] [1728963361.434370878] [rclcpp]: signal_handler(signum=15)
74: [node_with_name_1-2] [INFO] [1728963361.435685182] [rclcpp]: signal_handler(signum=15)
74: [ERROR] [node_check_names-11]: process[node_check_names-11] failed to terminate '10.0' seconds after receiving 'SIGTERM', escalating to 'SIGKILL'
74: [ERROR] [node_with_name_6-7]: process[node_with_name_6-7] failed to terminate '10.0' seconds after receiving 'SIGTERM', escalating to 'SIGKILL'
74: [ERROR] [node_with_name_5-6]: process[node_with_name_5-6] failed to terminate '10.0' seconds after receiving 'SIGTERM', escalating to 'SIGKILL'
74: [ERROR] [node_with_name_4-5]: process[node_with_name_4-5] failed to terminate '10.0' seconds after receiving 'SIGTERM', escalating to 'SIGKILL'
74: [ERROR] [node_with_name_3-4]: process[node_with_name_3-4] failed to terminate '10.0' seconds after receiving 'SIGTERM', escalating to 'SIGKILL'
74: [ERROR] [node_with_name_1-2]: process[node_with_name_1-2] failed to terminate '10.0' seconds after receiving 'SIGTERM', escalating to 'SIGKILL'
74: [INFO] [node_check_names-11]: sending signal 'SIGKILL' to process[node_check_names-11]
74: [INFO] [node_with_name_6-7]: sending signal 'SIGKILL' to process[node_with_name_6-7]
74: [INFO] [node_with_name_5-6]: sending signal 'SIGKILL' to process[node_with_name_5-6]
74: [INFO] [node_with_name_4-5]: sending signal 'SIGKILL' to process[node_with_name_4-5]
74: [ERROR] [node_check_names-11]: process has died [pid 61444, exit code -9, cmd '/workspace/build/test_rclcpp/node_check_names 10'].
74: [INFO] [node_with_name_3-4]: sending signal 'SIGKILL' to process[node_with_name_3-4]
74: [ERROR] [node_with_name_6-7]: process has died [pid 61440, exit code -9, cmd '/workspace/build/test_rclcpp/node_with_name'].
74: [ERROR] [node_with_name_5-6]: process has died [pid 61439, exit code -9, cmd '/workspace/build/test_rclcpp/node_with_name'].
74: [INFO] [node_with_name_1-2]: sending signal 'SIGKILL' to process[node_with_name_1-2]
74: [ERROR] [node_with_name_4-5]: process has died [pid 61438, exit code -9, cmd '/workspace/build/test_rclcpp/node_with_name'].
74: [ERROR] [node_with_name_3-4]: process has died [pid 61437, exit code -9, cmd '/workspace/build/test_rclcpp/node_with_name'].
74: [ERROR] [node_with_name_1-2]: process has died [pid 61435, exit code -9, cmd '/workspace/build/test_rclcpp/node_with_name'].
74: test_10_nodes (test_rclcpp.TestNNodesAfterShutdown.test_10_nodes) ... FAIL
74:
74: ======================================================================
74: FAIL: test_10_nodes (test_rclcpp.TestNNodesAfterShutdown.test_10_nodes)
74: ----------------------------------------------------------------------
74: Traceback (most recent call last):
74:   File "/workspace/build/test_rclcpp/test_n_nodes__rmw_zenoh_cpp_Release.py", line 55, in test_10_nodes
74:     launch_testing.asserts.assertExitCodes(
74:   File "/opt/ros/rolling/lib/python3.12/site-packages/launch_testing/asserts/assert_exit_codes.py", line 62, in assertExitCodes
74:     assert info.returncode in allowable_exit_codes, 'Proc {} exited with code {}'.format(
74:            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
74: AssertionError: Proc node_check_names-11 exited with code -9
74:
74: ----------------------------------------------------------------------
74: Ran 1 test in 0.000s
74:
74: FAILED (failures=1)
74: -- run_test.py: return code 1
74: -- run_test.py: verify result file '/workspace/build/test_rclcpp/test_results/test_rclcpp/test_n_nodes__rmw_zenoh_cpp.xunit.xml'
1/1 Test #74: test_n_nodes__rmw_zenoh_cpp ......***Failed   20.46 sec

0% tests passed, 1 tests failed out of 1

Label Time Summary:
launch_test    =  20.46 sec*proc (1 test)

Total Test time (real) =  20.47 sec

The following tests FAILED:
         74 - test_n_nodes__rmw_zenoh_cpp (Failed)
Errors while running CTest
Output from these tests are in: /workspace/build/test_rclcpp/Testing/Temporary/LastTest.log
Use "--rerun-failed --output-on-failure" to re-run the failed cases verbosely.
---
--- stderr: test_rclcpp
Errors while running CTest
Output from these tests are in: /workspace/build/test_rclcpp/Testing/Temporary/LastTest.log
Use "--rerun-failed --output-on-failure" to re-run the failed cases verbosely.
---
Finished <<< test_rclcpp [20.5s]        [ with test failures ]

Summary: 1 package finished [21.2s]
  1 package had stderr output: test_rclcpp
  1 package had test failures: test_rclcpp

Analysis

This failure happens on the dev/1.0.0 and the rolling branches. The reason is

  • z_close is blocking at https://github.com/eclipse-zenoh/zenoh/blob/4fbe04ab8d27f4792da9d2460bf120694aec2877/io/zenoh-transport/src/unicast/universal/link.rs#L165 that the cancellation token fails to work.
  • Even if we comment out the wait of TaskTracker, say, we don't wait until the link is deleted. The test possibly fails with an exit code -2. The issue is caused by the flying undeclartions and queries to process. The container is contaminated.
@YuanYuYuan YuanYuYuan mentioned this issue Dec 5, 2024
Closed
@YuanYuYuan
Copy link
Contributor Author

@yellowhatter Please check if your PR can fix this issue. 😄

@YuanYuYuan YuanYuYuan changed the title [Test Failure] test_rclcpp / test_n_nodes__rmw_zenoh_cpp [Test Failure] test_rclcpp / test_n_nodes__rmw_zenoh_cpp deadlock Dec 5, 2024
This was referenced Dec 5, 2024
Merged
Open
@christophebedard christophebedard mentioned this issue Dec 9, 2024
Merged
@YuanYuYuan YuanYuYuan mentioned this issue Dec 11, 2024
Merged
@sloretz sloretz assigned sloretz and Yadunund and unassigned sloretz Dec 13, 2024
@YuanYuYuan
Copy link
Contributor Author

This failure seems to be resolved by #347.

@clalancette
Copy link
Collaborator

Yes, agreed, I also see that. Closing as we have now merged #347 in, thanks!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@Yadunund Yadunund

Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@clalancette @sloretz @YuanYuYuan @Yadunund