Skip to content

CI build job kilted/testing failed! #341

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
Open
github-actions bot opened this issue May 25, 2025 · 1 comment
Open

CI build job kilted/testing failed! #341

github-actions bot opened this issue May 25, 2025 · 1 comment
Labels
CI

Comments

@github-actions
Copy link
Contributor

github-actions bot commented May 25, 2025 •
edited
Loading

An automated scheduled build failed on master: https://github.com/ros-controls/ros2_control_ci/actions/runs/15574899659
@github-actions github-actions bot added the CI label May 25, 2025
@christophfroehlich
Copy link
Contributor

The test ended before the system was launched successfully, why? Timeout of check_controllers_running should be 10s, this might be too short for gz tests

2025-05-25T04:06:07.3933754Z   <<< failure message
2025-05-25T04:06:07.3934077Z     -- run_test.py: extra environment variables:
2025-05-25T04:06:07.3934479Z      - PYTHONDONTWRITEBYTECODE=1
2025-05-25T04:06:07.3935306Z     -- run_test.py: invoking following command in '/home/runner/work/ros2_control_ci/ros2_control_ci/.work/target_ws/build/gz_ros2_control_tests/tests':
2025-05-25T04:06:07.3937891Z      - /usr/bin/python3 -m launch_testing.launch_test /home/runner/work/ros2_control_ci/ros2_control_ci/.work/target_ws/src/ros-controls/gz_ros2_control/gz_ros2_control_tests/tests/velocity_test.py --junit-xml=/home/runner/work/ros2_control_ci/ros2_control_ci/.work/target_ws/build/gz_ros2_control_tests/test_results/gz_ros2_control_tests/tests_velocity_test.py.xunit.xml --package-name=gz_ros2_control_tests
2025-05-25T04:06:07.3940445Z     [INFO] [launch]: All log files can be found below /root/.ros/log/2025-05-25-04-05-41-363111-f3dcb04c4b7d-57011
2025-05-25T04:06:07.3941156Z     [INFO] [launch]: Default logging verbosity is set to INFO
2025-05-25T04:06:07.3941857Z     test_arm (gz_ros2_control_tests.TestFixture.test_arm) ... [INFO] [gazebo-1]: process started with pid [57031]
2025-05-25T04:06:07.3942575Z     [INFO] [parameter_bridge-2]: process started with pid [57032]
2025-05-25T04:06:07.3943113Z     [INFO] [robot_state_publisher-3]: process started with pid [57033]
2025-05-25T04:06:07.3943764Z     [INFO] [create-4]: process started with pid [57035]
2025-05-25T04:06:07.3944205Z     [INFO] [python3-5]: process started with pid [57037]
2025-05-25T04:06:07.3944775Z     [create-4] [INFO] [1748145941.872306740] [ros_gz_sim]: Requesting list of world names.
2025-05-25T04:06:07.3945807Z     [parameter_bridge-2] [INFO] [1748145941.892059997] [ros_gz_bridge]: Creating GZ->ROS Bridge: [/clock (gz.msgs.Clock) -> /clock (rosgraph_msgs/msg/Clock)] (Lazy 0)
2025-05-25T04:06:07.3946881Z     [robot_state_publisher-3] [INFO] [1748145941.912983384] [robot_state_publisher]: Robot initialized
2025-05-25T04:06:07.3947720Z     [create-4] [INFO] [1748145942.358652941] [ros_gz_sim]: Waiting messages on topic [robot_description].
2025-05-25T04:06:07.3948490Z     [create-4] [INFO] [1748145942.370005704] [ros_gz_sim]: Entity creation successful.
2025-05-25T04:06:07.3949135Z     [INFO] [create-4]: process has finished cleanly [pid 57035]
2025-05-25T04:06:07.3949660Z     [INFO] [spawner-6]: process started with pid [57116]
2025-05-25T04:06:07.3950668Z     [spawner-6] [INFO] [1748145942.751656941] [spawner_joint_state_broadcaster]: waiting for service /controller_manager/list_controllers to become available...
2025-05-25T04:06:07.3951945Z     [gazebo-1] [INFO] [1748145944.199430867] [gz_ros_control]: [gz_ros2_control] Fixed joint [world_to_base] (Entity=20)] is skipped
2025-05-25T04:06:07.3952866Z     [gazebo-1] [INFO] [1748145944.205185125] [gz_ros_control]: Loading controller_manager
2025-05-25T04:06:07.3953949Z     [gazebo-1] [INFO] [1748145944.224828825] [controller_manager]: Using ROS clock for triggering controller manager cycles.
2025-05-25T04:06:07.3955204Z     [gazebo-1] [INFO] [1748145944.231002481] [controller_manager]: Subscribing to '/robot_description' topic for robot description.
2025-05-25T04:06:07.3956294Z     [gazebo-1] [INFO] [1748145944.233900704] [controller_manager]: Enforcing command limits is enabled...
2025-05-25T04:06:07.3957216Z     [gazebo-1] [WARN] [1748145944.234025339] [gz_ros_control]: Waiting RM to load and initialize hardware...
2025-05-25T04:06:07.3958298Z     [gazebo-1] [INFO] [1748145944.375104521] [controller_manager]: Received robot description from topic.
2025-05-25T04:06:07.3959698Z     [gazebo-1] [INFO] [1748145944.380220500] [gz_ros_control.resource_manager]: Using JointLimiter for joint 'slider_to_cart' in hardware 'GazeboSimSystem' : '  has position limits: true [-15, 15]
2025-05-25T04:06:07.3960830Z     [gazebo-1]   has velocity limits: true [15]
2025-05-25T04:06:07.3961288Z     [gazebo-1]   has acceleration limits: false [nan]
2025-05-25T04:06:07.3961769Z     [gazebo-1]   has deceleration limits: false [nan]
2025-05-25T04:06:07.3962228Z     [gazebo-1]   has jerk limits: false [nan]
2025-05-25T04:06:07.3962646Z     [gazebo-1]   has effort limits: true [1000]
2025-05-25T04:06:07.3963056Z     [gazebo-1]   angle wraparound: false'
2025-05-25T04:06:07.3964206Z     [gazebo-1] [INFO] [1748145944.380276095] [gz_ros_control.resource_manager]: Creating JointSaturationLimiter for joint 'slider_to_cart' in hardware 'GazeboSimSystem'
2025-05-25T04:06:07.3965521Z     [gazebo-1] [INFO] [1748145944.386993962] [gz_ros_control]: The position_proportional_gain has been set to: 0.1
2025-05-25T04:06:07.3966518Z     [gazebo-1] [INFO] [1748145944.387487219] [gz_ros_control]: Loading joint: slider_to_cart
2025-05-25T04:06:07.3967184Z     [gazebo-1] [INFO] [1748145944.387527635] [gz_ros_control]: 	State:
2025-05-25T04:06:07.3967860Z     [gazebo-1] [INFO] [1748145944.387545168] [gz_ros_control]: 		 position
2025-05-25T04:06:07.3968559Z     [gazebo-1] [INFO] [1748145944.387686974] [gz_ros_control]: 			 found initial value: 1.000000
2025-05-25T04:06:07.3969247Z     [gazebo-1] [INFO] [1748145944.387714746] [gz_ros_control]: 		 velocity
2025-05-25T04:06:07.3969854Z     [gazebo-1] [INFO] [1748145944.387908059] [gz_ros_control]: 		 effort
2025-05-25T04:06:07.3970444Z     [gazebo-1] [INFO] [1748145944.387949668] [gz_ros_control]: 	Command:
2025-05-25T04:06:07.3971047Z     [gazebo-1] [INFO] [1748145944.387967130] [gz_ros_control]: 		 velocity
2025-05-25T04:06:07.3971753Z     [gazebo-1] [INFO] [1748145944.389464964] [gz_ros_control]: Loading sensor: cart_imu_sensor
2025-05-25T04:06:07.3972460Z     [gazebo-1] [INFO] [1748145944.389501482] [gz_ros_control]: 	State:
2025-05-25T04:06:07.3973059Z     [gazebo-1] [INFO] [1748145944.389722327] [gz_ros_control]: 		 orientation.x
2025-05-25T04:06:07.3973782Z     [gazebo-1] [INFO] [1748145944.389793691] [gz_ros_control]: 		 orientation.y
2025-05-25T04:06:07.3974341Z     [gazebo-1] [INFO] [1748145944.389831462] [gz_ros_control]: 		 orientation.z
2025-05-25T04:06:07.3974881Z     [gazebo-1] [INFO] [1748145944.389848574] [gz_ros_control]: 		 orientation.w
2025-05-25T04:06:07.3975480Z     [gazebo-1] [INFO] [1748145944.389858974] [gz_ros_control]: 		 angular_velocity.x
2025-05-25T04:06:07.3976110Z     [gazebo-1] [INFO] [1748145944.389867740] [gz_ros_control]: 		 angular_velocity.y
2025-05-25T04:06:07.3976809Z     [gazebo-1] [INFO] [1748145944.389886495] [gz_ros_control]: 		 angular_velocity.z
2025-05-25T04:06:07.3977542Z     [gazebo-1] [INFO] [1748145944.389898588] [gz_ros_control]: 		 linear_acceleration.x
2025-05-25T04:06:07.3978245Z     [gazebo-1] [INFO] [1748145944.389908657] [gz_ros_control]: 		 linear_acceleration.y
2025-05-25T04:06:07.3978964Z     [gazebo-1] [INFO] [1748145944.389918075] [gz_ros_control]: 		 linear_acceleration.z
2025-05-25T04:06:07.3979859Z     [gazebo-1] [INFO] [1748145944.390414257] [gz_ros_control.resource_manager]: Initialize hardware 'GazeboSimSystem' 
2025-05-25T04:06:07.3981059Z     [gazebo-1] [INFO] [1748145944.391233415] [gz_ros_control.resource_manager]: Successful initialization of hardware 'GazeboSimSystem'
2025-05-25T04:06:07.3982306Z     [gazebo-1] [INFO] [1748145944.393197154] [resource_manager]: 'configure' hardware 'GazeboSimSystem' 
2025-05-25T04:06:07.3983191Z     [gazebo-1] [INFO] [1748145944.393247649] [gz_ros_control]: System Successfully configured!
2025-05-25T04:06:07.3984346Z     [gazebo-1] [INFO] [1748145944.393267065] [resource_manager]: Successful 'configure' of hardware 'GazeboSimSystem'
2025-05-25T04:06:07.3985512Z     [gazebo-1] [INFO] [1748145944.393320846] [resource_manager]: 'activate' hardware 'GazeboSimSystem' 
2025-05-25T04:06:07.3986522Z     [gazebo-1] [INFO] [1748145944.393388704] [resource_manager]: Successful 'activate' of hardware 'GazeboSimSystem'
2025-05-25T04:06:07.3987929Z     [gazebo-1] [INFO] [1748145944.393839901] [controller_manager]: Resource Manager has been successfully initialized. Starting Controller Manager services...
2025-05-25T04:06:07.3989556Z     [gazebo-1] [INFO] [1748145944.505974820] [controller_manager]: Loading controller : 'joint_state_broadcaster' of type 'joint_state_broadcaster/JointStateBroadcaster'
2025-05-25T04:06:07.3990917Z     [gazebo-1] [INFO] [1748145944.506043850] [controller_manager]: Loading controller 'joint_state_broadcaster'
2025-05-25T04:06:07.3993318Z     [gazebo-1] [INFO] [1748145944.515125889] [controller_manager]: Controller 'joint_state_broadcaster' node arguments: --ros-args --params-file /home/runner/work/ros2_control_ci/ros2_control_ci/.work/target_ws/install/gz_ros2_control_demos/share/gz_ros2_control_demos/config/cart_controller_velocity.yaml -p use_sim_time:=true --param use_sim_time:=true 
2025-05-25T04:06:07.3996629Z     [spawner-6] [INFO] [1748145944.531094033] [spawner_joint_state_broadcaster]: [NON-XML-CHAR-0x1B][94mLoaded [NON-XML-CHAR-0x1B][1mjoint_state_broadcaster[NON-XML-CHAR-0x1B][0m
2025-05-25T04:06:07.3998214Z     [gazebo-1] [INFO] [1748145944.532935913] [controller_manager]: Configuring controller: 'joint_state_broadcaster'
2025-05-25T04:06:07.3999540Z     [gazebo-1] [INFO] [1748145944.533499150] [joint_state_broadcaster]: 'joints' or 'interfaces' parameter is empty. All available state interfaces will be published
2025-05-25T04:06:07.4000853Z     [gazebo-1] [INFO] [1748145944.548483816] [controller_manager]: Activating controllers: [ joint_state_broadcaster ]
2025-05-25T04:06:07.4001921Z     [gazebo-1] [INFO] [1748145946.248151208] [controller_manager]: Successfully switched controllers!
2025-05-25T04:06:07.4002863Z     [gazebo-1] [INFO] [1748145946.248486051] [gz_ros_control]: IMU cart_imu_sensor has a topic name: imu
2025-05-25T04:06:07.4004462Z     [spawner-6] [INFO] [1748145946.251074333] [spawner_joint_state_broadcaster]: [NON-XML-CHAR-0x1B][92mConfigured and activated [NON-XML-CHAR-0x1B][1mjoint_state_broadcaster[NON-XML-CHAR-0x1B][0m
2025-05-25T04:06:07.4005763Z     [INFO] [spawner-6]: process has finished cleanly [pid 57116]
2025-05-25T04:06:07.4006321Z     [INFO] [spawner-7]: process started with pid [57165]
2025-05-25T04:06:07.4006842Z     [INFO] [spawner-8]: process started with pid [57166]
2025-05-25T04:06:07.4007945Z     [spawner-7] [INFO] [1748145946.739592752] [spawner_joint_trajectory_controller]: waiting for service /controller_manager/list_controllers to become available...
2025-05-25T04:06:07.4010819Z     [spawner-7] [INFO] [1748145946.999585286] [spawner_joint_trajectory_controller]: [NON-XML-CHAR-0x1B][96mSetting controller param "params_file" to "['/home/runner/work/ros2_control_ci/ros2_control_ci/.work/target_ws/install/gz_ros2_control_demos/share/gz_ros2_control_demos/config/cart_controller_velocity.yaml']" for [NON-XML-CHAR-0x1B][1mjoint_trajectory_controller[NON-XML-CHAR-0x1B][0m
2025-05-25T04:06:07.4014371Z     [spawner-7] [INFO] [1748145947.007256974] [spawner_joint_trajectory_controller]: [NON-XML-CHAR-0x1B][96mSetting controller param "type" to "joint_trajectory_controller/JointTrajectoryController" for [NON-XML-CHAR-0x1B][1mjoint_trajectory_controller[NON-XML-CHAR-0x1B][0m
2025-05-25T04:06:07.4016635Z     [gazebo-1] [INFO] [1748145947.010661751] [controller_manager]: Loading controller : 'joint_trajectory_controller' of type 'joint_trajectory_controller/JointTrajectoryController'
2025-05-25T04:06:07.4018027Z     [gazebo-1] [INFO] [1748145947.010697999] [controller_manager]: Loading controller 'joint_trajectory_controller'
2025-05-25T04:06:07.4021187Z     [gazebo-1] [INFO] [1748145947.018773107] [controller_manager]: Controller 'joint_trajectory_controller' node arguments: --ros-args --params-file /home/runner/work/ros2_control_ci/ros2_control_ci/.work/target_ws/install/gz_ros2_control_demos/share/gz_ros2_control_demos/config/cart_controller_velocity.yaml -p use_sim_time:=true --params-file /home/runner/work/ros2_control_ci/ros2_control_ci/.work/target_ws/install/gz_ros2_control_demos/share/gz_ros2_control_demos/config/cart_controller_velocity.yaml --param use_sim_time:=true 
2025-05-25T04:06:07.4024670Z     [spawner-7] [INFO] [1748145947.035844161] [spawner_joint_trajectory_controller]: [NON-XML-CHAR-0x1B][94mLoaded [NON-XML-CHAR-0x1B][1mjoint_trajectory_controller[NON-XML-CHAR-0x1B][0m
2025-05-25T04:06:07.4026160Z     [gazebo-1] [INFO] [1748145947.037615010] [controller_manager]: Configuring controller: 'joint_trajectory_controller'
2025-05-25T04:06:07.4027515Z     [gazebo-1] [INFO] [1748145947.037894906] [joint_trajectory_controller]: No specific joint names are used for command interfaces. Using 'joints' parameter.
2025-05-25T04:06:07.4029034Z     [gazebo-1] [INFO] [1748145947.038643182] [joint_trajectory_controller]: Command interfaces are [velocity] and state interfaces are [position velocity].
2025-05-25T04:06:07.4030443Z     [gazebo-1] [INFO] [1748145947.038923428] [joint_trajectory_controller]: Using 'splines' interpolation method.
2025-05-25T04:06:07.4031565Z     [gazebo-1] [INFO] [1748145947.044497936] [joint_trajectory_controller]: Action status changes will be monitored at 20.00 Hz.
2025-05-25T04:06:07.4032844Z     [gazebo-1] [INFO] [1748145947.062958490] [controller_manager]: Activating controllers: [ joint_trajectory_controller ]
2025-05-25T04:06:07.4034061Z     [gazebo-1] [INFO] [1748145947.064801992] [controller_manager]: Successfully switched controllers!
2025-05-25T04:06:07.4035539Z     [spawner-7] [INFO] [1748145947.066847033] [spawner_joint_trajectory_controller]: [NON-XML-CHAR-0x1B][92mConfigured and activated [NON-XML-CHAR-0x1B][1mjoint_trajectory_controller[NON-XML-CHAR-0x1B][0m
2025-05-25T04:06:07.4037300Z     [spawner-8] [INFO] [1748145947.194890785] [spawner_imu_sensor_broadcaster]: waiting for service /controller_manager/list_controllers to become available...
2025-05-25T04:06:07.4038355Z     [INFO] [spawner-7]: process has finished cleanly [pid 57165]
2025-05-25T04:06:07.4040635Z     [spawner-8] [INFO] [1748145947.453623067] [spawner_imu_sensor_broadcaster]: [NON-XML-CHAR-0x1B][96mSetting controller param "params_file" to "['/home/runner/work/ros2_control_ci/ros2_control_ci/.work/target_ws/install/gz_ros2_control_demos/share/gz_ros2_control_demos/config/cart_controller_velocity.yaml']" for [NON-XML-CHAR-0x1B][1mimu_sensor_broadcaster[NON-XML-CHAR-0x1B][0m
2025-05-25T04:06:07.4043848Z     [spawner-8] [INFO] [1748145947.460261836] [spawner_imu_sensor_broadcaster]: [NON-XML-CHAR-0x1B][96mSetting controller param "type" to "imu_sensor_broadcaster/IMUSensorBroadcaster" for [NON-XML-CHAR-0x1B][1mimu_sensor_broadcaster[NON-XML-CHAR-0x1B][0m
2025-05-25T04:06:07.4045889Z     [spawner-8] [INFO] [1748145947.464024693] [spawner_imu_sensor_broadcaster]: waiting for service /controller_manager/load_controller to become available...
2025-05-25T04:06:07.4046807Z     FAIL
2025-05-25T04:06:07.4047389Z     test_check_if_msgs_published (gz_ros2_control_tests.TestFixture.test_check_if_msgs_published) ... ok
2025-05-25T04:06:07.4048320Z     test_clock (gz_ros2_control_tests.TestFixture.test_clock) ... /clock is receiving messages!
2025-05-25T04:06:07.4048961Z     ok
2025-05-25T04:06:07.4049369Z     test_node_start (gz_ros2_control_tests.TestFixture.test_node_start) ... ok
2025-05-25T04:06:07.4049908Z     
2025-05-25T04:06:07.4050167Z     ======================================================================
2025-05-25T04:06:07.4050802Z     FAIL: test_arm (gz_ros2_control_tests.TestFixture.test_arm)
2025-05-25T04:06:07.4051359Z     ----------------------------------------------------------------------
2025-05-25T04:06:07.4051859Z     Traceback (most recent call last):
2025-05-25T04:06:07.4052965Z       File "/home/runner/work/ros2_control_ci/ros2_control_ci/.work/target_ws/src/ros-controls/gz_ros2_control/gz_ros2_control_tests/tests/velocity_test.py", line 104, in test_arm
2025-05-25T04:06:07.4054382Z         check_controllers_running(self.node, cnames)
2025-05-25T04:06:07.4055727Z       File "/home/runner/work/ros2_control_ci/ros2_control_ci/.work/target_ws/install/controller_manager/lib/python3.12/site-packages/controller_manager/test_utils.py", line 81, in check_controllers_running
2025-05-25T04:06:07.4057058Z         assert all(
2025-05-25T04:06:07.4057331Z                ^^^^
2025-05-25T04:06:07.4059113Z     AssertionError: Controller node(s) not found: ns: /, ctrl:imu_sensor_broadcaster, but seeing [('_ros2cli_daemon_0_3d6b7692d1154bbdb7a0f027f3cb347d', '/'), ('spawner_imu_sensor_broadcaster', '/'), ('test_node', '/'), ('ros_gz_bridge', '/'), ('robot_state_publisher', '/'), ('gz_ros_control', '/'), ('controller_manager', '/'), ('joint_state_broadcaster', '/'), ('joint_trajectory_controller', '/')]
2025-05-25T04:06:07.4060902Z     
2025-05-25T04:06:07.4061179Z     --------------------The test ended before the system was launched successfully, why?

2025-05-25T04:06:07.3933754Z   <<< failure message
2025-05-25T04:06:07.3934077Z     -- run_test.py: extra environment variables:
2025-05-25T04:06:07.3934479Z      - PYTHONDONTWRITEBYTECODE=1
2025-05-25T04:06:07.3935306Z     -- run_test.py: invoking following command in '/home/runner/work/ros2_control_ci/ros2_control_ci/.work/target_ws/build/gz_ros2_control_tests/tests':
2025-05-25T04:06:07.3937891Z      - /usr/bin/python3 -m launch_testing.launch_test /home/runner/work/ros2_control_ci/ros2_control_ci/.work/target_ws/src/ros-controls/gz_ros2_control/gz_ros2_control_tests/tests/velocity_test.py --junit-xml=/home/runner/work/ros2_control_ci/ros2_control_ci/.work/target_ws/build/gz_ros2_control_tests/test_results/gz_ros2_control_tests/tests_velocity_test.py.xunit.xml --package-name=gz_ros2_control_tests
2025-05-25T04:06:07.3940445Z     [INFO] [launch]: All log files can be found below /root/.ros/log/2025-05-25-04-05-41-363111-f3dcb04c4b7d-57011
2025-05-25T04:06:07.3941156Z     [INFO] [launch]: Default logging verbosity is set to INFO
2025-05-25T04:06:07.3941857Z     test_arm (gz_ros2_control_tests.TestFixture.test_arm) ... [INFO] [gazebo-1]: process started with pid [57031]
2025-05-25T04:06:07.3942575Z     [INFO] [parameter_bridge-2]: process started with pid [57032]
2025-05-25T04:06:07.3943113Z     [INFO] [robot_state_publisher-3]: process started with pid [57033]
2025-05-25T04:06:07.3943764Z     [INFO] [create-4]: process started with pid [57035]
2025-05-25T04:06:07.3944205Z     [INFO] [python3-5]: process started with pid [57037]
2025-05-25T04:06:07.3944775Z     [create-4] [INFO] [1748145941.872306740] [ros_gz_sim]: Requesting list of world names.
2025-05-25T04:06:07.3945807Z     [parameter_bridge-2] [INFO] [1748145941.892059997] [ros_gz_bridge]: Creating GZ->ROS Bridge: [/clock (gz.msgs.Clock) -> /clock (rosgraph_msgs/msg/Clock)] (Lazy 0)
2025-05-25T04:06:07.3946881Z     [robot_state_publisher-3] [INFO] [1748145941.912983384] [robot_state_publisher]: Robot initialized
2025-05-25T04:06:07.3947720Z     [create-4] [INFO] [1748145942.358652941] [ros_gz_sim]: Waiting messages on topic [robot_description].
2025-05-25T04:06:07.3948490Z     [create-4] [INFO] [1748145942.370005704] [ros_gz_sim]: Entity creation successful.
2025-05-25T04:06:07.3949135Z     [INFO] [create-4]: process has finished cleanly [pid 57035]
2025-05-25T04:06:07.3949660Z     [INFO] [spawner-6]: process started with pid [57116]
2025-05-25T04:06:07.3950668Z     [spawner-6] [INFO] [1748145942.751656941] [spawner_joint_state_broadcaster]: waiting for service /controller_manager/list_controllers to become available...
2025-05-25T04:06:07.3951945Z     [gazebo-1] [INFO] [1748145944.199430867] [gz_ros_control]: [gz_ros2_control] Fixed joint [world_to_base] (Entity=20)] is skipped
2025-05-25T04:06:07.3952866Z     [gazebo-1] [INFO] [1748145944.205185125] [gz_ros_control]: Loading controller_manager
2025-05-25T04:06:07.3953949Z     [gazebo-1] [INFO] [1748145944.224828825] [controller_manager]: Using ROS clock for triggering controller manager cycles.
2025-05-25T04:06:07.3955204Z     [gazebo-1] [INFO] [1748145944.231002481] [controller_manager]: Subscribing to '/robot_description' topic for robot description.
2025-05-25T04:06:07.3956294Z     [gazebo-1] [INFO] [1748145944.233900704] [controller_manager]: Enforcing command limits is enabled...
2025-05-25T04:06:07.3957216Z     [gazebo-1] [WARN] [1748145944.234025339] [gz_ros_control]: Waiting RM to load and initialize hardware...
2025-05-25T04:06:07.3958298Z     [gazebo-1] [INFO] [1748145944.375104521] [controller_manager]: Received robot description from topic.
2025-05-25T04:06:07.3959698Z     [gazebo-1] [INFO] [1748145944.380220500] [gz_ros_control.resource_manager]: Using JointLimiter for joint 'slider_to_cart' in hardware 'GazeboSimSystem' : '  has position limits: true [-15, 15]
2025-05-25T04:06:07.3960830Z     [gazebo-1]   has velocity limits: true [15]
2025-05-25T04:06:07.3961288Z     [gazebo-1]   has acceleration limits: false [nan]
2025-05-25T04:06:07.3961769Z     [gazebo-1]   has deceleration limits: false [nan]
2025-05-25T04:06:07.3962228Z     [gazebo-1]   has jerk limits: false [nan]
2025-05-25T04:06:07.3962646Z     [gazebo-1]   has effort limits: true [1000]
2025-05-25T04:06:07.3963056Z     [gazebo-1]   angle wraparound: false'
2025-05-25T04:06:07.3964206Z     [gazebo-1] [INFO] [1748145944.380276095] [gz_ros_control.resource_manager]: Creating JointSaturationLimiter for joint 'slider_to_cart' in hardware 'GazeboSimSystem'
2025-05-25T04:06:07.3965521Z     [gazebo-1] [INFO] [1748145944.386993962] [gz_ros_control]: The position_proportional_gain has been set to: 0.1
2025-05-25T04:06:07.3966518Z     [gazebo-1] [INFO] [1748145944.387487219] [gz_ros_control]: Loading joint: slider_to_cart
2025-05-25T04:06:07.3967184Z     [gazebo-1] [INFO] [1748145944.387527635] [gz_ros_control]: 	State:
2025-05-25T04:06:07.3967860Z     [gazebo-1] [INFO] [1748145944.387545168] [gz_ros_control]: 		 position
2025-05-25T04:06:07.3968559Z     [gazebo-1] [INFO] [1748145944.387686974] [gz_ros_control]: 			 found initial value: 1.000000
2025-05-25T04:06:07.3969247Z     [gazebo-1] [INFO] [1748145944.387714746] [gz_ros_control]: 		 velocity
2025-05-25T04:06:07.3969854Z     [gazebo-1] [INFO] [1748145944.387908059] [gz_ros_control]: 		 effort
2025-05-25T04:06:07.3970444Z     [gazebo-1] [INFO] [1748145944.387949668] [gz_ros_control]: 	Command:
2025-05-25T04:06:07.3971047Z     [gazebo-1] [INFO] [1748145944.387967130] [gz_ros_control]: 		 velocity
2025-05-25T04:06:07.3971753Z     [gazebo-1] [INFO] [1748145944.389464964] [gz_ros_control]: Loading sensor: cart_imu_sensor
2025-05-25T04:06:07.3972460Z     [gazebo-1] [INFO] [1748145944.389501482] [gz_ros_control]: 	State:
2025-05-25T04:06:07.3973059Z     [gazebo-1] [INFO] [1748145944.389722327] [gz_ros_control]: 		 orientation.x
2025-05-25T04:06:07.3973782Z     [gazebo-1] [INFO] [1748145944.389793691] [gz_ros_control]: 		 orientation.y
2025-05-25T04:06:07.3974341Z     [gazebo-1] [INFO] [1748145944.389831462] [gz_ros_control]: 		 orientation.z
2025-05-25T04:06:07.3974881Z     [gazebo-1] [INFO] [1748145944.389848574] [gz_ros_control]: 		 orientation.w
2025-05-25T04:06:07.3975480Z     [gazebo-1] [INFO] [1748145944.389858974] [gz_ros_control]: 		 angular_velocity.x
2025-05-25T04:06:07.3976110Z     [gazebo-1] [INFO] [1748145944.389867740] [gz_ros_control]: 		 angular_velocity.y
2025-05-25T04:06:07.3976809Z     [gazebo-1] [INFO] [1748145944.389886495] [gz_ros_control]: 		 angular_velocity.z
2025-05-25T04:06:07.3977542Z     [gazebo-1] [INFO] [1748145944.389898588] [gz_ros_control]: 		 linear_acceleration.x
2025-05-25T04:06:07.3978245Z     [gazebo-1] [INFO] [1748145944.389908657] [gz_ros_control]: 		 linear_acceleration.y
2025-05-25T04:06:07.3978964Z     [gazebo-1] [INFO] [1748145944.389918075] [gz_ros_control]: 		 linear_acceleration.z
2025-05-25T04:06:07.3979859Z     [gazebo-1] [INFO] [1748145944.390414257] [gz_ros_control.resource_manager]: Initialize hardware 'GazeboSimSystem' 
2025-05-25T04:06:07.3981059Z     [gazebo-1] [INFO] [1748145944.391233415] [gz_ros_control.resource_manager]: Successful initialization of hardware 'GazeboSimSystem'
2025-05-25T04:06:07.3982306Z     [gazebo-1] [INFO] [1748145944.393197154] [resource_manager]: 'configure' hardware 'GazeboSimSystem' 
2025-05-25T04:06:07.3983191Z     [gazebo-1] [INFO] [1748145944.393247649] [gz_ros_control]: System Successfully configured!
2025-05-25T04:06:07.3984346Z     [gazebo-1] [INFO] [1748145944.393267065] [resource_manager]: Successful 'configure' of hardware 'GazeboSimSystem'
2025-05-25T04:06:07.3985512Z     [gazebo-1] [INFO] [1748145944.393320846] [resource_manager]: 'activate' hardware 'GazeboSimSystem' 
2025-05-25T04:06:07.3986522Z     [gazebo-1] [INFO] [1748145944.393388704] [resource_manager]: Successful 'activate' of hardware 'GazeboSimSystem'
2025-05-25T04:06:07.3987929Z     [gazebo-1] [INFO] [1748145944.393839901] [controller_manager]: Resource Manager has been successfully initialized. Starting Controller Manager services...
2025-05-25T04:06:07.3989556Z     [gazebo-1] [INFO] [1748145944.505974820] [controller_manager]: Loading controller : 'joint_state_broadcaster' of type 'joint_state_broadcaster/JointStateBroadcaster'
2025-05-25T04:06:07.3990917Z     [gazebo-1] [INFO] [1748145944.506043850] [controller_manager]: Loading controller 'joint_state_broadcaster'
2025-05-25T04:06:07.3993318Z     [gazebo-1] [INFO] [1748145944.515125889] [controller_manager]: Controller 'joint_state_broadcaster' node arguments: --ros-args --params-file /home/runner/work/ros2_control_ci/ros2_control_ci/.work/target_ws/install/gz_ros2_control_demos/share/gz_ros2_control_demos/config/cart_controller_velocity.yaml -p use_sim_time:=true --param use_sim_time:=true 
2025-05-25T04:06:07.3996629Z     [spawner-6] [INFO] [1748145944.531094033] [spawner_joint_state_broadcaster]: [NON-XML-CHAR-0x1B][94mLoaded [NON-XML-CHAR-0x1B][1mjoint_state_broadcaster[NON-XML-CHAR-0x1B][0m
2025-05-25T04:06:07.3998214Z     [gazebo-1] [INFO] [1748145944.532935913] [controller_manager]: Configuring controller: 'joint_state_broadcaster'
2025-05-25T04:06:07.3999540Z     [gazebo-1] [INFO] [1748145944.533499150] [joint_state_broadcaster]: 'joints' or 'interfaces' parameter is empty. All available state interfaces will be published
2025-05-25T04:06:07.4000853Z     [gazebo-1] [INFO] [1748145944.548483816] [controller_manager]: Activating controllers: [ joint_state_broadcaster ]
2025-05-25T04:06:07.4001921Z     [gazebo-1] [INFO] [1748145946.248151208] [controller_manager]: Successfully switched controllers!
2025-05-25T04:06:07.4002863Z     [gazebo-1] [INFO] [1748145946.248486051] [gz_ros_control]: IMU cart_imu_sensor has a topic name: imu
2025-05-25T04:06:07.4004462Z     [spawner-6] [INFO] [1748145946.251074333] [spawner_joint_state_broadcaster]: [NON-XML-CHAR-0x1B][92mConfigured and activated [NON-XML-CHAR-0x1B][1mjoint_state_broadcaster[NON-XML-CHAR-0x1B][0m
2025-05-25T04:06:07.4005763Z     [INFO] [spawner-6]: process has finished cleanly [pid 57116]
2025-05-25T04:06:07.4006321Z     [INFO] [spawner-7]: process started with pid [57165]
2025-05-25T04:06:07.4006842Z     [INFO] [spawner-8]: process started with pid [57166]
2025-05-25T04:06:07.4007945Z     [spawner-7] [INFO] [1748145946.739592752] [spawner_joint_trajectory_controller]: waiting for service /controller_manager/list_controllers to become available...
2025-05-25T04:06:07.4010819Z     [spawner-7] [INFO] [1748145946.999585286] [spawner_joint_trajectory_controller]: [NON-XML-CHAR-0x1B][96mSetting controller param "params_file" to "['/home/runner/work/ros2_control_ci/ros2_control_ci/.work/target_ws/install/gz_ros2_control_demos/share/gz_ros2_control_demos/config/cart_controller_velocity.yaml']" for [NON-XML-CHAR-0x1B][1mjoint_trajectory_controller[NON-XML-CHAR-0x1B][0m
2025-05-25T04:06:07.4014371Z     [spawner-7] [INFO] [1748145947.007256974] [spawner_joint_trajectory_controller]: [NON-XML-CHAR-0x1B][96mSetting controller param "type" to "joint_trajectory_controller/JointTrajectoryController" for [NON-XML-CHAR-0x1B][1mjoint_trajectory_controller[NON-XML-CHAR-0x1B][0m
2025-05-25T04:06:07.4016635Z     [gazebo-1] [INFO] [1748145947.010661751] [controller_manager]: Loading controller : 'joint_trajectory_controller' of type 'joint_trajectory_controller/JointTrajectoryController'
2025-05-25T04:06:07.4018027Z     [gazebo-1] [INFO] [1748145947.010697999] [controller_manager]: Loading controller 'joint_trajectory_controller'
2025-05-25T04:06:07.4021187Z     [gazebo-1] [INFO] [1748145947.018773107] [controller_manager]: Controller 'joint_trajectory_controller' node arguments: --ros-args --params-file /home/runner/work/ros2_control_ci/ros2_control_ci/.work/target_ws/install/gz_ros2_control_demos/share/gz_ros2_control_demos/config/cart_controller_velocity.yaml -p use_sim_time:=true --params-file /home/runner/work/ros2_control_ci/ros2_control_ci/.work/target_ws/install/gz_ros2_control_demos/share/gz_ros2_control_demos/config/cart_controller_velocity.yaml --param use_sim_time:=true 
2025-05-25T04:06:07.4024670Z     [spawner-7] [INFO] [1748145947.035844161] [spawner_joint_trajectory_controller]: [NON-XML-CHAR-0x1B][94mLoaded [NON-XML-CHAR-0x1B][1mjoint_trajectory_controller[NON-XML-CHAR-0x1B][0m
2025-05-25T04:06:07.4026160Z     [gazebo-1] [INFO] [1748145947.037615010] [controller_manager]: Configuring controller: 'joint_trajectory_controller'
2025-05-25T04:06:07.4027515Z     [gazebo-1] [INFO] [1748145947.037894906] [joint_trajectory_controller]: No specific joint names are used for command interfaces. Using 'joints' parameter.
2025-05-25T04:06:07.4029034Z     [gazebo-1] [INFO] [1748145947.038643182] [joint_trajectory_controller]: Command interfaces are [velocity] and state interfaces are [position velocity].
2025-05-25T04:06:07.4030443Z     [gazebo-1] [INFO] [1748145947.038923428] [joint_trajectory_controller]: Using 'splines' interpolation method.
2025-05-25T04:06:07.4031565Z     [gazebo-1] [INFO] [1748145947.044497936] [joint_trajectory_controller]: Action status changes will be monitored at 20.00 Hz.
2025-05-25T04:06:07.4032844Z     [gazebo-1] [INFO] [1748145947.062958490] [controller_manager]: Activating controllers: [ joint_trajectory_controller ]
2025-05-25T04:06:07.4034061Z     [gazebo-1] [INFO] [1748145947.064801992] [controller_manager]: Successfully switched controllers!
2025-05-25T04:06:07.4035539Z     [spawner-7] [INFO] [1748145947.066847033] [spawner_joint_trajectory_controller]: [NON-XML-CHAR-0x1B][92mConfigured and activated [NON-XML-CHAR-0x1B][1mjoint_trajectory_controller[NON-XML-CHAR-0x1B][0m
2025-05-25T04:06:07.4037300Z     [spawner-8] [INFO] [1748145947.194890785] [spawner_imu_sensor_broadcaster]: waiting for service /controller_manager/list_controllers to become available...
2025-05-25T04:06:07.4038355Z     [INFO] [spawner-7]: process has finished cleanly [pid 57165]
2025-05-25T04:06:07.4040635Z     [spawner-8] [INFO] [1748145947.453623067] [spawner_imu_sensor_broadcaster]: [NON-XML-CHAR-0x1B][96mSetting controller param "params_file" to "['/home/runner/work/ros2_control_ci/ros2_control_ci/.work/target_ws/install/gz_ros2_control_demos/share/gz_ros2_control_demos/config/cart_controller_velocity.yaml']" for [NON-XML-CHAR-0x1B][1mimu_sensor_broadcaster[NON-XML-CHAR-0x1B][0m
2025-05-25T04:06:07.4043848Z     [spawner-8] [INFO] [1748145947.460261836] [spawner_imu_sensor_broadcaster]: [NON-XML-CHAR-0x1B][96mSetting controller param "type" to "imu_sensor_broadcaster/IMUSensorBroadcaster" for [NON-XML-CHAR-0x1B][1mimu_sensor_broadcaster[NON-XML-CHAR-0x1B][0m
2025-05-25T04:06:07.4045889Z     [spawner-8] [INFO] [1748145947.464024693] [spawner_imu_sensor_broadcaster]: waiting for service /controller_manager/load_controller to become available...
2025-05-25T04:06:07.4046807Z     FAIL
2025-05-25T04:06:07.4047389Z     test_check_if_msgs_published (gz_ros2_control_tests.TestFixture.test_check_if_msgs_published) ... ok
2025-05-25T04:06:07.4048320Z     test_clock (gz_ros2_control_tests.TestFixture.test_clock) ... /clock is receiving messages!
2025-05-25T04:06:07.4048961Z     ok
2025-05-25T04:06:07.4049369Z     test_node_start (gz_ros2_control_tests.TestFixture.test_node_start) ... ok
2025-05-25T04:06:07.4049908Z     
2025-05-25T04:06:07.4050167Z     ======================================================================
2025-05-25T04:06:07.4050802Z     FAIL: test_arm (gz_ros2_control_tests.TestFixture.test_arm)
2025-05-25T04:06:07.4051359Z     ----------------------------------------------------------------------
2025-05-25T04:06:07.4051859Z     Traceback (most recent call last):
2025-05-25T04:06:07.4052965Z       File "/home/runner/work/ros2_control_ci/ros2_control_ci/.work/target_ws/src/ros-controls/gz_ros2_control/gz_ros2_control_tests/tests/velocity_test.py", line 104, in test_arm
2025-05-25T04:06:07.4054382Z         check_controllers_running(self.node, cnames)
2025-05-25T04:06:07.4055727Z       File "/home/runner/work/ros2_control_ci/ros2_control_ci/.work/target_ws/install/controller_manager/lib/python3.12/site-packages/controller_manager/test_utils.py", line 81, in check_controllers_running
2025-05-25T04:06:07.4057058Z         assert all(
2025-05-25T04:06:07.4057331Z                ^^^^
2025-05-25T04:06:07.4059113Z     AssertionError: Controller node(s) not found: ns: /, ctrl:imu_sensor_broadcaster, but seeing [('_ros2cli_daemon_0_3d6b7692d1154bbdb7a0f027f3cb347d', '/'), ('spawner_imu_sensor_broadcaster', '/'), ('test_node', '/'), ('ros_gz_bridge', '/'), ('robot_state_publisher', '/'), ('gz_ros_control', '/'), ('controller_manager', '/'), ('joint_state_broadcaster', '/'), ('joint_trajectory_controller', '/')]
2025-05-25T04:06:07.4060902Z     
2025-05-25T04:06:07.4061179Z     ----------------------------------------------------------------------
2025-05-25T04:06:07.4061696Z     Ran 4 tests in 11.663s
2025-05-25T04:06:07.4061973Z     
2025-05-25T04:06:07.4062191Z     FAILED (failures=1)
2025-05-25T04:06:07.4062591Z     [INFO] [spawner-8]: sending signal 'SIGINT' to process[spawner-8]
2025-05-25T04:06:07.4063191Z     [INFO] [python3-5]: sending signal 'SIGINT' to process[python3-5]
2025-05-25T04:06:07.4064235Z     [INFO] [robot_state_publisher-3]: sending signal 'SIGINT' to process[robot_state_publisher-3]
2025-05-25T04:06:09.9261698Z     [INFO] [parameter_bridge-2]: sending signal 'SIGINT' to process[parameter_bridge-2]
2025-05-25T04:06:09.9262530Z     [INFO] [gazebo-1]: sending signal 'SIGINT' to process[gazebo-1]
2025-05-25T04:06:09.9263366Z     [spawner-8] [INFO] [1748145953.443829170] [spawner_imu_sensor_broadcaster]: KeyboardInterrupt received! Exiting....
2025-05-25T04:06:09.9266319Z     [robot_state_publisher-3] [INFO] [1748145953.445920217] [rclcpp]: signal_handler(signum=2)
2025-05-25T04:06:09.9267074Z     [parameter_bridge-2] [INFO] [1748145953.445962707] [rclcpp]: signal_handler(signum=2)
2025-05-25T04:06:09.9267759Z     [INFO] [python3-5]: process has finished cleanly [pid 57037]
2025-05-25T04:06:09.9268317Z     [INFO] [parameter_bridge-2]: process has finished cleanly [pid 57032]
2025-05-25T04:06:09.9268775Z     [gazebo-1] Killed
2025-05-25T04:06:09.9269550Z     [ERROR] [gazebo-1]: process has died [pid 57031, exit code -2, cmd 'ruby $(which gz) sim --headless-rendering -s -r -v 1 empty.sdf --force-version 9'].
2025-05-25T04:06:09.9270535Z     [INFO] [robot_state_publisher-3]: process has finished cleanly [pid 57033]
2025-05-25T04:06:09.9271148Z     [INFO] [spawner-8]: process has finished cleanly [pid 57166]--------------------------------------------------
2025-05-25T04:06:07.4061696Z     Ran 4 tests in 11.663s
2025-05-25T04:06:07.4061973Z     
2025-05-25T04:06:07.4062191Z     FAILED (failures=1)
2025-05-25T04:06:07.4062591Z     [INFO] [spawner-8]: sending signal 'SIGINT' to process[spawner-8]
2025-05-25T04:06:07.4063191Z     [INFO] [python3-5]: sending signal 'SIGINT' to process[python3-5]
2025-05-25T04:06:07.4064235Z     [INFO] [robot_state_publisher-3]: sending signal 'SIGINT' to process[robot_state_publisher-3]
2025-05-25T04:06:09.9261698Z     [INFO] [parameter_bridge-2]: sending signal 'SIGINT' to process[parameter_bridge-2]
2025-05-25T04:06:09.9262530Z     [INFO] [gazebo-1]: sending signal 'SIGINT' to process[gazebo-1]
2025-05-25T04:06:09.9263366Z     [spawner-8] [INFO] [1748145953.443829170] [spawner_imu_sensor_broadcaster]: KeyboardInterrupt received! Exiting....
2025-05-25T04:06:09.9266319Z     [robot_state_publisher-3] [INFO] [1748145953.445920217] [rclcpp]: signal_handler(signum=2)
2025-05-25T04:06:09.9267074Z     [parameter_bridge-2] [INFO] [1748145953.445962707] [rclcpp]: signal_handler(signum=2)
2025-05-25T04:06:09.9267759Z     [INFO] [python3-5]: process has finished cleanly [pid 57037]
2025-05-25T04:06:09.9268317Z     [INFO] [parameter_bridge-2]: process has finished cleanly [pid 57032]
2025-05-25T04:06:09.9268775Z     [gazebo-1] Killed
2025-05-25T04:06:09.9269550Z     [ERROR] [gazebo-1]: process has died [pid 57031, exit code -2, cmd 'ruby $(which gz) sim --headless-rendering -s -r -v 1 empty.sdf --force-version 9'].
2025-05-25T04:06:09.9270535Z     [INFO] [robot_state_publisher-3]: process has finished cleanly [pid 57033]
2025-05-25T04:06:09.9271148Z     [INFO] [spawner-8]: process has finished cleanly [pid 57166]

@christophfroehlich christophfroehlich mentioned this issue May 25, 2025
Merged
This was referenced May 25, 2025
Merged
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
CI
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@christophfroehlich