search

ros-controls / gazebo_ros2_control

Wrappers, tools and additional API's for using ros2_control with Gazebo Classic
Apache License 2.0
210 stars 125 forks source link

gazebo_ros2_control crashes when trying to load controller_manager #364

Open Flamethr0wer opened 3 months ago

Flamethr0wer commented 3 months ago

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 commented 3 months ago

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 commented 3 months ago

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 commented 3 months ago

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 commented 3 months ago

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 commented 3 months ago

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 commented 3 months ago

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 commented 3 months ago

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 commented 3 months ago

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 commented 3 months ago

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