CI build job humble/testing failed!

[github-actions]

An automated scheduled build failed on master: https://github.com/ros-controls/ros2_control_ci/actions/runs/8134894075

[christophfroehlich]

Not sure why this failed.

There is a timeout of this assertion
https://github.com/ros-controls/ros2_control_ci/actions/runs/8119504060/job/22195468568#step:6:22777

https://github.com/ros-controls/gz_ros2_control/blob/ad76ddccc4b1b78f110202879bded5146670d109/gz_ros2_control_tests/tests/position_test.py#L123-L125

Let's see if it also fails with the next scheduled test.

[christophfroehlich]

@ahcorde do you have maybe an idea why the launch_test from ign_ros2_control fails here? The output contains the test string, but it times out.

[fmauch]

I can reproduce that locally. Will further debug this at a later point.

[christophfroehlich]

Really? How? I used act, and it succeeded.

[fmauch]

I created a new workspace, did

vcs import --input https://raw.githubusercontent.com/ros-controls/ros2_control_ci/master/ros_controls.humble.repos .

and ran

rosdep install --from-path . --ignore-src
colcon build --symlink-install --cmake-args   -DCMAKE_EXPORT_COMPILE_COMMANDS=1
source install/setup.zsh
colcon test --event-handlers console_direct+

[fmauch]

Well, actually, my traceback looks different:

