gazebo_ros2_control crashes when trying to load controller_manager

[Flamethr0wer]

I've followed the Articulated Robotics tutorial on simulated ros2_control. However, when I try to launch my package, this is the output:

[INFO] [launch]: All log files can be found below /home/flamethrower/.ros/log/2024-08-07-21-53-05-343082-robot-2365
[INFO] [launch]: Default logging verbosity is set to INFO
[INFO] [robot_state_publisher-1]: process started with pid [2367]
[INFO] [gzserver-2]: process started with pid [2369]
[INFO] [gzclient   -3]: process started with pid [2371]
[INFO] [spawn_entity.py-4]: process started with pid [2374]
[INFO] [spawner.py-5]: process started with pid [2378]
[INFO] [spawner.py-6]: process started with pid [2380]
[robot_state_publisher-1] Parsing robot urdf xml string.
[robot_state_publisher-1] Link FL_wheel had 0 children
[robot_state_publisher-1] Link FR_wheel had 0 children
[robot_state_publisher-1] Link RL_wheel had 0 children
[robot_state_publisher-1] Link RR_wheel had 0 children
[robot_state_publisher-1] Link chassis had 1 children
[robot_state_publisher-1] Link laser_frame had 0 children
[robot_state_publisher-1] [INFO] [1723060388.264290005] [robot_state_publisher]: got segment FL_wheel
[robot_state_publisher-1] [INFO] [1723060388.264900042] [robot_state_publisher]: got segment FR_wheel
[robot_state_publisher-1] [INFO] [1723060388.265019134] [robot_state_publisher]: got segment RL_wheel
[robot_state_publisher-1] [INFO] [1723060388.265123578] [robot_state_publisher]: got segment RR_wheel
[robot_state_publisher-1] [INFO] [1723060388.265159171] [robot_state_publisher]: got segment base_link
[robot_state_publisher-1] [INFO] [1723060388.265185782] [robot_state_publisher]: got segment chassis
[robot_state_publisher-1] [INFO] [1723060388.265210152] [robot_state_publisher]: got segment laser_frame
[spawner.py-6] [INFO] [1723060389.002629240] [spawner_joint_broad]: Waiting for /controller_manager services
[spawner.py-5] [INFO] [1723060389.131382144] [spawner_diff_cont]: Waiting for /controller_manager services
[spawn_entity.py-4] [INFO] [1723060390.605938042] [spawn_entity]: Spawn Entity started
[spawn_entity.py-4] [INFO] [1723060390.608900798] [spawn_entity]: Loading entity published on topic robot_description
[spawn_entity.py-4] [INFO] [1723060390.698362553] [spawn_entity]: Waiting for entity xml on robot_description
[spawn_entity.py-4] [INFO] [1723060390.721761513] [spawn_entity]: Waiting for service /spawn_entity, timeout = 30
[spawn_entity.py-4] [INFO] [1723060390.723954030] [spawn_entity]: Waiting for service /spawn_entity
[spawner.py-6] [INFO] [1723060391.046582763] [spawner_joint_broad]: Waiting for /controller_manager services
[spawner.py-5] [INFO] [1723060391.174303335] [spawner_diff_cont]: Waiting for /controller_manager services
[spawner.py-6] [INFO] [1723060393.081256090] [spawner_joint_broad]: Waiting for /controller_manager services
[spawner.py-5] [INFO] [1723060393.209384810] [spawner_diff_cont]: Waiting for /controller_manager services
[spawner.py-6] [INFO] [1723060395.146927093] [spawner_joint_broad]: Waiting for /controller_manager services
[spawner.py-5] [INFO] [1723060395.275156850] [spawner_diff_cont]: Waiting for /controller_manager services
[spawner.py-6] [INFO] [1723060397.204037419] [spawner_joint_broad]: Waiting for /controller_manager services
[spawner.py-5] [INFO] [1723060397.335731691] [spawner_diff_cont]: Waiting for /controller_manager services
[spawn_entity.py-4] [INFO] [1723060398.860464415] [spawn_entity]: Calling service /spawn_entity
[spawner.py-6] [ERROR] [1723060399.042842864] [spawner_joint_broad]: Controller manager not available
[spawner.py-5] [ERROR] [1723060399.170336344] [spawner_diff_cont]: Controller manager not available
[ERROR] [spawner.py-6]: process has died [pid 2380, exit code 1, cmd '/opt/ros/foxy/lib/controller_manager/spawner.py joint_broad --ros-args'].
[ERROR] [spawner.py-5]: process has died [pid 2378, exit code 1, cmd '/opt/ros/foxy/lib/controller_manager/spawner.py diff_cont --ros-args'].
[spawn_entity.py-4] [INFO] [1723060400.018573500] [spawn_entity]: Spawn status: SpawnEntity: Successfully spawned entity [robot]
[gzserver-2] [WARN] [1723060400.125107035] [rcl]: Found remap rule '~/out:=scan'. This syntax is deprecated. Use '--ros-args --remap ~/out:=scan' instead.
[gzserver-2] [WARN] [1723060400.221840413] [rcl]: Found remap rule '~/out:=scan'. This syntax is deprecated. Use '--ros-args --remap ~/out:=scan' instead.
[INFO] [spawn_entity.py-4]: process has finished cleanly [pid 2374]
[gzserver-2] [INFO] [1723060400.486924511] [gazebo_ros2_control]: Loading gazebo_ros2_control plugin
[gzserver-2] [INFO] [1723060400.503913774] [gazebo_ros2_control]: Starting gazebo_ros2_control plugin in namespace: /
[gzserver-2] [INFO] [1723060400.506897493] [gazebo_ros2_control]: Starting gazebo_ros2_control plugin in ros 2 node: gazebo_ros2_control
[gzserver-2] [INFO] [1723060400.507364863] [gazebo_ros2_control]: Loading parameter files /home/flamethrower/robot_ws/install/robot/share/robot/config/my_controllers.yaml
[gzserver-2] [INFO] [1723060400.541606037] [gazebo_ros2_control]: connected to service!! robot_state_publisher
[gzserver-2] [INFO] [1723060400.546505662] [gazebo_ros2_control]: Recieved urdf from param server, parsing...
[gzserver-2] [INFO] [1723060400.623758890] [gazebo_ros2_control]: Loading joint: FL_wheel_joint
[gzserver-2] [INFO] [1723060400.624196464] [gazebo_ros2_control]: 	State:
[gzserver-2] [INFO] [1723060400.624326223] [gazebo_ros2_control]: 		 velocity
[gzserver-2] [INFO] [1723060400.624639371] [gazebo_ros2_control]: 		 position
[gzserver-2] [INFO] [1723060400.624758519] [gazebo_ros2_control]: 	Command:
[gzserver-2] [INFO] [1723060400.624798833] [gazebo_ros2_control]: 		 velocity
[gzserver-2] [INFO] [1723060400.625100648] [gazebo_ros2_control]: Loading joint: FR_wheel_joint
[gzserver-2] [INFO] [1723060400.625215833] [gazebo_ros2_control]: 	State:
[gzserver-2] [INFO] [1723060400.625252685] [gazebo_ros2_control]: 		 velocity
[gzserver-2] [INFO] [1723060400.625290222] [gazebo_ros2_control]: 		 position
[gzserver-2] [INFO] [1723060400.625325370] [gazebo_ros2_control]: 	Command:
[gzserver-2] [INFO] [1723060400.625360981] [gazebo_ros2_control]: 		 velocity
[gzserver-2] [INFO] [1723060400.625405481] [gazebo_ros2_control]: Loading joint: RL_wheel_joint
[gzserver-2] [INFO] [1723060400.625445481] [gazebo_ros2_control]: 	State:
[gzserver-2] [INFO] [1723060400.625478722] [gazebo_ros2_control]: 		 velocity
[gzserver-2] [INFO] [1723060400.625512796] [gazebo_ros2_control]: 		 position
[gzserver-2] [INFO] [1723060400.625546870] [gazebo_ros2_control]: 	Command:
[gzserver-2] [INFO] [1723060400.625580629] [gazebo_ros2_control]: 		 velocity
[gzserver-2] [INFO] [1723060400.625619573] [gazebo_ros2_control]: Loading joint: RR_wheel_joint
[gzserver-2] [INFO] [1723060400.625655888] [gazebo_ros2_control]: 	State:
[gzserver-2] [INFO] [1723060400.625686703] [gazebo_ros2_control]: 		 velocity
[gzserver-2] [INFO] [1723060400.625717018] [gazebo_ros2_control]: 		 position
[gzserver-2] [INFO] [1723060400.625749907] [gazebo_ros2_control]: 	Command:
[gzserver-2] [INFO] [1723060400.625779684] [gazebo_ros2_control]: 		 velocity
[gzserver-2] [INFO] [1723060400.627084424] [gazebo_ros2_control]: Loading controller_manager
[gzserver-2] terminate called after throwing an instance of 'std::system_error'
[gzserver-2]   what():  Invalid argument
[gzserver-2] Aborted (core dumped)
[ERROR] [gzserver-2]: process has died [pid 2369, exit code 134, cmd 'gzserver                                                                       -s libgazebo_ros_init.so   -s libgazebo_ros_factory.so   -s libgazebo_ros_force_system.so       '].

