search

gazebosim / gazebo-classic

Gazebo classic. For the latest version, see https://github.com/gazebosim/gz-sim
http://classic.gazebosim.org/
Other
1.17k stars 476 forks source link

Services calls [/shadow_caster_material_name] and [/shadow_caster_render_back_faces] timed out, making Gazebo and ROS launchers unusable #3173

Closed ljaniec closed 2 years ago

ljaniec commented 2 years ago

Setup: Ubuntu 20.04, ROS 2 Galactic, Gazebo (11.10.1-1~focal)

With the update to the gazebo11 (ver 11.10.1) in the last ROS 2 Galactic sync my launch files and Gazebo overall stopped working correctly (services are timed out).

dpkg -l | grep gazebo
ii  gazebo11                                            11.10.1-1~focal                           amd64        Open Source Robotics Simulator
ii  gazebo11-common                                     11.10.1-1~focal                           all          Open Source Robotics Simulator - Shared files
ii  gazebo11-plugin-base                                11.10.1-1~focal                           amd64        Open Source Robotics Simulator - base plug-ins
ii  libgazebo11:amd64                                   11.10.1-1~focal                           amd64        Open Source Robotics Simulator - shared library
ii  libgazebo11-dev:amd64                               11.10.1-1~focal                           amd64        Open Source Robotics Simulator - Development Files
ii  ros-galactic-gazebo-dev                             3.5.2-5focal.20220124.195852              amd64        Provides a cmake config for the default version of Gazebo for the ROS distribution.
ii  ros-galactic-gazebo-msgs                            3.5.2-5focal.20220202.225637              amd64        Message and service data structures for interacting with Gazebo from ROS2.
ii  ros-galactic-gazebo-plugins                         3.5.2-5focal.20220203.025751              amd64        Robot-independent Gazebo plugins for sensors, motors and dynamic reconfigurable components.
ii  ros-galactic-gazebo-ros                             3.5.2-5focal.20220203.021749              amd64        Utilities to interface with Gazebo through ROS.
ii  ros-galactic-gazebo-ros-pkgs                        3.5.2-5focal.20220203.035839              amd64        Interface for using ROS with the Gazebo simulator.
ii  ros-galactic-nav2-gazebo-spawner                    1.0.8-1focal.20220203.014643              amd64        Package for spawning a robot model into Gazebo for Nav2
ii  ros-galactic-turtlebot3-gazebo                      2.2.4-2focal.20220203.040439              amd64        Gazebo simulation package for the TurtleBot3
ii  ros-galactic-turtlebot3-gazebo-dbgsym               2.2.4-2focal.20220203.040439              amd64        debug symbols for ros-galactic-turtlebot3-gazebo

After starting gazebo --verbose I got:

~$ gazebo --verbose
Gazebo multi-robot simulator, version 11.10.1
Copyright (C) 2012 Open Source Robotics Foundation.
Released under the Apache 2 License.
http://gazebosim.org

[Msg] Waiting for master.
Gazebo multi-robot simulator, version 11.10.1
Copyright (C) 2012 Open Source Robotics Foundation.
Released under the Apache 2 License.
http://gazebosim.org

[Msg] Waiting for master.
[Msg] Connected to gazebo master @ http://127.0.0.1:11345
[Msg] Publicized address: 192.168.10.103
[Msg] Loading world file [/usr/share/gazebo-11/worlds/empty.world]
[Msg] Connected to gazebo master @ http://127.0.0.1:11345
[Msg] Publicized address: 192.168.10.103
[Err] [Scene.cc:227] Service call[/shadow_caster_material_name] timed out
[Err] [Scene.cc:249] Service call[/shadow_caster_render_back_faces] timed out
[Wrn] [Scene.cc:462] Ignition transport [/scene_info] service call failed, falling back to gazebo transport [scene_info] request.

Part of the terminal logs after using my simulation launch file:

[nav2_gazebo_spawner-2] [INFO] [1644595446.406743712] [entity_spawner]: Creating Service client to connect to `/spawn_entity`
[nav2_gazebo_spawner-3] [INFO] [1644595446.462208129] [entity_spawner]: Creating Service client to connect to `/spawn_entity`
[nav2_gazebo_spawner-4] [INFO] [1644595446.469925262] [entity_spawner]: Creating Service client to connect to `/spawn_entity`
[gazebo-1] Gazebo multi-robot simulator, version 11.10.1
[gazebo-1] Copyright (C) 2012 Open Source Robotics Foundation.
[gazebo-1] Released under the Apache 2 License.
[gazebo-1] http://gazebosim.org
[gazebo-1] 
[nav2_gazebo_spawner-2] [INFO] [1644595446.663426899] [entity_spawner]: Connecting to `/spawn_entity` service...
[gazebo-1] Gazebo multi-robot simulator, version 11.10.1
[gazebo-1] Copyright (C) 2012 Open Source Robotics Foundation.
[gazebo-1] Released under the Apache 2 License.
[gazebo-1] http://gazebosim.org
[gazebo-1] 
[nav2_gazebo_spawner-3] [INFO] [1644595446.739736214] [entity_spawner]: Connecting to `/spawn_entity` service...
[nav2_gazebo_spawner-4] [INFO] [1644595446.744334475] [entity_spawner]: Connecting to `/spawn_entity` service...
[rviz2-16] [INFO] [1644595448.921861782] [rviz2]: Stereo is NOT SUPPORTED
[rviz2-16] [INFO] [1644595448.922153597] [rviz2]: OpenGl version: 4.6 (GLSL 4.6)
[rviz2-16] [INFO] [1644595449.036399848] [rviz2]: Stereo is NOT SUPPORTED
[rviz2-5] [INFO] [1644595449.040512526] [rviz2]: Stereo is NOT SUPPORTED
[rviz2-5] [INFO] [1644595449.040642670] [rviz2]: OpenGl version: 4.6 (GLSL 4.6)
[rviz2-5] [INFO] [1644595449.157253467] [rviz2]: Stereo is NOT SUPPORTED
[rviz2-27] [INFO] [1644595449.219489985] [rviz2]: Stereo is NOT SUPPORTED
[rviz2-27] [INFO] [1644595449.219624549] [rviz2]: OpenGl version: 4.6 (GLSL 4.6)
[rviz2-27] [INFO] [1644595449.314909029] [rviz2]: Stereo is NOT SUPPORTED
[gazebo-1] [Msg] Waiting for master.
[gazebo-1] [Msg] Connected to gazebo master @ http://127.0.0.1:11345
[gazebo-1] [Msg] Publicized address: 192.168.10.103
[gazebo-1] [Err] [Scene.cc:227] Service call[/shadow_caster_material_name] timed out
[gazebo-1] [Err] [Scene.cc:249] Service call[/shadow_caster_render_back_faces] timed out
[gazebo-1] [Wrn] [Scene.cc:462] Ignition transport [/scene_info] service call failed, falling back to gazebo transport [scene_info] request.

But I could put the robot manually in the world, with this output:

[gazebo-1] [INFO] [1644595511.485998038] [turtlebot3_imu]: <initial_orientation_as_reference> is unset, using default value of false to comply with REP 145 (world as orientation reference)
[gazebo-1] [INFO] [1644595511.786551485] [turtlebot3_diff_drive]: Wheel pair 1 separation set to [0.160000m]
[gazebo-1] [INFO] [1644595511.786631388] [turtlebot3_diff_drive]: Wheel pair 1 diameter set to [0.066000m]
[gazebo-1] [INFO] [1644595511.788092149] [turtlebot3_diff_drive]: Subscribed to [/cmd_vel]
[gazebo-1] [INFO] [1644595511.790290199] [turtlebot3_diff_drive]: Advertise odometry on [/odom]
[gazebo-1] [INFO] [1644595511.792370222] [turtlebot3_diff_drive]: Publishing odom transforms between [odom] and [base_footprint]
[gazebo-1] [INFO] [1644595511.810008709] [turtlebot3_joint_state]: Going to publish joint [wheel_left_joint]
[gazebo-1] [INFO] [1644595511.810074926] [turtlebot3_joint_state]: Going to publish joint [wheel_right_joint]

Reverting to the old version of Gazebo packages didn't help, but I am not sure if I did it correctly too (maybe I have missed some dependent ROS packages). I have used:

sudo apt-get install gazebo11=11.9.0-1~focal gazebo11-common=11.9.0-1~focal gazebo11-plugin-base=11.9.0-1~focal libgazebo11=11.9.0-1~focal libgazebo11-dev=11.9.0-1~focal

Launcher still won't work even after that.

relffok commented 2 years ago

I ran into this issue on one of my machines as well. Latest galactic sync, though I am still on Gazebo 11.9 and I experience the exact same behavior when starting gazebo without anything loaded. Running gazebo or ros2 launch gazebo_ros gazebo.launch.py results in the same.

scpeters commented 2 years ago

it sounds like ignition transport services are not working properly, and this causes gazebo to fail to load? Do you see anything in gzclient? It should still attempt to load the scene using gazebo-transport

ljaniec commented 2 years ago

image

