:farmer: Windows and Linux timing out for some tests freezing without logs

[miguelgonrod]

launch_testing_examples pixi failure 4:36 hours

Reference Build

• https://ci.ros2.org/job/nightly_win_rel/3672

Log Output

09:00:12 --- stderr: launch_testing_examples
09:00:12 Traceback (most recent call last):
09:00:12   File "C:\pixi_ws\.pixi\envs\default\Lib\site-packages\colcon_core\executor\__init__.py", line 91, in __call__
09:00:12     rc = await self.task(*args, **kwargs)
09:00:12          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
09:00:12   File "C:\pixi_ws\.pixi\envs\default\Lib\site-packages\colcon_core\task\__init__.py", line 93, in __call__
09:00:15     return await task_method(*args, **kwargs)
09:00:22            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
09:00:24   File "C:\pixi_ws\.pixi\envs\default\Lib\site-packages\colcon_ros\task\ament_python\test.py", line 29, in test
09:00:35     return await extension.test()
09:00:36            ^^^^^^^^^^^^^^^^^^^^^^
09:00:37   File "C:\pixi_ws\.pixi\envs\default\Lib\site-packages\colcon_core\task\python\test\__init__.py", line 42, in test
09:00:38     setup_py_data = get_setup_data(self.context.pkg, env)
09:00:45                     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
09:00:45   File "C:\pixi_ws\.pixi\envs\default\Lib\site-packages\colcon_core\task\python\__init__.py", line 20, in get_setup_data
09:00:45     return dict(pkg.metadata[key](env))
09:00:45                 ^^^^^^^^^^^^^^^^^^^^^^
09:00:45   File "C:\pixi_ws\.pixi\envs\default\Lib\site-packages\colcon_ros\package_augmentation\ros_ament_python.py", line 57, in getter
09:00:45     return get_setup_information(
09:00:45            ^^^^^^^^^^^^^^^^^^^^^^
09:00:45   File "C:\pixi_ws\.pixi\envs\default\Lib\site-packages\colcon_python_setup_py\package_identification\python_setup_py.py", line 249, in get_setup_information
09:00:45     _setup_information_cache[hashable_env] = _get_setup_information(
09:00:45                                              ^^^^^^^^^^^^^^^^^^^^^^^
09:00:45   File "C:\pixi_ws\.pixi\envs\default\Lib\site-packages\colcon_python_setup_py\package_identification\python_setup_py.py", line 296, in _get_setup_information
09:00:45     result = subprocess.run(
09:00:45              ^^^^^^^^^^^^^^^
09:00:45   File "C:\pixi_ws\.pixi\envs\default\Lib\subprocess.py", line 571, in run
09:00:45     raise CalledProcessError(retcode, process.args,
09:00:45 subprocess.CalledProcessError: Command '['C:\\pixi_ws\\.pixi\\envs\\default\\python.exe', '-c', 'import sys;from contextlib import suppress;exec("with suppress(ImportError):    from setuptools.extern.packaging.specifiers    import SpecifierSet");exec("with suppress(ImportError):    from packaging.specifiers import SpecifierSet");from distutils.core import run_setup;dist = run_setup(    \'setup.py\', script_args=(\'--dry-run\',), stop_after=\'config\');skip_keys = (\'cmdclass\', \'distclass\', \'ext_modules\', \'metadata\');data = {    key: value for key, value in dist.__dict__.items()     if (        not key.startswith(\'_\') and         not callable(value) and         key not in skip_keys and         key not in dist.display_option_names    )};data[\'metadata\'] = {    k: v for k, v in dist.metadata.__dict__.items()     if k not in (\'license_files\', \'provides_extras\')};sys.stdout.buffer.write(repr(data).encode(\'utf-8\'))']' returned non-zero exit status 3221225794.
09:01:03 ---
09:01:03 Failed   <<< launch_testing_examples [4h 36min 17s, exited with code 1]

launch_testing_ros freezing for several hours

Reference Build

• https://ci.ros2.org/job/nightly_linux-rhel_debug/2567
• https://ci.ros2.org/job/nightly_linux-aarch64_debug/3441
• https://ci.ros2.org/job/nightly_win_rep/3966
• https://ci.ros2.org/job/nightly_linux-rhel_debug/2546
• https://ci.ros2.org/job/nightly_linux-rhel_release/2521/console
• https://ci.ros2.org/job/nightly_linux-rhel_debug/2543
• https://ci.ros2.org/job/nightly_linux-rhel_debug/2542
• https://ci.ros2.org/job/nightly_linux-aarch64_debug/3424
• https://ci.ros2.org/job/nightly_linux-aarch64_debug/3419
• https://ci.ros2.org/job/nightly_linux-rhel_debug/2538
• https://ci.ros2.org/job/nightly_linux-rhel_repeated/2514
• https://ci.ros2.org/job/nightly_linux-rhel_repeated/2513
• https://ci.ros2.org/job/nightly_linux-rhel_release/2514
• https://ci.ros2.org/job/nightly_linux-aarch64_debug/3416
• https://ci.ros2.org/job/nightly_linux-aarch64_release/3390

Log Output

10:29:32 [Processing: launch_testing_ros]
10:30:02 [Processing: launch_testing_ros]
10:30:32 [Processing: launch_testing_ros]
...

There is no output explaining the launch_testing_ros problem, maybe with verbose or adding additional logging to this package?

test_ros2trace freezing for several hours

Build Reference

• https://ci.ros2.org/job/nightly_win_rel/3669

Log output

test_ros2trace
Starting >>> test_ros2trace
Build timed out (after 600 minutes). Marking the build as aborted.

Same as Before, maybe with verbose or additional logging

Note

looking up to https://ci.ros2.org/job/nightly_win_rel/3652 I found this message, maybe can give us an insight

test_ros2trace (stderr)
09:39:57 --- stderr: test_ros2trace
09:39:57 System 'Windows' does not support LTTng.
09:39:57 
09:39:57 Cannot trace. See documentation at: https://github.com/ros2/ros2_tracing
09:39:57 
09:39:57 System 'Windows' does not support LTTng.
09:39:57 
09:39:57 Cannot trace. See documentation at: https://github.com/ros2/ros2_tracing
09:39:57 
09:39:57 System 'Windows' does not support LTTng.
09:39:57 
09:39:57 Cannot trace. See documentation at: https://github.com/ros2/ros2_tracing
09:39:57 
09:39:57 System 'Windows' does not support LTTng.
09:39:57 
09:39:57 Cannot trace. See documentation at: https://github.com/ros2/ros2_tracing
09:39:57 
09:39:57 System 'Windows' does not support LTTng.
09:39:57 
09:39:57 Cannot trace. See documentation at: https://github.com/ros2/ros2_tracing
09:39:57 
09:39:57 System 'Windows' does not support LTTng.
09:39:57 
09:39:57 Cannot trace. See documentation at: https://github.com/ros2/ros2_tracing
09:39:57 
09:39:57 
09:39:57 
09:39:57 ============================== warnings summary ===============================
09:39:57 
09:39:57 test_ros2trace/test/test_flake8.py::test_flake8
09:39:57 
09:39:57   Warning: pkg_resources is deprecated as an API. See https://setuptools.pypa.io/en/latest/pkg_resources.html
09:39:57 
09:39:57 
09:39:57 
09:39:57 -- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html
09:39:57 
09:39:57 ---
09:39:57 Finished <<< test_ros2trace [4h 9min 59s]

launch_testing_examples, rosbag2_examples_cpp, rosbag2_examples_py and rqt_bag_plugins freezing for several hours

Reference Build

• https://ci.ros2.org/job/nightly_win_rep/3969

Log Output

.....
08:48:30 [Processing: launch_testing_examples, rosbag2_examples_cpp, rosbag2_examples_py, rqt_bag_plugins]
08:48:30 [Processing: launch_testing_examples, rosbag2_examples_cpp, rosbag2_examples_py, rqt_bag_plugins]
08:48:30 [Processing: launch_testing_examples, rosbag2_examples_cpp, rosbag2_examples_py, rqt_bag_plugins]
08:48:30 [Processing: launch_testing_examples, rosbag2_examples_cpp, rosbag2_examples_py, rqt_bag_plugins]
08:48:30 [Processing: launch_testing_examples, rosbag2_examples_cpp, rosbag2_examples_py, rqt_bag_plugins]
08:48:30 [Processing: launch_testing_examples, rosbag2_examples_cpp, rosbag2_examples_py, rqt_bag_plugins]
09:00:06 Build timed out (after 600 minutes). Marking the build as aborted.

Same as the two before this one

intra_process_demo freezing for several hours

Reference Builds

• https://ci.ros2.org/job/nightly_win_rel/3656

log Output

intra_process_demo
08:22:35 Starting >>> intra_process_demo
09:00:07 Build timed out (after 600 minutes). Marking the build as aborted.

This is pretty similar as test_ros2trace

rqt_publisher, rqt_py_console, rqt_service_caller, rqt_shell Freezing for several hours

Reference Build

• https://ci.ros2.org/job/nightly_win_rel/3653

Log Output

09:00:58 [Processing: rqt_publisher, rqt_py_console, rqt_service_caller, rqt_shell]
09:00:58 [Processing: rqt_publisher, rqt_py_console, rqt_service_caller, rqt_shell]
[Processing: rqt_publisher, rqt_py_console, rqt_service_caller, rqt_shell]
[Processing: rqt_publisher, rqt_py_console, rqt_service_caller, rqt_shell]
[Processing: rqt_publisher, rqt_py_console, rqt_service_caller, rqt_shell]
[Processing: rqt_publisher, rqt_py_console, rqt_service_caller, rqt_shell]
Build timed out (after 600 minutes). Marking the build as aborted.

test_tracetools_launch freezing after several hours

Reference Build

• https://ci.ros2.org/job/nightly_linux-aarch64_repeated/3400
• https://ci.ros2.org/job/nightly_linux-aarch64_release/3386
• https://ci.ros2.org/job/nightly_linux-rhel_release/2505
• https://ci.ros2.org/job/nightly_linux-rhel_release/2500

Log Output

09:11:03 [Processing: test_tracetools_launch]
09:11:33 [Processing: test_tracetools_launch]
09:12:03 [Processing: test_tracetools_launch]
09:12:33 [Processing: test_tracetools_launch]
09:13:03 [Processing: test_tracetools_launch]
09:13:33 [Processing: test_tracetools_launch]
09:14:03 [Processing: test_tracetools_launch]
....

ros2component, rqt_topic freezing after several hours

Build Reference

• https://ci.ros2.org/job/nightly_win_rel/3642

Log Output

......
05:59:39 [Processing: ros2component, rqt_topic]
05:59:39 [Processing: ros2component, rqt_topic]
05:59:39 [Processing: ros2component, rqt_topic]
05:59:39 [Processing: ros2component, rqt_topic]
05:59:39 [Processing: ros2component, rqt_topic]
05:59:39 [Processing: ros2component, rqt_topic]
05:59:39 [Processing: ros2component, rqt_topic]
07:34:30 Build was aborted

Have to say this happened some time ago and hasn't happened again

• https://ci.ros2.org/job/nightly_win_rel/3652/console This got timeout because test_ros2trace used almost all the time, so the last process didn't had enought time to finish

To Investigate

• https://ci.ros2.org/job/nightly_win_rep/3970
• https://ci.ros2.org/job/nightly_win_rep/3955
• https://ci.ros2.org/job/nightly_win_rep/3954/ and https://ci.ros2.org/job/nightly_win_rel/3646

Data and Hypothesis

• The packages that are failing the most are launch_testing_ros for 15 builds and test_tracetools_launch for 4 builds.
• We can check test_ros2 trace as we have a posible cause, and this could help reduce the test time for the other builds.

Number of fails

Fail Name	Failed Builds count
launch_testing_examples pixi	1
launch_testing_ros	15
test_ros2trace	1
launch_testing_examples, rosbag2_examples_cpp, rosbag2_examples_py and rqt_bag_plugins	1
intra_process_demo	1
rqt_publisher, rqt_py_console, rqt_service_caller, rqt_shell	1
test_tracetools_launch	4
ros2component, rqt_topic	1

CC: @Crola1702