9: xacro_file  /home/ubuntu/checkout/ros2_control_humble/colcon_ws/install/gz_ros2_control_tests/share/gz_ros2_control_tests/urdf/test_cart_position.xacro.urdf                                                                                                                                                             
9: [INFO] [launch]: All log files can be found below /home/ubuntu/.ros/log/2024-03-14-11-33-24-218648-jamy-71836                                                                                                                                                                                                            
9: [INFO] [launch]: Default logging verbosity is set to INFO                                                                                                                                                                                                                                                                
9: test_arm (gz_ros2_control_tests.TestFixture) ... [INFO] [ruby $(which ign) gazebo-1]: process started with pid [71839]                                                                                                                                                                                                   
9: [INFO] [create-2]: process started with pid [71841]                                                                                                                                                                                                                                                                      
9: [INFO] [robot_state_publisher-3]: process started with pid [71843]                                                                                                                                                                                                                                                       
9: [INFO] [python3-4]: process started with pid [71846]                                                                                                                                                                                                                                                                     
9: [robot_state_publisher-3] [INFO] [1710416004.339071300] [robot_state_publisher]: got segment cart                                                                                                                                                                                                                        
9: [robot_state_publisher-3] [INFO] [1710416004.339145184] [robot_state_publisher]: got segment slideBar                                                                                                                                                                                                                    
9: [robot_state_publisher-3] [INFO] [1710416004.339153758] [robot_state_publisher]: got segment world                                                                                                                                                                                                                       
9: [create-2] [INFO] [1710416004.352468729] [ros_gz_sim]: Requesting list of world names.                                                                                                                                                                                                                                   
9: [create-2] [INFO] [1710416004.569629871] [ros_gz_sim]: Requested creation of entity.                                                                                                                                                                                                                                     
9: [create-2] [INFO] [1710416004.569669428] [ros_gz_sim]: OK creation of entity.                                                                                                                                                                                                                                            
9: [INFO] [create-2]: process has finished cleanly [pid 71841]                                                                                                                                                                                                                                                              
9: [INFO] [ros2-5]: process started with pid [71904]                                                                                                                                                                                                                                                                        
9: [ros2-5] Error loading controller, check controller_manager logs                                                                                                                                                                                                                                                         
9: [ERROR] [ros2-5]: process has died [pid 71904, exit code 1, cmd 'ros2 control load_controller --set-state active joint_state_broadcaster'].                                                                                                                                                                              
9: [INFO] [ros2-6]: process started with pid [71924]                                                                                                                                                                                                                                                                        
9: [ruby $(which ign) gazebo-1] [Wrn] [SimulationRunner.cc:662] Found additional publishers on /stats, using namespaced stats topic only                                                                                                                                                                                    
9: [ruby $(which ign) gazebo-1] [Msg] Ignition Gazebo Server v6.16.0                                                                                                                                                                                                                                                        
9: [ruby $(which ign) gazebo-1] [Msg] Loading SDF world file[/usr/share/ignition/ignition-gazebo6/worlds/empty.sdf].                                                                                                                                                                                                        
9: [ruby $(which ign) gazebo-1] [Msg] Serving entity system service on [/entity/system/add]                                                                                                                                                                                                                                 
9: [ruby $(which ign) gazebo-1] [Dbg] [Physics.cc:804] Loaded [ignition::physics::dartsim::Plugin] from library [/usr/lib/x86_64-linux-gnu/ign-physics-5/engine-plugins/libignition-physics-dartsim-plugin.so]                                                                                                              
9: [ruby $(which ign) gazebo-1] [Dbg] [SystemManager.cc:70] Loaded system [gz::sim::systems::Physics] for entity [1]                                                                                                                                                                                                        
9: [ruby $(which ign) gazebo-1] [Msg] Create service on [/world/empty/create]                                                                                                                                                                                                                                               
9: [ruby $(which ign) gazebo-1] [Msg] Remove service on [/world/empty/remove]                                                                                                                                                                                                                                               
9: [ruby $(which ign) gazebo-1] [Msg] Pose service on [/world/empty/set_pose]                                                                                                                                                                                                                                               
9: [ruby $(which ign) gazebo-1] [Msg] Pose service on [/world/empty/set_pose_vector]                                                                                                                                                                                                                                        
9: [ruby $(which ign) gazebo-1] [Msg] Light configuration service on [/world/empty/light_config]                                                                                                                                                                                                                            
9: [ruby $(which ign) gazebo-1] [Msg] Physics service on [/world/empty/set_physics]                                                                                                                                                                                                                                         
9: [ruby $(which ign) gazebo-1] [Msg] SphericalCoordinates service on [/world/empty/set_spherical_coordinates]                                                                                                                                                                                                              
9: [ruby $(which ign) gazebo-1] [Msg] Enable collision service on [/world/empty/enable_collision]                                                                                                                                                                                                                           
9: [ruby $(which ign) gazebo-1] [Msg] Disable collision service on [/world/empty/disable_collision]                                                                                                                                                                                                                         
9: [ruby $(which ign) gazebo-1] [Msg] Material service on [/world/empty/visual_config]                                                                                                                                                                                                                                      
9: [ruby $(which ign) gazebo-1] [Msg] Material service on [/world/empty/wheel_slip]                                                                                                                                                                                                                                         
9: [ruby $(which ign) gazebo-1] [Dbg] [SystemManager.cc:70] Loaded system [gz::sim::systems::UserCommands] for entity [1]                                                                                                                                                                                                   
9: [ruby $(which ign) gazebo-1] [Dbg] [SystemManager.cc:70] Loaded system [gz::sim::systems::SceneBroadcaster] for entity [1]                                                                                                                                                                                               
9: [ruby $(which ign) gazebo-1] [Dbg] [SystemManager.cc:70] Loaded system [gz::sim::systems::Contact] for entity [1]                                                                                                                                                                                                        
9: [ruby $(which ign) gazebo-1] [Msg] Loaded level [3]                                                                                                                                                                                                                                                                      
9: [ruby $(which ign) gazebo-1] [Msg] Serving world controls on [/world/empty/control], [/world/empty/control/state] and [/world/empty/playback/control]                                                                                                                                                                    
9: [ruby $(which ign) gazebo-1] [Msg] Serving GUI information on [/world/empty/gui/info]                                                                                                                                                                                                                                    
9: [ruby $(which ign) gazebo-1] [Msg] World [empty] initialized with [1ms] physics profile.                                                                                                                                                                                                                                 
9: [ruby $(which ign) gazebo-1] [Msg] Serving world SDF generation service on [/world/empty/generate_world_sdf]                                                                                                                                                                                                             
9: [ruby $(which ign) gazebo-1] [Msg] Serving world names on [/gazebo/worlds]                                                                                                                                                                                                                                               
9: [ruby $(which ign) gazebo-1] [Msg] Resource path add service on [/gazebo/resource_paths/add].                                                                                                                                                                                                                            
9: [ruby $(which ign) gazebo-1] [Msg] Resource path get service on [/gazebo/resource_paths/get].                                                                                                                                                                                                                            
9: [ruby $(which ign) gazebo-1] [Msg] Resource path resolve service on [/gazebo/resource_paths/resolve].                                                                                                                                                                                                                    
9: [ruby $(which ign) gazebo-1] [Msg] Resource paths published on [/gazebo/resource_paths].                                                                                                                                                                                                                                 
9: [ruby $(which ign) gazebo-1] [Msg] Server control service on [/server_control].                                                                                                                                                                                                                                          
9: [ruby $(which ign) gazebo-1] [Dbg] [SimulationRunner.cc:664] Publishers [Address, Message Type]:                                                                                                                                                                                                                         
9: [ruby $(which ign) gazebo-1] [Wrn] [SimulationRunner.cc:695] Found additional publishers on /clock, using namespaced clock topic only                                                                                                                                                                                    
9: [ros2-6] Error loading controller, check controller_manager logs                                                                                                                                                                                                                                                         
9: [ERROR] [ros2-6]: process has died [pid 71924, exit code 1, cmd 'ros2 control load_controller --set-state active joint_trajectory_controller'].                                                                                                                                                                          
[Processing: gz_ros2_control_tests]                                                                                                                                                                                                                                                                                         
[Processing: gz_ros2_control_tests]                                                                                                                                                                                                                                                                                         
[Processing: gz_ros2_control_tests]                                                                                                                                                                                                                                                                                         
9: FAIL                                                                                                                                                                                                                                                                                                                     
9:                                                                                                                                                                                                                                                                                                                          
9: ======================================================================                                                                                                                                                                                                                                                   
9: FAIL: test_arm (gz_ros2_control_tests.TestFixture)                                                                                                                                                                                                                                                                       
9: ----------------------------------------------------------------------                                                                                                                                                                                                                                                   
9: Traceback (most recent call last):                                                                                                                                                                                                                                                                                       
9:   File "/home/ubuntu/checkout/ros2_control_humble/colcon_ws/src/ros-controls/gz_ros2_control/gz_ros2_control_tests/tests/position_test.py", line 123, in test_arm                                                                                                                                                        
9:     proc_output.assertWaitFor('Sucessfully loaded controller joint_trajectory_controller '                                                                                                                                                                                                                               
9:   File "/opt/ros/humble/lib/python3.10/site-packages/launch_testing/io_handler.py", line 146, in assertWaitFor                                                                                                                                                                                                           
9:     assert success, 'Waiting for output timed out'                                                                                                                                                                                                                                                                       
9: AssertionError: Waiting for output timed out                                                                                                                                                                                                                                                                             
9:                                                                                                                                                                                                                                                                                                                          
9: ----------------------------------------------------------------------                                                                                                                                                                                                                                                   
9: Ran 1 test in 100.001s

I'll try again using a fresh docker container and with running sequentially.

[fmauch]

I created a new docker container:

docker run -it --rm ros:humble

Inside the container I ran

apt update
apt dist-upgrade
rosdep update
mkdir -p colcon_ws/src
cd colcon_ws/src
vcs import --input https://raw.githubusercontent.com/ros-controls/ros2_control_ci/master/ros_controls.humble.repos .
rosdep install --from-path . --ignore-src -y
cd ..
colcon build --symlink-install --cmake-args   -DCMAKE_EXPORT_COMPILE_COMMANDS=1
source install/setup.bash
colcon test --event-handlers console_direct+ --packages-select ign_ros2_control ign_ros2_control_demos gz_ros2_control_tests

Result:

    Start 9: test_position_controller                                                                                                                                                                                                                                                                                                                                                                                                                                                                                     
                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                          
9: Test command: /usr/bin/python3 "-u" "/opt/ros/humble/share/ament_cmake_test/cmake/run_test.py" "/colcon_ws/build/gz_ros2_control_tests/test_results/gz_ros2_control_tests/test_position_controller.xunit.xml" "--package-name" "gz_ros2_control_tests" "--output-file" "/colcon_ws/build/gz_ros2_control_tests/launch_test/test_position_controller.txt" "--command" "/usr/bin/python3" "-m" "launch_testing.launch_test" "/colcon_ws/src/ros-controls/gz_ros2_control/gz_ros2_control_tests/tests/position_test.py" "-
-junit-xml=/colcon_ws/build/gz_ros2_control_tests/test_results/gz_ros2_control_tests/test_position_controller.xunit.xml" "--package-name=gz_ros2_control_tests"                                                                                                                                                                                                                                                                                                                                                           
9: Test timeout computed to be: 120                                                                                                                                                                                                                                                                                                                                                                                                                                                                                       
9: -- run_test.py: invoking following command in '/colcon_ws/build/gz_ros2_control_tests/tests':                                                                                                                                                                                                                                                                                                                                                                                                                          
9:  - /usr/bin/python3 -m launch_testing.launch_test /colcon_ws/src/ros-controls/gz_ros2_control/gz_ros2_control_tests/tests/position_test.py --junit-xml=/colcon_ws/build/gz_ros2_control_tests/test_results/gz_ros2_control_tests/test_position_controller.xunit.xml --package-name=gz_ros2_control_tests                                                                                                                                                                                                               
9: xacro_file  /colcon_ws/install/gz_ros2_control_tests/share/gz_ros2_control_tests/urdf/test_cart_position.xacro.urdf                                                                                                                                                                                                                                                                                                                                                                                                    
9: [INFO] [launch]: All log files can be found below /root/.ros/log/2024-03-14-11-56-06-019876-a6c3bfc60d62-34187                                                                                                                                                                                                                                                                                                                                                                                                         
9: [INFO] [launch]: Default logging verbosity is set to INFO                                                                                                                                                                                                                                                                                                                                                                                                                                                              
9: test_arm (gz_ros2_control_tests.TestFixture) ... [INFO] [ruby $(which ign) gazebo-1]: process started with pid [34189]                                                                                                                                                                                                                                                                                                                                                                                                 
9: [INFO] [create-2]: process started with pid [34191]                                                                                                                                                                                                                                                                                                                                                                                                                                                                    
9: [INFO] [robot_state_publisher-3]: process started with pid [34193]                                                                                                                                                                                                                                                                                                                                                                                                                                                     
9: [INFO] [python3-4]: process started with pid [34195]                                                                                                                                                                                                                                                                                                                                                                                                                                                                   
9: [robot_state_publisher-3] [INFO] [1710417366.120964905] [robot_state_publisher]: got segment cart                                                                                                                                                                                                                                                                                                                                                                                                                      
9: [robot_state_publisher-3] [INFO] [1710417366.121103810] [robot_state_publisher]: got segment slideBar                                                                                                                                                                                                                                                                                                                                                                                                                  
9: [robot_state_publisher-3] [INFO] [1710417366.121116942] [robot_state_publisher]: got segment world                                                                                                                                                                                                                                                                                                                                                                                                                     
9: [create-2] [INFO] [1710417366.130844815] [ros_gz_sim]: Requesting list of world names.                                                                                                                                                                                                                                                                                                                                                                                                                                 
9: [create-2] [INFO] [1710417366.552531779] [ros_gz_sim]: Requested creation of entity.                                                                                                                                                                                                                                                                                                                                                                                                                                   
9: [create-2] [INFO] [1710417366.552571706] [ros_gz_sim]: OK creation of entity.                                                                                                                                                                                                                                                                                                                                                                                                                                          
9: [INFO] [create-2]: process has finished cleanly [pid 34191]                                                                                                                                                                                                                                                                                                                                                                                                                                                            
9: [INFO] [ros2-5]: process started with pid [34253]                                                                                                                                                                                                                                                                                                                                                                                                                                                                      
9: [ruby $(which ign) gazebo-1] [Msg] Ignition Gazebo Server v6.16.0                                                                                                                                                                                                                                                                                                                                                                                                                                                      
9: [ruby $(which ign) gazebo-1] [Msg] Loading SDF world file[/usr/share/ignition/ignition-gazebo6/worlds/empty.sdf].                                                                                                                                                                                                                                                                                                                                                                                                      
9: [ruby $(which ign) gazebo-1] [Msg] Serving entity system service on [/entity/system/add]                                                                                                                                                                                                                                                                                                                                                                                                                               
9: [ruby $(which ign) gazebo-1] [Dbg] [Physics.cc:804] Loaded [ignition::physics::dartsim::Plugin] from library [/usr/lib/x86_64-linux-gnu/ign-physics-5/engine-plugins/libignition-physics-dartsim-plugin.so]                                                                                                                                                                                                                                                                                                            
9: [ruby $(which ign) gazebo-1] [Dbg] [SystemManager.cc:70] Loaded system [gz::sim::systems::Physics] for entity [1]                                                                                                                                                                                                                                                                                                                                                                                                      
9: [ruby $(which ign) gazebo-1] [Msg] Create service on [/world/empty/create]                                                                                                                                                                                                                                                                                                                                                                                                                                             
9: [ruby $(which ign) gazebo-1] [Msg] Remove service on [/world/empty/remove]                                                                                                                                                                                                                                                                                            
9: [ruby $(which ign) gazebo-1] [Msg] Pose service on [/world/empty/set_pose]                                                                                                                                                                                                                                                                                            
9: [ruby $(which ign) gazebo-1] [Msg] Pose service on [/world/empty/set_pose_vector]                                                                                                                                                                                                                                                                                     
9: [ruby $(which ign) gazebo-1] [Msg] Light configuration service on [/world/empty/light_config]                                                                                                                                                                                                                                                                         
9: [ruby $(which ign) gazebo-1] [Msg] Physics service on [/world/empty/set_physics]                                                                                                                                                                                                                                                                                      
9: [ruby $(which ign) gazebo-1] [Msg] SphericalCoordinates service on [/world/empty/set_spherical_coordinates]                                                                                                                                                                                                                                                           
9: [ruby $(which ign) gazebo-1] [Msg] Enable collision service on [/world/empty/enable_collision]                                                                                                                                                                                                                                                                        
9: [ruby $(which ign) gazebo-1] [Msg] Disable collision service on [/world/empty/disable_collision]                                                                                                                                                                                                                                                                      
9: [ruby $(which ign) gazebo-1] [Msg] Material service on [/world/empty/visual_config]                                                                                                                                                                                                                                                                                   
9: [ruby $(which ign) gazebo-1] [Msg] Material service on [/world/empty/wheel_slip]                                                                                                                                                                                                                                                                                      
9: [ruby $(which ign) gazebo-1] [Dbg] [SystemManager.cc:70] Loaded system [gz::sim::systems::UserCommands] for entity [1]                                                                                                                                                                                                                                                
9: [ruby $(which ign) gazebo-1] [Dbg] [SystemManager.cc:70] Loaded system [gz::sim::systems::SceneBroadcaster] for entity [1]                                                                                                                                                                                                                                            
9: [ruby $(which ign) gazebo-1] [Dbg] [SystemManager.cc:70] Loaded system [gz::sim::systems::Contact] for entity [1]                                                                                                                                                                                                                                                     
9: [ruby $(which ign) gazebo-1] [Msg] Loaded level [3]                                                                                                                                                                                                                                                                                                                   
9: [ruby $(which ign) gazebo-1] [Msg] Serving world controls on [/world/empty/control], [/world/empty/control/state] and [/world/empty/playback/control]                                                                                                                                                                                                                 
9: [ruby $(which ign) gazebo-1] [Msg] Serving GUI information on [/world/empty/gui/info]                                                                                                                                                                                                                                                                                 
9: [ruby $(which ign) gazebo-1] [Msg] World [empty] initialized with [1ms] physics profile.                                                                                                                                                                                                                                                                              
9: [ruby $(which ign) gazebo-1] [Msg] Serving world SDF generation service on [/world/empty/generate_world_sdf]                                                                                                                                                                                                                                                          
9: [ruby $(which ign) gazebo-1] [Msg] Serving world names on [/gazebo/worlds]                                                                                                                                                                                                                                                                                            
9: [ruby $(which ign) gazebo-1] [Msg] Resource path add service on [/gazebo/resource_paths/add].                                                                                                                                                                                                                                                                         
9: [ruby $(which ign) gazebo-1] [Msg] Resource path get service on [/gazebo/resource_paths/get].                                                                                                                                                                                                                                                                         
9: [ruby $(which ign) gazebo-1] [Msg] Resource path resolve service on [/gazebo/resource_paths/resolve].                                                                                                                                                                                                                                                                 
9: [ruby $(which ign) gazebo-1] [Msg] Resource paths published on [/gazebo/resource_paths].                                                                                                                                                                                                                                                                              
9: [ruby $(which ign) gazebo-1] [Msg] Server control service on [/server_control].                                                                                                                                                                                                                                                                                       
9: [ruby $(which ign) gazebo-1] [Msg] Found no publishers on /stats, adding root stats topic                                                                                                                                                                                                                                                                             
9: [ruby $(which ign) gazebo-1] [Msg] Found no publishers on /clock, adding root clock topic                                                                                                                                                                                                                                                                             
9: [ruby $(which ign) gazebo-1] [INFO] [1710417368.486834205] [gz_ros2_control]: [ign_ros2_control] Fixed joint [world_to_base] (Entity=17)] is skipped                                                                                                                                                                                                                  
9: [ruby $(which ign) gazebo-1] [INFO] [1710417368.489713584] [gz_ros2_control]: connected to service!! robot_state_publisher asking for robot_description                                                                                                                                                                                                               
9: [ruby $(which ign) gazebo-1] [INFO] [1710417368.490513804] [gz_ros2_control]: Received URDF from param server                                                                                                                                                                                                                                                         
9: [ruby $(which ign) gazebo-1] [WARN] [1710417368.532812557] [gz_ros2_control]: The position_proportional_gain parameter was not defined, defaulting to: 0.1                                                                                                                                                                                                            
9: [ruby $(which ign) gazebo-1] [INFO] [1710417368.532972562] [gz_ros2_control]: Loading joint: slider_to_cart                                                                                                                                                                                                                                                           
9: [ruby $(which ign) gazebo-1] [INFO] [1710417368.532998530] [gz_ros2_control]:        State:                                                                                                                                                                                                                                                                           
9: [ruby $(which ign) gazebo-1] [INFO] [1710417368.533010047] [gz_ros2_control]:                 position                                                                                                                                                                                                                                                                
9: [ruby $(which ign) gazebo-1] [INFO] [1710417368.533080648] [gz_ros2_control]:                         found initial value: 0.000000                                                                                                                                                                                                                                   
9: [ruby $(which ign) gazebo-1] [INFO] [1710417368.533090872] [gz_ros2_control]:                 velocity                                                                                                                                                                                                                                                                
9: [ruby $(which ign) gazebo-1] [INFO] [1710417368.533120742] [gz_ros2_control]:                 effort                                                                                                                                                                                                                                                                  
9: [ruby $(which ign) gazebo-1] [INFO] [1710417368.533137990] [gz_ros2_control]:        Command:                                                                                                                                                                                                                                                                         
9: [ruby $(which ign) gazebo-1] [INFO] [1710417368.533144244] [gz_ros2_control]:                 position                                                                                                                                                                                                                                                                
9: [ruby $(which ign) gazebo-1] [INFO] [1710417368.533729018] [resource_manager]: Initialize hardware 'IgnitionSystem'                                                                                                                                                                                                                                                   
9: [ruby $(which ign) gazebo-1] [WARN] [1710417368.533772206] [gz_ros2_control]: On init...                                                                                                                                                                                                                                                                              
9: [ruby $(which ign) gazebo-1] [INFO] [1710417368.534084994] [resource_manager]: Successful initialization of hardware 'IgnitionSystem'                                                                                                                                                                                                                                 
9: [ruby $(which ign) gazebo-1] [INFO] [1710417368.540174956] [resource_manager]: 'configure' hardware 'IgnitionSystem'                                                                                                                                                                                                                                                  
9: [ruby $(which ign) gazebo-1] [INFO] [1710417368.540230806] [gz_ros2_control]: System Successfully configured!                                                                                                                                                                                                                                                         
9: [ruby $(which ign) gazebo-1] [INFO] [1710417368.540261273] [resource_manager]: Successful 'configure' of hardware 'IgnitionSystem'                                                                                                                                                                                                                                    
9: [ruby $(which ign) gazebo-1] [INFO] [1710417368.540300664] [resource_manager]: 'activate' hardware 'IgnitionSystem'                                                                                                                                                                                                                                                   
9: [ruby $(which ign) gazebo-1] [INFO] [1710417368.540306402] [resource_manager]: Successful 'activate' of hardware 'IgnitionSystem'                                                                                                                                                                                                                                     
9: [ruby $(which ign) gazebo-1] [INFO] [1710417368.540316862] [gz_ros2_control]: Loading controller_manager                                                                                                                                                                                                                                                              
9: [ruby $(which ign) gazebo-1] [INFO] [1710417368.600194175] [controller_manager]: Loading controller 'joint_state_broadcaster'                                                                                                                                                                                                                                         
9: [ruby $(which ign) gazebo-1] [INFO] [1710417368.610437132] [controller_manager]: Configuring controller 'joint_state_broadcaster'                                                                                                                                                                                                                                     
9: [ruby $(which ign) gazebo-1] [INFO] [1710417368.610727738] [joint_state_broadcaster]: 'joints' or 'interfaces' parameter is empty. All available state interfaces will be published                                                                                                                                                                                   
9: [ros2-5] Successfully loaded controller joint_state_broadcaster into state active                                                                                                                                                                                                                                                                                     
9: [INFO] [ros2-5]: process has finished cleanly [pid 34253]                                                                                                                                                                                                                                                                                                             
9: [INFO] [ros2-6]: process started with pid [34293]                                                                                                                                                                                                                                                                                                                     
9: [ruby $(which ign) gazebo-1] [INFO] [1710417369.609735581] [controller_manager]: Loading controller 'joint_trajectory_controller'                                                                                                                                                                                                                                     
9: [ruby $(which ign) gazebo-1] [WARN] [1710417369.620761288] [joint_trajectory_controller]: [Deprecated]: "allow_nonzero_velocity_at_trajectory_end" is set to true. The default behavior will change to false.                                                                                                                                                         
9: [ruby $(which ign) gazebo-1] [INFO] [1710417369.622130635] [controller_manager]: Configuring controller 'joint_trajectory_controller'                                                                                                                                                                                                                                 
9: [ruby $(which ign) gazebo-1] [INFO] [1710417369.622319969] [joint_trajectory_controller]: No specific joint names are used for command interfaces. Using 'joints' parameter.                                                                                                                                                                                          
9: [ruby $(which ign) gazebo-1] [INFO] [1710417369.622577496] [joint_trajectory_controller]: Command interfaces are [position] and state interfaces are [position velocity].                                                                                                                                                                                             
9: [ruby $(which ign) gazebo-1] [INFO] [1710417369.622597576] [joint_trajectory_controller]: Using 'splines' interpolation method.                                                                                                                                                                                                                                       
9: [ruby $(which ign) gazebo-1] [INFO] [1710417369.625140889] [joint_trajectory_controller]: Controller state will be published at 50.00 Hz.                                                                                                                                                                                                                             
9: [ruby $(which ign) gazebo-1] [INFO] [1710417369.626722355] [joint_trajectory_controller]: Action status changes will be monitored at 20.00 Hz.                                                                                                                                                                                                                        
9: [ros2-6] Successfully loaded controller joint_trajectory_controller into state active                                                                                                                                                                                                                                                                                 
9: [INFO] [ros2-6]: process has finished cleanly [pid 34293]                                                                                                                                                                                                                                                                                                             
[Processing: gz_ros2_control_tests]                                                                                                                                                                                                                                                                                                                                      
[Processing: gz_ros2_control_tests]                                                                                                                                                                                                                                                                                                                                      
[Processing: gz_ros2_control_tests]                                                                                                                                                                                                                                                                                                                                      
9: FAIL                                                                                                                                                                                                                                                                                                                                                                  
9:                                                                                                                                                                                                                                                                                                                                                                       
9: ======================================================================                                                                                                                                                                                                                                                                                                
9: FAIL: test_arm (gz_ros2_control_tests.TestFixture)                                                                                                                                                                                                                                                                                                                    
9: ----------------------------------------------------------------------                                                                                                                                                                                                                                                                                                
9: Traceback (most recent call last):                                                                                                                                                                                                                                                                                                                                    
9:   File "/colcon_ws/src/ros-controls/gz_ros2_control/gz_ros2_control_tests/tests/position_test.py", line 123, in test_arm                                                                                                                                                                                                                                              
9:     proc_output.assertWaitFor('Sucessfully loaded controller joint_trajectory_controller '                                                                                                                                                                                                                                                                            
9:   File "/opt/ros/humble/lib/python3.10/site-packages/launch_testing/io_handler.py", line 146, in assertWaitFor                                                                                                                                                                                                                                                        
9:     assert success, 'Waiting for output timed out'                                                                         
9: AssertionError: Waiting for output timed out                                                                               
9:                                                                                                                            
9: ----------------------------------------------------------------------                                                     
9: Ran 1 test in 100.001s

---

Edit:

9: [ros2-6] Successfully loaded controller joint_trajectory_controller into state active
...
# failure:
9:     proc_output.assertWaitFor('Sucessfully loaded controller joint_trajectory_controller ' 

I guess, I'll call that a success... Still weird that this doesn't popup in the repo build.

[fmauch]

Has that been a recent fix?

---

Edit: Yep: ros-controls/ros2_control#1414

Case closed. :-)

[christophfroehlich]

Aaaaah, this was me :D I just haven't seen this difference.

[christophfroehlich]

Fixed!