Gazebo starts with empty.world scene, but any launcher (mine or from Nav2 repository and nav2_bringup package, branch" galactic, commit: 4bfedb8) cannot call any services (in particular spawn_entity). Example: ljaniec@ljaniec-PC:~/ros2_ws$ ros2 launch nav2_bringup multi_tb3_simulation_launch.py gives: image

Terminal log:

ljaniec@ljaniec-PC:~/ros2_ws$ ros2 launch nav2_bringup multi_tb3_simulation_launch.py
[INFO] [launch]: All log files can be found below /home/ljaniec/.ros/log/2022-02-14-09-57-57-833592-ljaniec-PC-100093
[INFO] [launch]: Default logging verbosity is set to INFO
[INFO] [launch.user]: Launching robot1
[INFO] [launch.user]: robot1 map yaml: /home/ljaniec/nav2_ws/install/nav2_bringup/share/nav2_bringup/maps/turtlebot3_world.yaml
[INFO] [launch.user]: robot1 params yaml: /home/ljaniec/nav2_ws/install/nav2_bringup/share/nav2_bringup/params/nav2_multirobot_params_1.yaml
[INFO] [launch.user]: robot1 rviz config file: /home/ljaniec/nav2_ws/install/nav2_bringup/share/nav2_bringup/rviz/nav2_namespaced_view.rviz
[INFO] [launch.user]: robot1 using robot state pub: True
[INFO] [launch.user]: robot1 autostart: false
[INFO] [launch.user]: Launching robot2
[INFO] [launch.user]: robot2 map yaml: /home/ljaniec/nav2_ws/install/nav2_bringup/share/nav2_bringup/maps/turtlebot3_world.yaml
[INFO] [launch.user]: robot2 params yaml: /home/ljaniec/nav2_ws/install/nav2_bringup/share/nav2_bringup/params/nav2_multirobot_params_2.yaml
[INFO] [launch.user]: robot2 rviz config file: /home/ljaniec/nav2_ws/install/nav2_bringup/share/nav2_bringup/rviz/nav2_namespaced_view.rviz
[INFO] [launch.user]: robot2 using robot state pub: True
[INFO] [launch.user]: robot2 autostart: false
[INFO] [gazebo-1]: process started with pid [100095]
[INFO] [nav2_gazebo_spawner-2]: process started with pid [100097]
[INFO] [nav2_gazebo_spawner-3]: process started with pid [100099]
[INFO] [rviz2-4]: process started with pid [100101]
[INFO] [robot_state_publisher-5]: process started with pid [100103]
[INFO] [map_server-6]: process started with pid [100105]
[INFO] [amcl-7]: process started with pid [100107]
[INFO] [lifecycle_manager-8]: process started with pid [100109]
[INFO] [controller_server-9]: process started with pid [100111]
[INFO] [planner_server-10]: process started with pid [100113]
[INFO] [recoveries_server-11]: process started with pid [100115]
[INFO] [bt_navigator-12]: process started with pid [100118]
[INFO] [waypoint_follower-13]: process started with pid [100128]
[INFO] [lifecycle_manager-14]: process started with pid [100131]
[INFO] [rviz2-15]: process started with pid [100140]
[INFO] [robot_state_publisher-16]: process started with pid [100202]
[INFO] [map_server-17]: process started with pid [100205]
[INFO] [amcl-18]: process started with pid [100210]
[INFO] [lifecycle_manager-19]: process started with pid [100213]
[INFO] [controller_server-20]: process started with pid [100233]
[INFO] [planner_server-21]: process started with pid [100256]
[INFO] [recoveries_server-22]: process started with pid [100280]
[INFO] [bt_navigator-23]: process started with pid [100282]
[INFO] [waypoint_follower-24]: process started with pid [100285]
[INFO] [lifecycle_manager-25]: process started with pid [100299]
[robot_state_publisher-5] [WARN] [1644829080.969024678] [robot1.robot_state_publisher]: No robot_description parameter, but command-line argument available.  Assuming argument is name of URDF file.  This backwards compatibility fallback will be removed in the future.
[robot_state_publisher-5] Link base_link had 7 children
[robot_state_publisher-5] Link camera_link had 2 children
[robot_state_publisher-5] Link camera_depth_frame had 1 children
[robot_state_publisher-5] Link camera_depth_optical_frame had 0 children
[robot_state_publisher-5] Link camera_rgb_frame had 1 children
[robot_state_publisher-5] Link camera_rgb_optical_frame had 0 children
[robot_state_publisher-5] Link caster_back_left_link had 0 children
[robot_state_publisher-5] Link caster_back_right_link had 0 children
[robot_state_publisher-5] Link imu_link had 0 children
[robot_state_publisher-5] Link base_scan had 0 children
[robot_state_publisher-5] Link wheel_left_link had 0 children
[robot_state_publisher-5] Link wheel_right_link had 0 children
[robot_state_publisher-5] [INFO] [1644829080.991185796] [robot1.robot_state_publisher]: got segment base_footprint
[robot_state_publisher-5] [INFO] [1644829080.991247898] [robot1.robot_state_publisher]: got segment base_link
[robot_state_publisher-5] [INFO] [1644829080.991270284] [robot1.robot_state_publisher]: got segment base_scan
[robot_state_publisher-5] [INFO] [1644829080.991287645] [robot1.robot_state_publisher]: got segment camera_depth_frame
[robot_state_publisher-5] [INFO] [1644829080.991303937] [robot1.robot_state_publisher]: got segment camera_depth_optical_frame
[robot_state_publisher-5] [INFO] [1644829080.991320379] [robot1.robot_state_publisher]: got segment camera_link
[robot_state_publisher-5] [INFO] [1644829080.991336675] [robot1.robot_state_publisher]: got segment camera_rgb_frame
[robot_state_publisher-5] [INFO] [1644829080.991352250] [robot1.robot_state_publisher]: got segment camera_rgb_optical_frame
[robot_state_publisher-5] [INFO] [1644829080.991380784] [robot1.robot_state_publisher]: got segment caster_back_left_link
[robot_state_publisher-5] [INFO] [1644829080.991397871] [robot1.robot_state_publisher]: got segment caster_back_right_link
[robot_state_publisher-5] [INFO] [1644829080.991413859] [robot1.robot_state_publisher]: got segment imu_link
[robot_state_publisher-5] [INFO] [1644829080.991430304] [robot1.robot_state_publisher]: got segment wheel_left_link
[robot_state_publisher-5] [INFO] [1644829080.991447087] [robot1.robot_state_publisher]: got segment wheel_right_link
[map_server-6] [INFO] [1644829081.009438210] [robot1.map_server]: 
[map_server-6]  map_server lifecycle node launched. 
[map_server-6]  Waiting on external lifecycle transitions to activate
[map_server-6]  See https://design.ros2.org/articles/node_lifecycle.html for more information.
[map_server-6] [INFO] [1644829081.009582716] [robot1.map_server]: Creating
[amcl-7] [INFO] [1644829080.992456313] [robot1.amcl]: 
[amcl-7]    amcl lifecycle node launched. 
[amcl-7]    Waiting on external lifecycle transitions to activate
[amcl-7]    See https://design.ros2.org/articles/node_lifecycle.html for more information.
[amcl-7] [INFO] [1644829080.992598171] [robot1.amcl]: Creating
[lifecycle_manager-8] [INFO] [1644829080.983211932] [robot1.lifecycle_manager_localization]: Creating
[lifecycle_manager-8] [INFO] [1644829080.994111745] [robot1.lifecycle_manager_localization]: Creating and initializing lifecycle service clients
[controller_server-9] [INFO] [1644829080.992024222] [robot1.controller_server]: 
[controller_server-9]   controller_server lifecycle node launched. 
[controller_server-9]   Waiting on external lifecycle transitions to activate
[controller_server-9]   See https://design.ros2.org/articles/node_lifecycle.html for more information.
[controller_server-9] [INFO] [1644829081.017305619] [robot1.controller_server]: Creating controller server
[controller_server-9] [INFO] [1644829081.046057477] [robot1.local_costmap.local_costmap]: 
[controller_server-9]   local_costmap lifecycle node launched. 
[controller_server-9]   Waiting on external lifecycle transitions to activate
[controller_server-9]   See https://design.ros2.org/articles/node_lifecycle.html for more information.
[controller_server-9] [INFO] [1644829081.048511420] [robot1.local_costmap.local_costmap]: Creating Costmap
[planner_server-10] [INFO] [1644829080.995973997] [robot1.planner_server]: 
[planner_server-10]     planner_server lifecycle node launched. 
[planner_server-10]     Waiting on external lifecycle transitions to activate
[planner_server-10]     See https://design.ros2.org/articles/node_lifecycle.html for more information.
[planner_server-10] [INFO] [1644829081.008384204] [robot1.planner_server]: Creating
[planner_server-10] [INFO] [1644829081.020677744] [robot1.global_costmap.global_costmap]: 
[planner_server-10]     global_costmap lifecycle node launched. 
[planner_server-10]     Waiting on external lifecycle transitions to activate
[planner_server-10]     See https://design.ros2.org/articles/node_lifecycle.html for more information.
[planner_server-10] [INFO] [1644829081.023179014] [robot1.global_costmap.global_costmap]: Creating Costmap
[recoveries_server-11] [INFO] [1644829080.996893989] [robot1.recoveries_server]: 
[recoveries_server-11]  recoveries_server lifecycle node launched. 
[recoveries_server-11]  Waiting on external lifecycle transitions to activate
[recoveries_server-11]  See https://design.ros2.org/articles/node_lifecycle.html for more information.
[bt_navigator-12] [INFO] [1644829081.010273702] [robot1.bt_navigator]: 
[bt_navigator-12]   bt_navigator lifecycle node launched. 
[bt_navigator-12]   Waiting on external lifecycle transitions to activate
[bt_navigator-12]   See https://design.ros2.org/articles/node_lifecycle.html for more information.
[bt_navigator-12] [INFO] [1644829081.010399554] [robot1.bt_navigator]: Creating
[waypoint_follower-13] [INFO] [1644829081.029140216] [robot1.waypoint_follower]: 
[waypoint_follower-13]  waypoint_follower lifecycle node launched. 
[waypoint_follower-13]  Waiting on external lifecycle transitions to activate
[waypoint_follower-13]  See https://design.ros2.org/articles/node_lifecycle.html for more information.
[waypoint_follower-13] [INFO] [1644829081.031691859] [robot1.waypoint_follower]: Creating
[lifecycle_manager-14] [INFO] [1644829081.037619846] [robot1.lifecycle_manager_navigation]: Creating
[lifecycle_manager-14] [INFO] [1644829081.042200654] [robot1.lifecycle_manager_navigation]: Creating and initializing lifecycle service clients
[robot_state_publisher-16] [WARN] [1644829081.044990805] [robot2.robot_state_publisher]: No robot_description parameter, but command-line argument available.  Assuming argument is name of URDF file.  This backwards compatibility fallback will be removed in the future.
[robot_state_publisher-16] Link base_link had 7 children
[robot_state_publisher-16] Link camera_link had 2 children
[robot_state_publisher-16] Link camera_depth_frame had 1 children
[robot_state_publisher-16] Link camera_depth_optical_frame had 0 children
[robot_state_publisher-16] Link camera_rgb_frame had 1 children
[robot_state_publisher-16] Link camera_rgb_optical_frame had 0 children
[robot_state_publisher-16] Link caster_back_left_link had 0 children
[robot_state_publisher-16] Link caster_back_right_link had 0 children
[robot_state_publisher-16] Link imu_link had 0 children
[robot_state_publisher-16] Link base_scan had 0 children
[robot_state_publisher-16] Link wheel_left_link had 0 children
[robot_state_publisher-16] Link wheel_right_link had 0 children
[robot_state_publisher-16] [INFO] [1644829081.054421308] [robot2.robot_state_publisher]: got segment base_footprint
[robot_state_publisher-16] [INFO] [1644829081.054480494] [robot2.robot_state_publisher]: got segment base_link
[robot_state_publisher-16] [INFO] [1644829081.054503366] [robot2.robot_state_publisher]: got segment base_scan
[robot_state_publisher-16] [INFO] [1644829081.054521753] [robot2.robot_state_publisher]: got segment camera_depth_frame
[robot_state_publisher-16] [INFO] [1644829081.054540079] [robot2.robot_state_publisher]: got segment camera_depth_optical_frame
[robot_state_publisher-16] [INFO] [1644829081.054557950] [robot2.robot_state_publisher]: got segment camera_link
[robot_state_publisher-16] [INFO] [1644829081.054575206] [robot2.robot_state_publisher]: got segment camera_rgb_frame
[robot_state_publisher-16] [INFO] [1644829081.054592992] [robot2.robot_state_publisher]: got segment camera_rgb_optical_frame
[robot_state_publisher-16] [INFO] [1644829081.054610828] [robot2.robot_state_publisher]: got segment caster_back_left_link
[robot_state_publisher-16] [INFO] [1644829081.054628537] [robot2.robot_state_publisher]: got segment caster_back_right_link
[robot_state_publisher-16] [INFO] [1644829081.054646644] [robot2.robot_state_publisher]: got segment imu_link
[robot_state_publisher-16] [INFO] [1644829081.054664950] [robot2.robot_state_publisher]: got segment wheel_left_link
[robot_state_publisher-16] [INFO] [1644829081.054682920] [robot2.robot_state_publisher]: got segment wheel_right_link
[map_server-17] [INFO] [1644829081.062437561] [robot2.map_server]: 
[map_server-17]     map_server lifecycle node launched. 
[map_server-17]     Waiting on external lifecycle transitions to activate
[map_server-17]     See https://design.ros2.org/articles/node_lifecycle.html for more information.
[map_server-17] [INFO] [1644829081.062588103] [robot2.map_server]: Creating
[amcl-18] [INFO] [1644829081.073759304] [robot2.amcl]: 
[amcl-18]   amcl lifecycle node launched. 
[amcl-18]   Waiting on external lifecycle transitions to activate
[amcl-18]   See https://design.ros2.org/articles/node_lifecycle.html for more information.
[amcl-18] [INFO] [1644829081.073916103] [robot2.amcl]: Creating
[lifecycle_manager-19] [INFO] [1644829081.055925866] [robot2.lifecycle_manager_localization]: Creating
[lifecycle_manager-19] [INFO] [1644829081.059712337] [robot2.lifecycle_manager_localization]: Creating and initializing lifecycle service clients
[controller_server-20] [INFO] [1644829081.084105496] [robot2.controller_server]: 
[controller_server-20]  controller_server lifecycle node launched. 
[controller_server-20]  Waiting on external lifecycle transitions to activate
[controller_server-20]  See https://design.ros2.org/articles/node_lifecycle.html for more information.
[planner_server-21] [INFO] [1644829081.105379594] [robot2.planner_server]: 
[planner_server-21]     planner_server lifecycle node launched. 
[planner_server-21]     Waiting on external lifecycle transitions to activate
[planner_server-21]     See https://design.ros2.org/articles/node_lifecycle.html for more information.
[controller_server-20] [INFO] [1644829081.106181847] [robot2.controller_server]: Creating controller server
[waypoint_follower-24] [INFO] [1644829081.108416551] [robot2.waypoint_follower]: 
[waypoint_follower-24]  waypoint_follower lifecycle node launched. 
[waypoint_follower-24]  Waiting on external lifecycle transitions to activate
[waypoint_follower-24]  See https://design.ros2.org/articles/node_lifecycle.html for more information.
[waypoint_follower-24] [INFO] [1644829081.113410569] [robot2.waypoint_follower]: Creating
[planner_server-21] [INFO] [1644829081.113574233] [robot2.planner_server]: Creating
[recoveries_server-22] [INFO] [1644829081.113726286] [robot2.recoveries_server]: 
[recoveries_server-22]  recoveries_server lifecycle node launched. 
[recoveries_server-22]  Waiting on external lifecycle transitions to activate
[recoveries_server-22]  See https://design.ros2.org/articles/node_lifecycle.html for more information.
[lifecycle_manager-25] [INFO] [1644829081.117832026] [robot2.lifecycle_manager_navigation]: Creating
[lifecycle_manager-25] [INFO] [1644829081.121754116] [robot2.lifecycle_manager_navigation]: Creating and initializing lifecycle service clients
[controller_server-20] [INFO] [1644829081.122563788] [robot2.local_costmap.local_costmap]: 
[controller_server-20]  local_costmap lifecycle node launched. 
[controller_server-20]  Waiting on external lifecycle transitions to activate
[controller_server-20]  See https://design.ros2.org/articles/node_lifecycle.html for more information.
[bt_navigator-23] [INFO] [1644829081.124364938] [robot2.bt_navigator]: 
[bt_navigator-23]   bt_navigator lifecycle node launched. 
[bt_navigator-23]   Waiting on external lifecycle transitions to activate
[bt_navigator-23]   See https://design.ros2.org/articles/node_lifecycle.html for more information.
[bt_navigator-23] [INFO] [1644829081.124524149] [robot2.bt_navigator]: Creating
[controller_server-20] [INFO] [1644829081.124560987] [robot2.local_costmap.local_costmap]: Creating Costmap
[planner_server-21] [INFO] [1644829081.124871987] [robot2.global_costmap.global_costmap]: 
[planner_server-21]     global_costmap lifecycle node launched. 
[planner_server-21]     Waiting on external lifecycle transitions to activate
[planner_server-21]     See https://design.ros2.org/articles/node_lifecycle.html for more information.
[planner_server-21] [INFO] [1644829081.127196839] [robot2.global_costmap.global_costmap]: Creating Costmap
[nav2_gazebo_spawner-3] [INFO] [1644829081.702631041] [entity_spawner]: Creating Service client to connect to `/spawn_entity`
[nav2_gazebo_spawner-2] [INFO] [1644829081.713785751] [entity_spawner]: Creating Service client to connect to `/spawn_entity`
[gazebo-1] Gazebo multi-robot simulator, version 11.10.1
[gazebo-1] Copyright (C) 2012 Open Source Robotics Foundation.
[gazebo-1] Released under the Apache 2 License.
[gazebo-1] http://gazebosim.org
[gazebo-1] 
[gazebo-1] Gazebo multi-robot simulator, version 11.10.1
[gazebo-1] Copyright (C) 2012 Open Source Robotics Foundation.
[gazebo-1] Released under the Apache 2 License.
[gazebo-1] http://gazebosim.org
[gazebo-1] 
[nav2_gazebo_spawner-3] [INFO] [1644829081.880547719] [entity_spawner]: Connecting to `/spawn_entity` service...
[nav2_gazebo_spawner-2] [INFO] [1644829081.897295888] [entity_spawner]: Connecting to `/spawn_entity` service...
[rviz2-4] [INFO] [1644829082.370616442] [rviz2]: Stereo is NOT SUPPORTED
[rviz2-4] [INFO] [1644829082.370725355] [rviz2]: OpenGl version: 4.6 (GLSL 4.6)
[rviz2-4] [INFO] [1644829082.425365409] [rviz2]: Stereo is NOT SUPPORTED
[rviz2-15] [INFO] [1644829082.462191535] [rviz2]: Stereo is NOT SUPPORTED
[rviz2-15] [INFO] [1644829082.462329768] [rviz2]: OpenGl version: 4.6 (GLSL 4.6)
[rviz2-15] [INFO] [1644829082.509462539] [rviz2]: Stereo is NOT SUPPORTED
[gazebo-1] [Msg] Waiting for master.
[gazebo-1] [Msg] Connected to gazebo master @ http://127.0.0.1:11345
[gazebo-1] [Msg] Publicized address: 192.168.0.101
[gazebo-1] [Err] [Scene.cc:227] Service call[/shadow_caster_material_name] timed out
[gazebo-1] [Err] [Scene.cc:249] Service call[/shadow_caster_render_back_faces] timed out
[gazebo-1] [Wrn] [Scene.cc:462] Ignition transport [/scene_info] service call failed, falling back to gazebo transport [scene_info] request.
[gazebo-1] [Wrn] [Publisher.cc:135] Queue limit reached for topic /gazebo/default/user_camera/pose, deleting message. This warning is printed only once.
relffok commented 2 years ago

it sounds like ignition transport services are not working properly, and this causes gazebo to fail to load? Do you see anything in gzclient? It should still attempt to load the scene using gazebo-transport

Gazebo is loading up and you can see the scene and even use it, though the services are not available. You can also reproduce this by just running the empty world using gazebo --verbose.

Edit: On my second machine this seems to happen randomly, especially when calling gzclient and gzserver seperately. Sometimes they load, sometimes they time out but I don't see a pattern. I am always killing all gzclient and gzserver processes before running again.

ljaniec commented 2 years ago

When starting gzserver --verbose I am getting:

ljaniec@ljaniec-PC:~$ gzserver --verbose
Gazebo multi-robot simulator, version 11.10.1
Copyright (C) 2012 Open Source Robotics Foundation.
Released under the Apache 2 License.
http://gazebosim.org

[Msg] Waiting for master.
[Msg] Connected to gazebo master @ http://127.0.0.1:11345
[Msg] Publicized address: 192.168.0.109
[Msg] Loading world file [/usr/share/gazebo-11/worlds/empty.world]

and gzclient --verbose gives me everytime the same timed-out error:

ljaniec@ljaniec-PC:~$ gzclient --verbose
Gazebo multi-robot simulator, version 11.10.1
Copyright (C) 2012 Open Source Robotics Foundation.
Released under the Apache 2 License.
http://gazebosim.org

[Msg] Waiting for master.
[Msg] Connected to gazebo master @ http://127.0.0.1:11345
[Msg] Publicized address: 192.168.0.109
[Err] [Scene.cc:227] Service call[/shadow_caster_material_name] timed out
[Err] [Scene.cc:249] Service call[/shadow_caster_render_back_faces] timed out
[Wrn] [Scene.cc:462] Ignition transport [/scene_info] service call failed, falling back to gazebo transport [scene_info] request.
ljaniec@ljaniec-PC:~$ gzclient --verbose
Gazebo multi-robot simulator, version 11.10.1
Copyright (C) 2012 Open Source Robotics Foundation.
Released under the Apache 2 License.
http://gazebosim.org

[Msg] Waiting for master.
[Msg] Connected to gazebo master @ http://127.0.0.1:11345
[Msg] Publicized address: 192.168.0.109
[Err] [Scene.cc:227] Service call[/shadow_caster_material_name] timed out
[Err] [Scene.cc:249] Service call[/shadow_caster_render_back_faces] timed out
[Wrn] [Scene.cc:462] Ignition transport [/scene_info] service call failed, falling back to gazebo transport [scene_info] request.
[Wrn] [Publisher.cc:135] Queue limit reached for topic /gazebo/default/user_camera/pose, deleting message. This warning is printed only once.

I tried to reinstall my NVidia drivers too - I got the latest recommended nvidia-driver-510:

== /sys/devices/pci0000:00/0000:00:01.0/0000:01:00.0 ==
modalias : pci:v000010DEd00001C8Dsv000017AAsd000038ECbc03sc02i00
vendor   : NVIDIA Corporation
model    : GP107M [GeForce GTX 1050 Mobile]
driver   : nvidia-driver-510 - distro non-free recommended

and at least I got shadows working (previously everything was much darker than normal).

I haven't found anything more than some issues of the problems with Ogre3d about this kind of services timing out...

There is my ogre.log too: ogre.log

ljaniec commented 2 years ago

I have found something unusual and weird, which maybe could help a bit there - I can use VirtualBox with Ubuntu 20.04 and ROS2 Galactic (binaries from Debian packages) with Gazebo without these errors of timed out services...

What is the source of this really weird situation? What do I have to change in my setup for everything to work?

Will building Gazebo from source help? It's last thing I haven't tried yet...

EDIT: I have done it and it didn't help - I still got the same service calls timed out: image

ljaniec commented 2 years ago

@relffok @scpeters There are some new details found by @beezow:

https://githubhot.com/repo/lopsided98/nix-ros-overlay/issues/161

So while gazebo was working, when trying to use gazebo_ros there were still some problems.

➤ rosrun gazebo_ros gzserver -e ode worlds/emtpy.world --verbose $final Gazebo multi-robot simulator, version 11.9.0 Copyright (C) 2012 Open Source Robotics Foundation. Released under the Apache 2 License. http://gazebosim.org

munmap_chunk(): invalid pointer /nix/store/8fj7m50ag8si1gzgdya7j2v2b9r5z1dw-ros-noetic-gazebo-ros-2.9.2-r1/lib/gazebo_ros/gzserver: line 41: 179679 Aborted (core dumped) GAZEBO_MASTER_URI="$desired_master_uri" GAZEBO_MODEL_DATABASE_URI="$desired_model_database_uri" gzserver $final

I was able to track this down the libgazebo_ros_paths_plugin.so as triggering the fault. When removed from the shared library list for gzserver, the error goes away. I tested this by directly calling gzserver with the args from gazebo_ros. This can be found in /nix/store/8fj7m50ag8si1gzgdya7j2v2b9r5z1dw-ros-noetic-gazebo-ros-2.9.2-r1/lib/gazebo_ros.

gzserver -e ode worlds/empty.world --verbose -s /nix/store/8fj7m50ag8si1gzgdya7j2v2b9r5z1dw-ros-noetic-gazebo-ros-2.9.2-r1/lib/libgazebo_ros_paths_plugin.so -s /nix/store/8fj7m50ag8si1gzgdya7j2v2b9r5z1dw-ros-noetic-gazebo-ros-2.9.2-r1/lib/libgazebo_ros_api_plugin.so

I dont know if this is related or not but wanted to document my efforts to get gazebo working again

and

After doing some debugging, ros::package::getPlugins("gazebo_ros","gazebo_media_path",gazebo_media_paths); in libgazebo_ros_paths_plugin.cpp is causing problems. In fact, every call to ros::package::getPlugins will trigger the fault. (...) If anyone has any insights on what may be causing the issue that would be great. I notice the call stack goes through boost so I wonder if somehow multiple versions are being pulled in? Or maybe something with the rospack dependencies are mucked up?

and

It seems gazebo was pulling in boost 173, while gazebo_ros was pulling in boost 177. By upgrading gazebo to boost177, the segfaults went away. Can finally run gazebo_ros again! You should be able to use the staging branch as it incorporates all the updates needed.

Can someone else can confirm the staging branch works for gazebo_ros?

The only remaining problem is with the shadows. There are some errors related to the shadow caster. The shadows from light sources do not work, with the light shining right through any obstacles.

ljaniec commented 2 years ago

I got some more warnings, maybe they will help:

[Wrn] [Scene.cc:462] Ignition transport [/scene_info] service call failed, falling back to gazebo transport [scene_info] request.

After 1 TurtleBot3 Waffle is added to the empty world and clicking Window > Plot, I can generate this errors:

[Err] [Palette.cc:783] No introspection managers detected.
[Err] [Palette.cc:784] Is a gzserver running?
[Err] [IntrospectionCurveHandler.cc:224] No introspection managers detected.

There are also no ROS2 topics coming from the robot, only:

ljaniec@ljaniec-PC:~$ ros2 topic list
/parameter_events
/rosout
ljaniec commented 2 years ago

There was an update to the Gazebo 11 and by struck of luck I have found out what was maybe not the problem, but at least a solution - I had to reset my Firewall settings in Ubuntu 20.04 because even ros2 topic list wasn't working correctly. Then I tried to launch gazebo --verbose and it didn't hanged, I could add TB3 to the empty world and see it's topics etc.

If this is acceptable solution to this problem, I think this issue could be closed.

mengchaoheng commented 2 years ago

@ljaniec Disconnect from the internet and no more errors.

scpeters commented 2 years ago

can you try setting IGN_IP=127.0.0.1 as an environment variable?

ljaniec commented 2 years ago

I cannot reproduce this error in a meaningful way right now to check it, sorry.

I will close this issue with these steps written down for future users

mengchaoheng commented 2 years ago

I cannot reproduce this error in a meaningful way right now to check it, sorry.

I will close this issue with these steps written down for future users

F*** you