My controllers wait for the controller_manager, but gazebo_ros2_control fails to load it. I've tried installing the dependencies, reinstalling the package, downgrading it and using gdb and logs to find more information, but I haven't managed to solve anything. I have a custom robot, but the files are not the issue because using the package at https://github.com/joshnewans/articubot_one/tree/0085689ee023baac604268cdf7a9ce85a0ed7bae gives me the exact same error.
I have installed ros-foxy-ros2-control, ros-foxy-ros2-controllers, ros-foxy-gazebo-ros2-control and ros-foxy-gazebo-ros-pkgs and always source robot_ws/install/setup.bash This happens both in ROS2 Foxy and ROS2 Humble. Any help is appreciated.

[christophfroehlich]

First of all, Foxy is EOL for a long time now. Don't expect any support for it.

Can you launch the demos successfully?

[Flamethr0wer]

Yes, with the demos, the controller_manager is loaded correctly. However, weirdly, when I now launch my package, the output has changed:

[INFO] [launch]: All log files can be found below /home/flamethrower/.ros/log/2024-08-08-09-38-24-156579-robot-5174
[INFO] [launch]: Default logging verbosity is set to INFO
[INFO] [robot_state_publisher-1]: process started with pid [5177]
[INFO] [gzserver-2]: process started with pid [5179]
[INFO] [gzclient   -3]: process started with pid [5181]
[INFO] [spawn_entity.py-4]: process started with pid [5185]
[INFO] [spawner.py-5]: process started with pid [5188]
[INFO] [spawner.py-6]: process started with pid [5198]
[robot_state_publisher-1] Parsing robot urdf xml string.
[robot_state_publisher-1] Link FL_wheel had 0 children
[robot_state_publisher-1] Link FR_wheel had 0 children
[robot_state_publisher-1] Link RL_wheel had 0 children
[robot_state_publisher-1] Link RR_wheel had 0 children
[robot_state_publisher-1] Link chassis had 1 children
[robot_state_publisher-1] Link laser_frame had 0 children
[robot_state_publisher-1] [INFO] [1723102706.394172699] [robot_state_publisher]: got segment FL_wheel
[robot_state_publisher-1] [INFO] [1723102706.394659273] [robot_state_publisher]: got segment FR_wheel
[robot_state_publisher-1] [INFO] [1723102706.394792681] [robot_state_publisher]: got segment RL_wheel
[robot_state_publisher-1] [INFO] [1723102706.394839070] [robot_state_publisher]: got segment RR_wheel
[robot_state_publisher-1] [INFO] [1723102706.394868514] [robot_state_publisher]: got segment base_link
[robot_state_publisher-1] [INFO] [1723102706.394893144] [robot_state_publisher]: got segment chassis
[robot_state_publisher-1] [INFO] [1723102706.394921070] [robot_state_publisher]: got segment laser_frame
[spawner.py-6] [INFO] [1723102708.230839531] [spawner_joint_broad]: Waiting for /controller_manager services
[spawner.py-5] [INFO] [1723102708.277828013] [spawner_diff_cont]: Waiting for /controller_manager services
[spawn_entity.py-4] [INFO] [1723102709.542547948] [spawn_entity]: Spawn Entity started
[spawn_entity.py-4] [INFO] [1723102709.546275505] [spawn_entity]: Loading entity published on topic robot_description
[spawn_entity.py-4] [INFO] [1723102709.559492899] [spawn_entity]: Waiting for entity xml on robot_description
[spawn_entity.py-4] [INFO] [1723102709.583245445] [spawn_entity]: Waiting for service /spawn_entity, timeout = 30
[spawn_entity.py-4] [INFO] [1723102709.597635451] [spawn_entity]: Waiting for service /spawn_entity
[spawner.py-6] [INFO] [1723102710.270663722] [spawner_joint_broad]: Waiting for /controller_manager services
[spawner.py-5] [INFO] [1723102710.316892333] [spawner_diff_cont]: Waiting for /controller_manager services
[spawner.py-6] [INFO] [1723102712.333093296] [spawner_joint_broad]: Waiting for /controller_manager services
[spawner.py-5] [INFO] [1723102712.396987246] [spawner_diff_cont]: Waiting for /controller_manager services
[spawner.py-6] [INFO] [1723102714.383951400] [spawner_joint_broad]: Waiting for /controller_manager services
[spawner.py-5] [INFO] [1723102714.441106063] [spawner_diff_cont]: Waiting for /controller_manager services
[spawn_entity.py-4] [INFO] [1723102714.891929503] [spawn_entity]: Calling service /spawn_entity
[spawn_entity.py-4] [INFO] [1723102715.962815576] [spawn_entity]: Spawn status: SpawnEntity: Successfully spawned entity [robot]
[gzserver-2] [WARN] [1723102716.033858505] [rcl]: Found remap rule '~/out:=scan'. This syntax is deprecated. Use '--ros-args --remap ~/out:=scan' instead.
[gzserver-2] [WARN] [1723102716.081173725] [rcl]: Found remap rule '~/out:=scan'. This syntax is deprecated. Use '--ros-args --remap ~/out:=scan' instead.
[INFO] [spawn_entity.py-4]: process has finished cleanly [pid 5185]
[gzserver-2] [INFO] [1723102716.406152487] [gazebo_ros2_control]: Loading gazebo_ros2_control plugin
[spawner.py-6] [INFO] [1723102716.430018419] [spawner_joint_broad]: Waiting for /controller_manager services
[gzserver-2] [INFO] [1723102716.435642398] [gazebo_ros2_control]: Starting gazebo_ros2_control plugin in namespace: /
[gzserver-2] [INFO] [1723102716.437482500] [gazebo_ros2_control]: Starting gazebo_ros2_control plugin in ros 2 node: gazebo_ros2_control
[gzserver-2] [INFO] [1723102716.438024448] [gazebo_ros2_control]: Loading parameter files /home/flamethrower/robot_ws/install/robot/share/robot/config/my_controllers.yaml
[gzserver-2] [INFO] [1723102716.473346392] [gazebo_ros2_control]: connected to service!! robot_state_publisher
[spawner.py-5] [INFO] [1723102716.488072034] [spawner_diff_cont]: Waiting for /controller_manager services
[spawner.py-6] [ERROR] [1723102718.254364669] [spawner_joint_broad]: Controller manager not available
[spawner.py-5] [ERROR] [1723102718.317288322] [spawner_diff_cont]: Controller manager not available
[ERROR] [spawner.py-6]: process has died [pid 5198, exit code 1, cmd '/opt/ros/foxy/lib/controller_manager/spawner.py joint_broad --ros-args'].
[ERROR] [spawner.py-5]: process has died [pid 5188, exit code 1, cmd '/opt/ros/foxy/lib/controller_manager/spawner.py diff_cont --ros-args'].

