Open YumengXiu opened 1 month ago
voshch
commented
2 weeks ago Hey, this is caused by Gazebo's ModelState requests being asynchronous, sometimes causing write-after-writes. This shouldn't affect your simulation though, except for printing error messages. Does this cause any other issues?
YumengXiu
commented
2 weeks ago Thanks for the reply, the issue is that the simulator and Rviz will stop resetting and get frozen after printing the error message, looks like it only happens when I use Gazebo, fitland seems to be more stable.
voshch
commented
2 weeks ago When the simulation gets stuck and you manually kill it (with SIGINT/SIGHUP), a python stack trace from task_generator_node.py should be printed in the terminal (as white text) after a few seconds. Can you share that segment or your entire terminal output?
YumengXiu
commented
2 weeks ago Here's the entire terminal output when I manually kill it.
[INFO] [1718676168.928679, 7.570000]: resetting
[ERROR] [1718676170.839208149, 7.570000000]: Updating ModelState: model [D_actor1_1] does not exist
[ERROR] [1718676170.839569126, 7.570000000]: Updating ModelState: model [D_actor1_2] does not exist
[ERROR] [1718676170.839967197, 7.570000000]: Updating ModelState: model [D_actor1_3] does not exist
[ERROR] [1718676170.840322791, 7.570000000]: Updating ModelState: model [D_actor1_4] does not exist
[INFO] [1718676170.879787, 7.574000]: =============
[INFO] [1718676170.882457, 7.577000]: Task Reset!
[INFO] [1718676170.888916, 7.584000]: =============
[ERROR] [1718676170.904646, 7.600000]: Characters replaced when decoding message pedsim_msgs/AgentStates (will print only once): 'utf-8' codec can't decode byte 0xff in position 0: invalid start byte
[ERROR] [1718676170.906722, 7.602000]: Characters replaced when decoding message rosgraph_msgs/Clock (will print only once): 'utf-8' codec can't decode byte 0xff in position 0: invalid start byte
[INFO] [1718676170.907697, 7.603000]: Spawning dynamic obstacle: actor_id = D_actor1_1
[ WARN] [1718676170.923829257, 7.619000000]: The origin for the sensor at (9.74, 6.19) is out of map bounds. So, the costmap cannot raytrace for it.
[ WARN] [1718676171.082641643, 7.761000000]: Could not find <model> or <world> element in sdf, so name and initial position cannot be applied
[INFO] [1718676172.239145, 7.961000]: Spawning dynamic obstacle: actor_id = D_actor1_2
[ WARN] [1718676172.741508077, 8.087000000]: Could not find <model> or <world> element in sdf, so name and initial position cannot be applied
[INFO] [1718676173.336911, 8.182000]: Spawning dynamic obstacle: actor_id = D_actor1_3
[ WARN] [1718676173.778875620, 8.363000000]: Could not find <model> or <world> element in sdf, so name and initial position cannot be applied
[INFO] [1718676174.435203, 8.412000]: Spawning dynamic obstacle: actor_id = D_actor1_4
[ WARN] [1718676174.864677130, 8.537000000]: Could not find <model> or <world> element in sdf, so name and initial position cannot be applied
[ WARN] [1718676177.642092093, 9.126000000]: WARNING: package://spencer_tracking_rviz_plugin/media/animated_walking_man.mesh is an older format ([MeshSerializer_v1.41]); you should upgrade it as soon as possible using the OgreMeshUpgrade tool.
[ WARN] [1718676177.642217707, 9.126000000]: Can't assign material male_base_lambert1 to SubEntity of mesh_person_visual0 because this Material does not exist. Have you forgotten to define it in a .material script?
[ WARN] [1718676177.644330547, 9.128000000]: Can't assign material male_base_lambert1 to SubEntity of mesh_person_visual1 because this Material does not exist. Have you forgotten to define it in a .material script?
[ WARN] [1718676177.644500525, 9.128000000]: Can't assign material male_base_lambert1 to SubEntity of mesh_person_visual2 because this Material does not exist. Have you forgotten to define it in a .material script?
[ WARN] [1718676177.644632967, 9.128000000]: Can't assign material male_base_lambert1 to SubEntity of mesh_person_visual3 because this Material does not exist. Have you forgotten to define it in a .material script?
[Wrn] [Publisher.cc:135] Queue limit reached for topic /gazebo/default/pose/local/info, deleting message. This warning is printed only once.
[ WARN] [1718676307.292479341, 52.384000000]: The controller is oscillating for 10.001s
[ WARN] [1718676307.292531993, 52.384000000]: Controller defers handling cancel; force it and wait until the current control cycle finished
[ WARN] [1718676307.388782689, 52.482000000]: Recovery behaviors are disabled!
[ WARN] [1718676307.388812282, 52.482000000]: Abort the execution of the controller: Oscillation detected!
[ERROR] [1718676338.618420, 62.093000]: Characters replaced when decoding message gazebo_msgs/SetModelStateResponse (will print only once): 'utf-8' codec can't decode byte 0xff in position 0: invalid start byte
[INFO] [1718676352.846049, 67.313000]: resetting
[ERROR] [1718676355.352659, 67.313000]: Characters replaced when decoding message pedsim_msgs/Walls (will print only once): 'utf-8' codec can't decode byte 0xff in position 0: invalid start byte
[ERROR] [1718676355.483482978, 67.313000000]: Updating ModelState: model [D_actor1_5] does not exist
^C[visualize_robot_model-15] killing on exit
[rviz_config_file_creator-14] killing on exit
[task_generator_filewatcher-13] killing on exit
[task_generator_node-11] killing on exit
[map_to_odom_tfpublisher-10] killing on exit
[task_generator_server-12] killing on exit
[map_server-7] killing on exit
[map_clock_simulator-9] killing on exit
[distance_server-8] killing on exit
[rviz-5] killing on exit
[burger_0_2/map_to_odom_tfpublisher-6] killing on exit
[burger_0_2/move_base_legacy_relay-5] killing on exit
[burger_0_2/move_base_flex-4] killing on exit
[burger_0_2/mbf_cmd_vel_relay-3] killing on exit
[burger_0_2/rob_st_pub-2] killing on exit
[burger_0_2/transform_broadcaster-1] killing on exit
[ WARN] [1718676475.904215371, 67.313000000]: Controller defers handling cancel; force it and wait until the current control cycle finished
[pedsim_visualizer-3] killing on exit
[gazebo-4] killing on exit
[ERROR] [1718676476.387484, 67.313000]: ServiceException("transport error completing service call: unable to receive data from sender, check sender's logs for details")
[ WARN] [1718676476.404530770, 67.313000000]: Timeout while waiting for control cycle to stop; immediately sent goals can get stuck
[ERROR] [1718676476.413714, 67.313000]: bad callback: <bound method PedsimManager._obstacle_callback of <task_generator.manager.entity_manager.pedsim_manager.PedsimManager object at 0x7f84f1525a90>>
Traceback (most recent call last):
File "/opt/ros/noetic/lib/python3/dist-packages/rospy/impl/tcpros_service.py", line 523, in call
responses = transport.receive_once()
File "/opt/ros/noetic/lib/python3/dist-packages/rospy/impl/tcpros_base.py", line 744, in receive_once
self.stat_bytes += recv_buff(sock, b, p.buff_size)
File "/opt/ros/noetic/lib/python3/dist-packages/rospy/impl/tcpros_base.py", line 111, in recv_buff
raise TransportTerminated("unable to receive data from sender, check sender's logs for details")
rospy.exceptions.TransportTerminated: unable to receive data from sender, check sender's logs for details
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/opt/ros/noetic/lib/python3/dist-packages/rospy/topics.py", line 750, in _invoke_callback
cb(msg)
File "/home/yumengxiu/arena_ws/src/arena/arena-rosnav/task_generator/task_generator/manager/entity_manager/pedsim_manager.py", line 629, in _obstacle_callback
self._simulator.move_entity(
File "/home/yumengxiu/arena_ws/src/arena/arena-rosnav/task_generator/task_generator/simulators/gazebo_simulator.py", line 97, in move_entity
return bool(self._move_model_srv(request).success)
File "/opt/ros/noetic/lib/python3/dist-packages/rospy/impl/tcpros_service.py", line 442, in __call__
return self.call(*args, **kwds)
File "/opt/ros/noetic/lib/python3/dist-packages/rospy/impl/tcpros_service.py", line 533, in call
raise ServiceException("transport error completing service call: %s"%(str(e)))
rospy.service.ServiceException: transport error completing service call: unable to receive data from sender, check sender's logs for details
[pedsim_simulator-2] killing on exit
terminate called without an active exception
Exception in thread Thread-40:
Traceback (most recent call last):
File "/opt/ros/noetic/lib/python3/dist-packages/rospy/impl/tcpros_service.py", line 523, in call
responses = transport.receive_once()
File "/opt/ros/noetic/lib/python3/dist-packages/rospy/impl/tcpros_base.py", line 744, in receive_once
self.stat_bytes += recv_buff(sock, b, p.buff_size)
File "/opt/ros/noetic/lib/python3/dist-packages/rospy/impl/tcpros_base.py", line 111, in recv_buff
raise TransportTerminated("unable to receive data from sender, check sender's logs for details")
rospy.exceptions.TransportTerminated: unable to receive data from sender, check sender's logs for details
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/home/yumengxiu/arena_ws/src/arena/arena-rosnav/task_generator/task_generator/tasks/task_factory.py", line 225, in _reset_task
self.obstacle_manager.respawn(respawn)
File "/home/yumengxiu/arena_ws/src/arena/arena-rosnav/task_generator/task_generator/manager/obstacle_manager.py", line 68, in respawn
self._entity_manager.remove_obstacles(purge=ObstacleLayer.UNUSED)
File "/home/yumengxiu/arena_ws/src/arena/arena-rosnav/task_generator/task_generator/manager/entity_manager/pedsim_manager.py", line 563, in remove_obstacles
action()
File "/home/yumengxiu/arena_ws/src/arena/arena-rosnav/task_generator/task_generator/manager/entity_manager/pedsim_manager.py", line 535, in anon1
self._simulator.move_entity(
File "/home/yumengxiu/arena_ws/src/arena/arena-rosnav/task_generator/task_generator/simulators/gazebo_simulator.py", line 97, in move_entity
return bool(self._move_model_srv(request).success)
File "/opt/ros/noetic/lib/python3/dist-packages/rospy/impl/tcpros_service.py", line 442, in __call__
return self.call(*args, **kwds)
File "/opt/ros/noetic/lib/python3/dist-packages/rospy/impl/tcpros_service.py", line 533, in call
raise ServiceException("transport error completing service call: %s"%(str(e)))
rospy.service.ServiceException: transport error completing service call: unable to receive data from sender, check sender's logs for details
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/usr/lib/python3.8/threading.py", line 932, in _bootstrap_inner
self.run()
File "/opt/ros/noetic/lib/python3/dist-packages/rospy/timer.py", line 237, in run
self._callback(TimerEvent(last_expected, last_real, current_expected, current_real, last_duration))
File "/home/yumengxiu/arena_ws/src/arena/arena-rosnav/task_generator/task_generator/task_generator_node.py", line 336, in _check_task_status
self.reset_task()
File "/home/yumengxiu/arena_ws/src/arena/arena-rosnav/task_generator/task_generator/task_generator_node.py", line 320, in reset_task
is_end = self._task.reset(callback=lambda: False, **kwargs)
File "/home/yumengxiu/arena_ws/src/arena/arena-rosnav/task_generator/task_generator/tasks/task_factory.py", line 282, in reset
self._mutex_reset_task(**kwargs)
File "/home/yumengxiu/arena_ws/src/arena/arena-rosnav/task_generator/task_generator/tasks/task_factory.py", line 265, in _mutex_reset_task
raise e
File "/home/yumengxiu/arena_ws/src/arena/arena-rosnav/task_generator/task_generator/tasks/task_factory.py", line 262, in _mutex_reset_task
self._reset_task()
File "/home/yumengxiu/arena_ws/src/arena/arena-rosnav/task_generator/task_generator/tasks/task_factory.py", line 235, in _reset_task
raise Exception("reset error!") from e
Exception: reset error!
[rviz-5] escalating to SIGTERM
[task_generator_node-11] escalating to SIGTERM
[burger_0_2/move_base_flex-4] escalating to SIGTERM
[gazebo-4] escalating to SIGTERM
[burger_1_2/map_to_odom_tfpublisher-12] killing on exit
[burger_1_2/move_base_legacy_relay-11] killing on exit
[burger_1_2/move_base_flex-10] killing on exit
[burger_1_2/mbf_cmd_vel_relay-9] killing on exit
[ WARN] [1718676491.250533213, 67.313000000]: Controller defers handling cancel; force it and wait until the current control cycle finished
[burger_1_2/rob_st_pub-8] killing on exit
[burger_1_2/transform_broadcaster-7] killing on exit
[ WARN] [1718676491.750932941, 67.313000000]: Timeout while waiting for control cycle to stop; immediately sent goals can get stuck
[task_generator_node-11] escalating to SIGKILL
[rviz-5] escalating to SIGKILL
[rosout-1] killing on exit
[master] killing on exit
Shutdown errors:
* process[task_generator_node-11, pid 7565]: required SIGKILL. May still be running.
* process[rviz-5, pid 7545]: required SIGKILL. May still be running.
shutting down processing monitor...
... shutting down processing monitor complete
done
I was using the pedsim entity_manager with Gazebo Simulator, for the first few epochs it works well, but the simulator shows the error after resetting:
[ WARN] [1715895663.979357211, 63.634000000]: Map update loop missed its desired rate of 5.0000Hz... the loop actually took 0.2490 seconds [WARN] [1715895666.423746, 64.375000]: REACHED 60.0
[ERROR] [1715895667.837760847, 64.379000000]: Updating ModelState: model [D_actor1_5] does not exist
Looks like it only shows the error when I use the Gazebo simulator, How can I fix this issue?