SSL-Roots / consai_ros2

ROS 2 packages for RoboCup SSL beginner. / RoboCup SSL初心者のための ROS 2パッケージ
Apache License 2.0
15 stars 1 forks source link

inplay中にconsaiが落ちた #159

Closed ShotaAk closed 6 months ago

ShotaAk commented 7 months ago

セッティング

異常発生の流れ

ログ

[game.py-4] [INFO] [1706965871.860584791] [referee_parser]: free kickから5秒経過したのでinplayに変わります
[game.py-4] [INFO] [1706965871.996799238] [operator]: Goal rejected
[game.py-4] [INFO] [1706965872.041558025] [operator]: Goal rejected
[game.py-4] Traceback (most recent call last):
[game.py-4]   File "/home/shotaak/ros2_ws/install/consai_examples/lib/consai_examples/game.py", line 230, in <module>
[game.py-4]     main()
[game.py-4]   File "/home/shotaak/ros2_ws/install/consai_examples/lib/consai_examples/game.py", line 118, in main
[game.py-4]     decisions[role].inplay(robot_id)
[game.py-4]   File "/home/shotaak/ros2_ws/src/consai_ros2/consai_examples/consai_examples/decisions/attacker.py", line 103, in inplay
[game.py-4]     shoot_pos_list = self._field_observer.get_open_path_id_list(robot_id)
[game.py-4]   File "/home/shotaak/ros2_ws/src/consai_ros2/consai_examples/consai_examples/field_observer.py", line 724, in get_open_path_id_list
[game.py-4]     can_shoot_id_list, can_shoot_pos_list = self.get_receiver_robots_id(
[game.py-4]   File "/home/shotaak/ros2_ws/src/consai_ros2/consai_examples/consai_examples/field_observer.py", line 832, in get_receiver_robots_id
[game.py-4]     robot_r + math.hypot(their_robot_vel.x, their_robot_vel.y) * dt:
[game.py-4] AttributeError: 'NoneType' object has no attribute 'x'
[game.py-4] terminate called without an active exception
[ERROR] [game.py-4]: process has died [pid 140071, exit code -6, cmd '/home/shotaak/ros2_ws/install/consai_examples/lib/consai_examples/game.py --goalie 0 --ros-args'].
tilt-silvie commented 7 months ago

同じことが 11vs1でも起きました

➜  ros2_ws ros2 launch consai_examples start.launch.py game:=true yellow:=false invert:=false goalie:=0 vision_port:=10020
[INFO] [launch]: All log files can be found below /home/ishikura/.ros/log/2024-02-03-22-22-37-360916-ishikura-ThinkPad-X1-Extreme-2nd-73172
[INFO] [launch]: Default logging verbosity is set to INFO
[INFO] [component_container_mt-1]: process started with pid [73185]
[INFO] [consai_visualizer-2]: process started with pid [73187]
[INFO] [component_container_mt-3]: process started with pid [73189]
[INFO] [game.py-4]: process started with pid [73191]
[component_container_mt-1] [INFO] [1706966557.834344544] [test_container]: Load Library: /home/ishikura/ros2_ws/install/consai_robot_controller/lib/libcontroller_component.so
[component_container_mt-3] [INFO] [1706966557.837549764] [referee_container]: Load Library: /home/ishikura/ros2_ws/install/robocup_ssl_comm/lib/libgame_controller_component.so
[component_container_mt-1] [INFO] [1706966557.839320839] [test_container]: Found class: rclcpp_components::NodeFactoryTemplate<consai_robot_controller::Controller>
[component_container_mt-1] [INFO] [1706966557.839360078] [test_container]: Instantiate class: rclcpp_components::NodeFactoryTemplate<consai_robot_controller::Controller>
[component_container_mt-3] [INFO] [1706966557.841818903] [referee_container]: Found class: rclcpp_components::NodeFactoryTemplate<robocup_ssl_comm::GameController>
[component_container_mt-3] [INFO] [1706966557.841856360] [referee_container]: Instantiate class: rclcpp_components::NodeFactoryTemplate<robocup_ssl_comm::GameController>
[component_container_mt-1] [INFO] [1706966557.845289444] [controller]: is yellow:0
[INFO] [launch_ros.actions.load_composable_nodes]: Loaded node '/game_controller' in container '/referee_container'
[INFO] [launch_ros.actions.load_composable_nodes]: Loaded node '/controller' in container '/test_container'
[component_container_mt-1] [INFO] [1706966557.900379400] [test_container]: Load Library: /home/ishikura/ros2_ws/install/consai_robot_controller/lib/libgrsim_command_converter.so
[component_container_mt-1] [INFO] [1706966557.902297886] [test_container]: Found class: rclcpp_components::NodeFactoryTemplate<consai_robot_controller::GrSimCommandConverter>
[component_container_mt-1] [INFO] [1706966557.902331124] [test_container]: Instantiate class: rclcpp_components::NodeFactoryTemplate<consai_robot_controller::GrSimCommandConverter>
[INFO] [launch_ros.actions.load_composable_nodes]: Loaded node '/command_converter' in container '/test_container'
[component_container_mt-1] [INFO] [1706966557.923369298] [test_container]: Load Library: /home/ishikura/ros2_ws/install/consai_vision_tracker/lib/libtracker_component.so
[component_container_mt-1] [INFO] [1706966557.926832812] [test_container]: Found class: rclcpp_components::NodeFactoryTemplate<consai_vision_tracker::Tracker>
[component_container_mt-1] [INFO] [1706966557.926874352] [test_container]: Instantiate class: rclcpp_components::NodeFactoryTemplate<consai_vision_tracker::Tracker>
[INFO] [launch_ros.actions.load_composable_nodes]: Loaded node '/tracker' in container '/test_container'
[component_container_mt-1] [INFO] [1706966557.946994168] [test_container]: Load Library: /home/ishikura/ros2_ws/install/robocup_ssl_comm/lib/libvision_component.so
[component_container_mt-1] [INFO] [1706966557.952640569] [test_container]: Found class: rclcpp_components::NodeFactoryTemplate<robocup_ssl_comm::Vision>
[component_container_mt-1] [INFO] [1706966557.952683989] [test_container]: Instantiate class: rclcpp_components::NodeFactoryTemplate<robocup_ssl_comm::Vision>
[INFO] [launch_ros.actions.load_composable_nodes]: Loaded node '/vision' in container '/test_container'
[component_container_mt-1] [INFO] [1706966557.966755998] [test_container]: Load Library: /home/ishikura/ros2_ws/install/robocup_ssl_comm/lib/libgrsim_component.so
[component_container_mt-1] [INFO] [1706966557.968965692] [test_container]: Found class: rclcpp_components::NodeFactoryTemplate<robocup_ssl_comm::GrSim>
[component_container_mt-1] [INFO] [1706966557.968997681] [test_container]: Instantiate class: rclcpp_components::NodeFactoryTemplate<robocup_ssl_comm::GrSim>
[INFO] [launch_ros.actions.load_composable_nodes]: Loaded node '/grsim' in container '/test_container'
[game.py-4] [INFO] [1706966558.065057589] [operator]: blueロボットを動かします
[game.py-4] [INFO] [1706966558.071763990] [assignor]: ourteamはblueです
[game.py-4] [INFO] [1706966558.072296554] [assignor]: goalie IDは0です
[game.py-4] [INFO] [1706966558.080517656] [referee_parser]: ourteamはblueです
[game.py-4] [INFO] [1706966685.429124202] [referee_parser]: ボールが0.05 meter動いたためinplayに変わります
[game.py-4] Traceback (most recent call last):
[game.py-4]   File "/home/ishikura/ros2_ws/install/consai_examples/lib/consai_examples/game.py", line 230, in <module>
[game.py-4]     main()
[game.py-4]   File "/home/ishikura/ros2_ws/install/consai_examples/lib/consai_examples/game.py", line 118, in main
[game.py-4]     decisions[role].inplay(robot_id)
[game.py-4]   File "/home/ishikura/ros2_ws/src/consai_ros2/consai_examples/consai_examples/decisions/attacker.py", line 103, in inplay
[game.py-4]     shoot_pos_list = self._field_observer.get_open_path_id_list(robot_id)
[game.py-4]   File "/home/ishikura/ros2_ws/src/consai_ros2/consai_examples/consai_examples/field_observer.py", line 724, in get_open_path_id_list
[game.py-4]     can_shoot_id_list, can_shoot_pos_list = self.get_receiver_robots_id(
[game.py-4]   File "/home/ishikura/ros2_ws/src/consai_ros2/consai_examples/consai_examples/field_observer.py", line 832, in get_receiver_robots_id
[game.py-4]     robot_r + math.hypot(their_robot_vel.x, their_robot_vel.y) * dt:
[game.py-4] AttributeError: 'NoneType' object has no attribute 'x'
[game.py-4] Exception in thread Thread-1 (spin):
[game.py-4] Traceback (most recent call last):
[game.py-4]   File "/usr/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
[ERROR] [game.py-4]: process has died [pid 73191, exit code 1, cmd '/home/ishikura/ros2_ws/install/consai_examples/lib/consai_examples/game.py --goalie 0 --ros-args'].
^C[WARNING] [launch]: user interrupted with ctrl-c (SIGINT)
[component_container_mt-3] [INFO] [1706967261.962171478] [rclcpp]: signal_handler(signum=2)
[INFO] [component_container_mt-3]: process has finished cleanly [pid 73189]
[consai_visualizer-2] [INFO] [1706967261.962171514] [rclcpp]: signal_handler(signum=2)
[component_container_mt-1] [INFO] [1706967261.962186364] [rclcpp]: signal_handler(signum=2)
[component_container_mt-1] double free or corruption (out)
[consai_visualizer-2] Traceback (most recent call last):
[consai_visualizer-2]   File "/opt/ros/humble/lib/python3.10/site-packages/rqt_gui_py/rclpy_spinner.py", line 32, in run
[consai_visualizer-2]     executor.spin_once(timeout_sec=1.0)
[consai_visualizer-2]   File "/opt/ros/humble/local/lib/python3.10/dist-packages/rclpy/executors.py", line 794, in spin_once
[consai_visualizer-2]     self._spin_once_impl(timeout_sec)
[consai_visualizer-2]   File "/opt/ros/humble/local/lib/python3.10/dist-packages/rclpy/executors.py", line 775, in _spin_once_impl
[consai_visualizer-2]     handler, entity, node = self.wait_for_ready_callbacks(
[consai_visualizer-2]   File "/opt/ros/humble/local/lib/python3.10/dist-packages/rclpy/executors.py", line 711, in wait_for_ready_callbacks
[consai_visualizer-2]     return next(self._cb_iter)
[consai_visualizer-2]   File "/opt/ros/humble/local/lib/python3.10/dist-packages/rclpy/executors.py", line 584, in _wait_for_ready_callbacks
[consai_visualizer-2]     wait_set = _rclpy.WaitSet(
[consai_visualizer-2] rclpy._rclpy_pybind11.RCLError: failed to initialize wait set: the given context is not valid, either rcl_init() was not called or rcl_shutdown() was called., at ./src/rcl/wait.c:130
[consai_visualizer-2] PluginHandler.shutdown_plugin() plugin "consai_visualizer/Visualizer#0" raised an exception:
[consai_visualizer-2] Traceback (most recent call last):
[consai_visualizer-2]   File "/opt/ros/humble/local/lib/python3.10/dist-packages/qt_gui/plugin_handler.py", line 136, in shutdown_plugin
[consai_visualizer-2]     self._shutdown_plugin()
[consai_visualizer-2]   File "/opt/ros/humble/local/lib/python3.10/dist-packages/qt_gui/plugin_handler_direct.py", line 92, in _shutdown_plugin
[consai_visualizer-2]     self.emit_shutdown_plugin_completed()
[consai_visualizer-2]   File "/opt/ros/humble/local/lib/python3.10/dist-packages/qt_gui/plugin_handler.py", line 150, in emit_shutdown_plugin_completed
[consai_visualizer-2]     callback(self._instance_id)
[consai_visualizer-2]   File "/opt/ros/humble/local/lib/python3.10/dist-packages/qt_gui/plugin_manager.py", line 480, in _close_application_shutdown_callback
[consai_visualizer-2]     self._close_application_signal()
[consai_visualizer-2]   File "/opt/ros/humble/local/lib/python3.10/dist-packages/qt_gui/plugin_manager.py", line 483, in _close_application_signal
[consai_visualizer-2]     self._plugin_provider.shutdown()
[consai_visualizer-2]   File "/opt/ros/humble/local/lib/python3.10/dist-packages/qt_gui/composite_plugin_provider.py", line 87, in shutdown
[consai_visualizer-2]     plugin_provider.shutdown()
[consai_visualizer-2]   File "/opt/ros/humble/local/lib/python3.10/dist-packages/qt_gui/composite_plugin_provider.py", line 87, in shutdown
[consai_visualizer-2]     plugin_provider.shutdown()
[consai_visualizer-2]   File "/opt/ros/humble/lib/python3.10/site-packages/rqt_gui_py/ros_py_plugin_provider.py", line 62, in shutdown
[consai_visualizer-2]     self._destroy_node()
[consai_visualizer-2]   File "/opt/ros/humble/lib/python3.10/site-packages/rqt_gui_py/ros_py_plugin_provider.py", line 89, in _destroy_node
[consai_visualizer-2]     rclpy.shutdown()
[consai_visualizer-2]   File "/opt/ros/humble/local/lib/python3.10/dist-packages/rclpy/__init__.py", line 126, in shutdown
[consai_visualizer-2]     _shutdown(context=context)
[consai_visualizer-2]   File "/opt/ros/humble/local/lib/python3.10/dist-packages/rclpy/utilities.py", line 58, in shutdown
[consai_visualizer-2]     return context.shutdown()
[consai_visualizer-2]   File "/opt/ros/humble/local/lib/python3.10/dist-packages/rclpy/context.py", line 102, in shutdown
[consai_visualizer-2]     self.__context.shutdown()
[consai_visualizer-2] rclpy._rclpy_pybind11.RCLError: failed to shutdown: rcl_shutdown already called on the given context, at ./src/rcl/init.c:241
[consai_visualizer-2] 
[ERROR] [component_container_mt-1]: process has died [pid 73185, exit code -6, cmd '/opt/ros/humble/lib/rclcpp_components/component_container_mt --ros-args -r __node:=test_container -r __ns:=/'].
[ERROR] [consai_visualizer-2]: process has died [pid 73187, exit code -11, cmd '/home/ishikura/ros2_ws/install/consai_visualizer/lib/consai_visualizer/consai_visualizer --ros-args --params-file /tmp/launch_params_nyuyx62w'].
ShotaAk commented 6 months ago

フィールド評価中にdetection_trackedを受信すると、 評価中に存在しないロボット情報を参照する可能性がある。

mutexなどで対策できるが、根本的にソフト構造を変更すべきである。

https://github.com/SSL-Roots/consai_ros2/blob/5b094399e43285e5e53f0765b7a365e00b90d987/consai_examples/consai_examples/field_observer.py#L139

ShotaAk commented 6 months ago

別の箇所でも再発したのでReOpenします。

ソフト構造を変更するまでは、一時的な修正を実施します。

[game.py-4] Traceback (most recent call last):
[game.py-4]   File "/home/shotaak/ros2_ws/install/consai_examples/lib/consai_examples/game.py", line 234, in <module>
[game.py-4]     main()
[game.py-4]   File "/home/shotaak/ros2_ws/install/consai_examples/lib/consai_examples/game.py", line 118, in main
[game.py-4]     decisions[role].inplay(robot_id)
[game.py-4]   File "/home/shotaak/ros2_ws/src/consai_ros2/consai_examples/consai_examples/decisions/attacker.py", line 103, in inplay
[game.py-4]     shoot_pos_list = self._field_observer.get_open_path_id_list(robot_id)
[game.py-4]   File "/home/shotaak/ros2_ws/src/consai_ros2/consai_examples/consai_examples/field_observer.py", line 724, in get_open_path_id_list
[game.py-4]     can_shoot_id_list, can_shoot_pos_list = self.get_receiver_robots_id(
[game.py-4]   File "/home/shotaak/ros2_ws/src/consai_ros2/consai_examples/consai_examples/field_observer.py", line 791, in get_receiver_robots_id
[game.py-4]     forward_their_robot_id = self._forward_robots_id(
[game.py-4]   File "/home/shotaak/ros2_ws/src/consai_ros2/consai_examples/consai_examples/field_observer.py", line 914, in _forward_robots_id
[game.py-4]     if my_robot_pos.x < target_robot_pos.x + estimated_displacement:
[game.py-4] AttributeError: 'NoneType' object has no attribute 'x'
[game.py-4] terminate called without an active exception