Maybe it's because I ran rosdep, although now gazebo_ros2_control seems to die even earlier, before printing the state interfaces. The entity spawner works now, though.

[christophfroehlich]

there is no indication that the gazebo plugin dies. The spawners just die because of the timeout, you can increase that with --controller-manager-timeout or even split your launch files for testing and manually spawn the controllers after gazebo is running.

[Flamethr0wer]

Well that means I got yet another output. After rebooting, I actually get the original output now... Also, launching the demo and then my package doesn't change the output anymore, which is weird. I can't find any major differences between the files, either, just that mine uses the spawner.py instead of commands and that I use split urdf and launch files and include them in a main one...

[Flamethr0wer]

Does the invalid argument line mean that it's something to do with the .yaml file? Also, how do I change that timeout argument if I'm in a launch file?

[christophfroehlich]

Also, how do I change that timeout argument if I'm in a launch file?

https://github.com/ros-controls/ros2_control_demos/blob/1d520486eebaebecb9932493b61e42e69a14ef54/example_1/bringup/launch/rrbot.launch.py#L91-L95

[Flamethr0wer]

Okay, I added more time, but gazebo_ros2_control still crashes. But is this line

[gzserver-2] what(): Invalid argument

the error that's causing the crash?

[Flamethr0wer]

It was the dot...
update_rate: 30.0
It had to be
update_rate: 30
Although I don't understand why the publish rate in the diff_cont controller accepts decimal places but the one in the controller_manager doesn't. Anyway, I'm happy I managed to solve it.
No, wait, that solved it for me, but Josh Newans' package on GitHub did not have the dot and didn't work before, either... That is weird.

[Flamethr0wer]

The output is inconsistent between reboots, I'm not sure why gzserver just dies sometimes.