test_load_composable_nodes.py flaky on Windows

[Blast545]

Bug report

Required Info:

• Operating System:
  • Windows
• Installation type:
  • Source, buildfar
• Version or commit hash:
  • main
• DDS implementation:
  • N/A
• Client library (if applicable):
  • rclpy

Steps to reproduce issue

Run a Windows Buildfarm job. nightly_win_rep shows the problem almost reliably, it has happened about 3 times each 14 jobs in the nightly_win_deb and nightly_win_rel jobs.

Expected behavior

All tests pass.

Actual behavior

This test fails:
https://ci.ros2.org/view/nightly/job/nightly_win_deb/2332/testReport/junit/test_launch_ros.test.test_launch_ros.actions/test_load_composable_nodes/test_load_node_with_param_file/

Additional information

The first time this test failed was about three months ago.
https://ci.ros2.org/view/nightly/job/nightly_win_rep/2505/#showFailuresLink

This is the test failing:
https://github.com/ros2/launch_ros/blob/master/test_launch_ros/test/test_launch_ros/actions/test_load_composable_nodes.py#L353

Is there a ROS2 guarantee that these nodes will be queried in a specified order here?

launch_ros/test_launch_ros/test/test_launch_ros/actions/test_load_composable_nodes.py

Line 351 in d3970e5

request = mock_component_container.requests[-2]

[sloretz]

Is there a ROS2 guarantee that these nodes will be queried in a specified order here?

It looks like launch called the load_node service for the second node before the first node, despite the action for the first node coming first. I'm checking the code to see if that's expected or not.

[DEBUG] [launch_ros.actions.load_composable_nodes]: Calling the '/mock_component_container/_container/load_node' service with request 'composition_interfaces.srv.LoadNode_Request(package_name='foo_package', plugin_name='bar_plugin', node_name='node_2', node_namespace='/ns_2', log_level=0, remap_rules=[], parameters=[rcl_interfaces.msg.Parameter(name='param_2', value=rcl_interfaces.msg.ParameterValue(type=2, bool_value=False, integer_value=22, double_value=0.0, string_value='', byte_array_value=[], bool_array_value=[], integer_array_value=[], double_array_value=[], string_array_value=[])), rcl_interfaces.msg.Parameter(name='param_3', value=rcl_interfaces.msg.ParameterValue(type=2, bool_value=False, integer_value=3, double_value=0.0, string_value='', byte_array_value=[], bool_array_value=[], integer_array_value=[], double_array_value=[], string_array_value=[]))], extra_arguments=[])'
[DEBUG] [launch_ros.actions.load_composable_nodes]: Calling the '/mock_component_container/_container/load_node' service with request 'composition_interfaces.srv.LoadNode_Request(package_name='foo_package', plugin_name='bar_plugin', node_name='node_1', node_namespace='/ns_1', log_level=0, remap_rules=[], parameters=[rcl_interfaces.msg.Parameter(name='param_2', value=rcl_interfaces.msg.ParameterValue(type=2, bool_value=False, integer_value=2, double_value=0.0, string_value='', byte_array_value=[], bool_array_value=[], integer_array_value=[], double_array_value=[], string_array_value=[])), rcl_interfaces.msg.Parameter(name='param_3', value=rcl_interfaces.msg.ParameterValue(type=2, bool_value=False, integer_value=33, double_value=0.0, string_value='', byte_array_value=[], bool_array_value=[], integer_array_value=[], double_array_value=[], string_array_value=[])), rcl_interfaces.msg.Parameter(name='param_1', value=rcl_interfaces.msg.ParameterValue(type=2, bool_value=False, integer_value=1, double_value=0.0, string_value='', byte_array_value=[], bool_array_value=[], integer_array_value=[], double_array_value=[], string_array_value=[]))], extra_arguments=[])'
[DEBUG] [launch_ros.actions.load_composable_nodes]: Received response 'composition_interfaces.srv.LoadNode_Response(success=True, error_message='', full_node_name='/ns_2/node_2', unique_id=6)'
[DEBUG] [launch_ros.actions.load_composable_nodes]: Received response 'composition_interfaces.srv.LoadNode_Response(success=True, error_message='', full_node_name='/ns_1/node_1', unique_id=7)'

Log statements look like they come from

launch_ros/launch_ros/launch_ros/actions/load_composable_nodes.py

Line 135 in d3970e5

self.__logger.debug(

and

launch_ros/launch_ros/launch_ros/actions/load_composable_nodes.py

Line 158 in d3970e5

self.__logger.debug("Received response '{}'".format(response))