full_control crashing - Githubissues

Bug report

Required information:

Operating system and version: Ubuntu 22
OpenRMF installation type: form source
OpenRMF version or commit hash Main baranch
ROS distribution and version: Humble
ROS installation type: source
Package or library, if applicable:

Description of the bug

[ERROR] [full_control-15]: process has died [pid 99870, exit code 1, cmd '/home/user/ros2_ws/install/rmf_fleet_adapter/lib/rmf_fleet_adapter/full_control --ros-args -r __node:=barista_fleet_adapter --params-file /tmp/launch_params_5z7_ov43 --params-file /tmp/launch_params_5bp8ca7w --params-file /tmp/launch_params_5evujkym --params-file /tmp/launch_params_oalnr0dc --params-file /tmp/launch_paramsp3pym70 --params-file /tmp/launch_params_yesfir2p --params-file /tmp/launch_params_mniau3qi --params-file /tmp/launch_params_ijm5u6yx --params-file /tmp/launch_params_op9sxyep --params-file /tmp/launch_params_luuws46e --params-file /tmp/launch_params_kk8fo8m7 --params-file /tmp/launch_params_1v0sz6a7 --params-file /tmp/launch_params_vvrpvjwk --params-file /tmp/launch_params_14us2pvq --params-file /tmp/launch_params_ndpd60f5 --params-file /tmp/launch_params_a0_c3kmn --params-file /tmp/launch_params_0y082bvi --params-file /tmp/launch_params_6c7vfyu3 --params-file /tmp/launch_params_diljy4r6 --params-file /tmp/launch_params_s3gmihsd --params-file /tmp/launch_params_dj_s4l57 --params-file /tmp/launch_params_y5vebzin --params-file /tmp/launch_params_0thchlx9 --params-file /tmp/launch_params_63zghksk --params-file /tmp/launch_params_m4djxc7k --params-file /tmp/launch_params_eqwb8zgg --params-file /tmp/launch_params_e540fx9b --params-file /tmp/launch_params_jrafvypm --params-file /tmp/launch_params_rfq2nw6r --params-file /tmp/launch_params_uy8tpywd --params-file /tmp/launch_params_yadkkcdb --params-file /tmp/launch_params_ekjmgbyw'].

The only error I get.

This makes the RMF not work, We only receive the visualization of the map ( no lanes ) an the robot locations ( no estimated locations form the planner itself)

The simulation, the navigation and the freefleet are working perfectly. Its when we start RMF that it just doesn't work most of the times. Best case is when it loads the paths and sends the robots to the initial position but that's quite it.

Steps to reproduce the bug

It happens randomly it seems, but very frequent. Normally the first time we launch it in a system Sometimes it runs, sometimes it doesnt.

Testing I've seen that its seems that using the full_control generates issues. When using the procedure used for example in the clinic example, where no full_cobtrol is used, the map appears every time without issues, except for the fact that the planner is not working.

Expected behavior

I would expect it to work consistently.

Actual behavior

Most of the times it just doesn't work, or works at the start but then fails to receive the commands sent by the web interface

Screenshots

Additional information

We have compiled with this package repo rmw_fastrtps for humble from source because navigation costmaps don't work otherwise.

Any ideas what could be causing this? Becuase RMF was before this quite consistent in the things that worked.

Hello @TheConstructAi ! Could you perhaps provide a longer history of the logs in a github gist? The longer the better. That should help us narrow down the problem since this error message just tells us it has crashed.

OK let me paste it here:

Here is one output:

[INFO] [launch]: All log files can be found below /home/user/.ros/log/2022-10-21-11-38-55-289140-1_xterm-128022 [INFO] [launch]: Default logging verbosity is set to INFO [INFO] [rmf_traffic_schedule-1]: process started with pid [128047] [INFO] [rmf_traffic_blockade-2]: process started with pid [128049] [INFO] [building_map_server-3]: process started with pid [128051] [INFO] [schedule_visualizer_node-4]: process started with pid [128053] [INFO] [fleetstates_visualizer_node-5]: process started with pid [128055] [INFO] [rmf_visualization_building_systems-6]: process started with pid [128057] [INFO] [navgraph_visualizer_node-7]: process started with pid [128059] [INFO] [floorplan_visualizer_node-8]: process started with pid [128061] [INFO] [obstacle_visualizer_node-9]: process started with pid [128063] [INFO] [rviz2-10]: process started with pid [128065] [INFO] [door_supervisor-11]: process started with pid [128067] [INFO] [lift_supervisor-12]: process started with pid [128071] [INFO] [rmf_task_dispatcher-13]: process started with pid [128092] [INFO] [simple_api_server-14]: process started with pid [128110] [INFO] [full_control-15]: process started with pid [128117] [INFO] [robot_state_aggregator-16]: process started with pid [128120] [fleetstates_visualizer_node-5] [INFO] [1666352338.287213528] [fleet_states_visualizer]: Configuring fleet_states_visualizer... [fleetstates_visualizer_node-5] [INFO] [1666352338.287851105] [fleet_states_visualizer]: Setting parameter initial_map_name to L1 [fleetstates_visualizer_node-5] [INFO] [1666352338.287916924] [fleet_states_visualizer]: Setting parameter fleet_state_nose_scale to 0.500000 [rviz2-10] QStandardPaths: XDG_RUNTIME_DIR not set, defaulting to '/tmp/runtime-user' [rmf_task_dispatcher-13] ~Initializing Dispatcher Node~ [fleetstates_visualizer_node-5] [INFO] [1666352338.672640739] [fleet_states_visualizer]: Running fleet_states_visualizer... [rmf_traffic_schedule-1] [INFO] [1666352338.724646932] [rmf_traffic_schedule_primary]: Successfully loaded logfile .rmf_schedule_node.yaml [rmf_traffic_schedule-1] [INFO] [1666352338.728055502] [rmf_traffic_schedule_primary]: Set up heartbeat on /rmf_traffic/heartbeat with liveliness lease duration of 10000 ms and deadline of 10000 ms [rmf_traffic_blockade-2] [INFO] [1666352338.744204092] [rmf_traffic_blockade_node]: Beginning traffic blockade node [obstacle_visualizer_node-9] [INFO] [1666352338.753936614] [rmf_obstacle_visualizer]: Beginning RMF obstacle visualizer node [navgraph_visualizer_node-7] [INFO] [1666352338.967375822] [navgraph_visualizer]: Setting parameter initial_map_name to L1 [navgraph_visualizer_node-7] [INFO] [1666352338.967621863] [navgraph_visualizer]: Setting parameter lane_width to 0.500000 [navgraph_visualizer_node-7] [INFO] [1666352338.967685934] [navgraph_visualizer]: Setting parameter lane_transparency to 0.600000 [navgraph_visualizer_node-7] [INFO] [1666352338.967733351] [navgraph_visualizer]: Setting parameter waypoint_scale to 1.300000 [navgraph_visualizer_node-7] [INFO] [1666352338.967777615] [navgraph_visualizer]: Setting parameter text_scale to 0.700000 [navgraph_visualizer_node-7] [INFO] [1666352339.012564473] [navgraph_visualizer]: NavGraph visualizer is running... [rmf_traffic_schedule-1] [INFO] [1666352339.043667389] [rmf_traffic_schedule_primary]: Beginning traffic schedule node [schedule_visualizer_node-4] [INFO] [1666352339.157334570] [schedule_visualizer_node]: Setting parameter rate to 10.000000 [schedule_visualizer_node-4] [INFO] [1666352339.158020015] [schedule_visualizer_node]: Setting parameter path_width to 0.200000 [schedule_visualizer_node-4] [INFO] [1666352339.158377749] [schedule_visualizer_node]: Setting parameter initial_map_name to L1 [schedule_visualizer_node-4] [INFO] [1666352339.158459150] [schedule_visualizer_node]: Setting parameter wait_secs to 10 [schedule_visualizer_node-4] [INFO] [1666352339.158530626] [schedule_visualizer_node]: Setting parameter port to 8006 [schedule_visualizer_node-4] [INFO] [1666352339.158597817] [schedule_visualizer_node]: Setting parameter retained_history_count to 50 [rmf_task_dispatcher-13] [INFO] [1666352339.160705546] [rmf_dispatcher_node]: Declared Time Window Param as: 2.000000 secs [rmf_task_dispatcher-13] [INFO] [1666352339.161319872] [rmf_dispatcher_node]: Declared Terminated Tasks Max Size Param as: 100 [rmf_task_dispatcher-13] [INFO] [1666352339.162032079] [rmf_dispatcher_node]: Declared publish_active_tasks_period as: 2 secs [rmf_task_dispatcher-13] [INFO] [1666352339.162400476] [rmf_dispatcher_node]: Use timestamp with task_id: false [full_control-15] [INFO] [1666352339.307590216] [barista_fleet_adapter]: Parameter [discovery_timeout] set to: 60.000000 [rmf_task_dispatcher-13] [INFO] [1666352339.325146989] [rmf_dispatcher_node]: Starting task dispatcher node [rviz2-10] [INFO] [1666352339.405621250] [rviz2]: Stereo is NOT SUPPORTED [rviz2-10] [INFO] [1666352339.405751750] [rviz2]: OpenGl version: 4.5 (GLSL 4.5) [rmf_visualization_building_systems-6] [INFO] [1666352339.415843005] [building_systems_visualizer]: Building systems visualizer started... [rmf_visualization_building_systems-6] /opt/ros/humble/local/lib/python3.10/dist-packages/rclpy/qos.py:307: UserWarning: HistoryPolicy.RMW_QOS_POLICY_HISTORY_KEEP_LAST is deprecated. Use HistoryPolicy.KEEP_LAST instead. [rmf_visualization_building_systems-6] warnings.warn( [rmf_visualization_building_systems-6] /opt/ros/humble/local/lib/python3.10/dist-packages/rclpy/qos.py:307: UserWarning: ReliabilityPolicy.RMW_QOS_POLICY_RELIABILITY_RELIABLE is deprecated. Use ReliabilityPolicy.RELIABLE instead. [rmf_visualization_building_systems-6] warnings.warn( [rmf_visualization_building_systems-6] /opt/ros/humble/local/lib/python3.10/dist-packages/rclpy/qos.py:307: UserWarning: DurabilityPolicy.RMW_QOS_POLICY_DURABILITY_TRANSIENT_LOCAL is deprecated. Use DurabilityPolicy.TRANSIENT_LOCAL instead. [rmf_visualization_building_systems-6] warnings.warn( [rviz2-10] [INFO] [1666352339.448704575] [rviz2]: Stereo is NOT SUPPORTED [building_map_server-3] [INFO] [1666352339.595666144] [building_map_server]: loading map path: /home/user/ros2_ws/install/barista_rmf_gazebo/share/barista_rmf_gazebo/rmf_config/multirobot_turtle3_map.building.yaml [building_map_server-3] [INFO] [1666352339.620158803] [building_map_server]: opening: /home/user/ros2_ws/install/barista_rmf_gazebo/share/barista_rmf_gazebo/rmf_config/turtle3_map.png [building_map_server-3] [INFO] [1666352339.623654600] [building_map_server]: read 1640 byte image [building_map_server-3] [INFO] [1666352339.629493242] [building_map_server]: unable to generate GeoJSON for this map. [building_map_server-3] [INFO] [1666352339.643741165] [building_map_server]: publishing map... [building_map_server-3] [INFO] [1666352339.645822590] [building_map_server]: ready to serve map: "turtle3_map" Ctrl+C to exit... [floorplan_visualizer_node-8] [INFO] [1666352339.889555014] [floorplan_visualizer]: Configuring floorplan_visualizer... [floorplan_visualizer_node-8] [INFO] [1666352339.890673712] [floorplan_visualizer]: Setting parameter initial_map_name to L1 [floorplan_visualizer_node-8] [INFO] [1666352339.930865843] [floorplan_visualizer]: Running floorplan_visualizer... [simple_api_server-14] Set Server IP to: 0.0.0.0 [simple_api_server-14] Set Server port to: 0.0.0.0:8083 [simple_api_server-14] Set RMF Websocket port to: localhost:7878 [simple_api_server-14] Starting Websocket Server [simple_api_server-14] Starting RMF_Demos API Server: 0.0.0.0:8083, with ws://localhost:7878 [simple_api_server-14] Serving Flask app 'rmf_demos_panel.simple_api_server' [simple_api_server-14] Debug mode: off [schedule_visualizer_node-4] [ERROR] [1666352349.158774594] [schedule_data_node]: Mirror was not initialized in enough time [10.000000s]! [schedule_visualizer_node-4] [ERROR] [1666352349.219848166] [schedule_visualizer_node]: Failed to create a Mirror of the RMF Schedule Database after waiting for 10 seconds. Please ensur rmf_traffic_schedule node is running. No schedule markers will be published to RViz.

@aaronchongth This is another output where the paths and the location appeared, but no back image nor planner positions:

[INFO] [launch]: All log files can be found below /home/user/.ros/log/2022-10-21-11-40-10-645185-1_xterm-128670 [INFO] [launch]: Default logging verbosity is set to INFO [INFO] [rmf_traffic_schedule-1]: process started with pid [128671] [INFO] [rmf_traffic_blockade-2]: process started with pid [128673] [INFO] [building_map_server-3]: process started with pid [128675] [INFO] [schedule_visualizer_node-4]: process started with pid [128677] [INFO] [fleetstates_visualizer_node-5]: process started with pid [128679] [INFO] [rmf_visualization_building_systems-6]: process started with pid [128681] [INFO] [navgraph_visualizer_node-7]: process started with pid [128683] [INFO] [floorplan_visualizer_node-8]: process started with pid [128685] [INFO] [obstacle_visualizer_node-9]: process started with pid [128687] [INFO] [rviz2-10]: process started with pid [128689] [INFO] [door_supervisor-11]: process started with pid [128693] [INFO] [lift_supervisor-12]: process started with pid [128706] [INFO] [rmf_task_dispatcher-13]: process started with pid [128721] [INFO] [simple_api_server-14]: process started with pid [128730] [INFO] [full_control-15]: process started with pid [128740] [INFO] [robot_state_aggregator-16]: process started with pid [128745] [rviz2-10] QStandardPaths: XDG_RUNTIME_DIR not set, defaulting to '/tmp/runtime-user' [obstacle_visualizer_node-9] [INFO] [1666352413.727259891] [rmf_obstacle_visualizer]: Beginning RMF obstacle visualizer node [rmf_task_dispatcher-13] ~Initializing Dispatcher Node~ [fleetstates_visualizer_node-5] [INFO] [1666352414.041547595] [fleet_states_visualizer]: Configuring fleet_states_visualizer... [fleetstates_visualizer_node-5] [INFO] [1666352414.041759341] [fleet_states_visualizer]: Setting parameter initial_map_name to L1 [fleetstates_visualizer_node-5] [INFO] [1666352414.044778939] [fleet_states_visualizer]: Setting parameter fleet_state_nose_scale to 0.500000 [fleetstates_visualizer_node-5] [INFO] [1666352414.104408504] [fleet_states_visualizer]: Running fleet_states_visualizer... [navgraph_visualizer_node-7] [INFO] [1666352414.109166912] [navgraph_visualizer]: Setting parameter initial_map_name to L1 [navgraph_visualizer_node-7] [INFO] [1666352414.109364843] [navgraph_visualizer]: Setting parameter lane_width to 0.500000 [navgraph_visualizer_node-7] [INFO] [1666352414.109430596] [navgraph_visualizer]: Setting parameter lane_transparency to 0.600000 [navgraph_visualizer_node-7] [INFO] [1666352414.109480059] [navgraph_visualizer]: Setting parameter waypoint_scale to 1.300000 [navgraph_visualizer_node-7] [INFO] [1666352414.109548684] [navgraph_visualizer]: Setting parameter text_scale to 0.700000 [rmf_traffic_schedule-1] [INFO] [1666352414.121800002] [rmf_traffic_schedule_primary]: Successfully loaded logfile .rmf_schedule_node.yaml [schedule_visualizer_node-4] [INFO] [1666352414.133263806] [schedule_visualizer_node]: Setting parameter rate to 10.000000 [schedule_visualizer_node-4] [INFO] [1666352414.133440951] [schedule_visualizer_node]: Setting parameter path_width to 0.200000 [schedule_visualizer_node-4] [INFO] [1666352414.133500378] [schedule_visualizer_node]: Setting parameter initial_map_name to L1 [schedule_visualizer_node-4] [INFO] [1666352414.133552816] [schedule_visualizer_node]: Setting parameter wait_secs to 10 [schedule_visualizer_node-4] [INFO] [1666352414.133597716] [schedule_visualizer_node]: Setting parameter port to 8006 [schedule_visualizer_node-4] [INFO] [1666352414.133641014] [schedule_visualizer_node]: Setting parameter retained_history_count to 50 [navgraph_visualizer_node-7] [INFO] [1666352414.157810736] [navgraph_visualizer]: NavGraph visualizer is running... [rmf_traffic_schedule-1] [INFO] [1666352414.190702432] [rmf_traffic_schedule_primary]: Set up heartbeat on /rmf_traffic/heartbeat with liveliness lease duration of 10000 ms and deadline of 10000 ms [rmf_task_dispatcher-13] [INFO] [1666352414.225405359] [rmf_dispatcher_node]: Declared Time Window Param as: 2.000000 secs [rmf_task_dispatcher-13] [INFO] [1666352414.227138897] [rmf_dispatcher_node]: Declared Terminated Tasks Max Size Param as: 100 [rmf_task_dispatcher-13] [INFO] [1666352414.229926161] [rmf_dispatcher_node]: Declared publish_active_tasks_period as: 2 secs [rmf_task_dispatcher-13] [INFO] [1666352414.230002963] [rmf_dispatcher_node]: Use timestamp with task_id: false [rmf_traffic_blockade-2] [INFO] [1666352414.245355676] [rmf_traffic_blockade_node]: Beginning traffic blockade node [rmf_task_dispatcher-13] [INFO] [1666352414.350827449] [rmf_dispatcher_node]: Starting task dispatcher node [rmf_visualization_building_systems-6] [INFO] [1666352414.485547865] [building_systems_visualizer]: Building systems visualizer started... [rmf_visualization_building_systems-6] /opt/ros/humble/local/lib/python3.10/dist-packages/rclpy/qos.py:307: UserWarning: HistoryPolicy.RMW_QOS_POLICY_HISTORY_KEEP_LAST is deprecated. Use HistoryPolicy.KEEP_LAST instead. [rmf_visualization_building_systems-6] warnings.warn( [rmf_visualization_building_systems-6] /opt/ros/humble/local/lib/python3.10/dist-packages/rclpy/qos.py:307: UserWarning: ReliabilityPolicy.RMW_QOS_POLICY_RELIABILITY_RELIABLE is deprecated. Use ReliabilityPolicy.RELIABLE instead. [rmf_visualization_building_systems-6] warnings.warn( [rmf_visualization_building_systems-6] /opt/ros/humble/local/lib/python3.10/dist-packages/rclpy/qos.py:307: UserWarning: DurabilityPolicy.RMW_QOS_POLICY_DURABILITY_TRANSIENT_LOCAL is deprecated. Use DurabilityPolicy.TRANSIENT_LOCAL instead. [rmf_visualization_building_systems-6] warnings.warn( [rviz2-10] [INFO] [1666352414.624071262] [rviz2]: Stereo is NOT SUPPORTED [rviz2-10] [INFO] [1666352414.624194452] [rviz2]: OpenGl version: 4.5 (GLSL 4.5) [rviz2-10] [INFO] [1666352414.656059364] [rviz2]: Stereo is NOT SUPPORTED [floorplan_visualizer_node-8] [INFO] [1666352414.818574756] [floorplan_visualizer]: Configuring floorplan_visualizer... [floorplan_visualizer_node-8] [INFO] [1666352414.820565251] [floorplan_visualizer]: Setting parameter initial_map_name to L1 [rmf_traffic_schedule-1] [INFO] [1666352414.826871769] [rmf_traffic_schedule_primary]: Beginning traffic schedule node [full_control-15] [INFO] [1666352414.845851278] [barista_fleet_adapter]: Parameter [discovery_timeout] set to: 60.000000 [floorplan_visualizer_node-8] [INFO] [1666352414.912862061] [floorplan_visualizer]: Running floorplan_visualizer... [rmf_traffic_schedule-1] [INFO] [1666352414.952973449] [rmf_traffic_schedule_primary]: Registered new query [1] [schedule_visualizer_node-4] [INFO] [1666352414.968847123] [schedule_data_node]: Registering to query topic rmf_traffic/query_update_1 [rmf_traffic_schedule-1] [INFO] [1666352414.986825112] [rmf_traffic_schedule_primary]: A new mirror is tracking query ID [1] [full_control-15] [INFO] [1666352414.993192287] [barista_fleet_adapter]: Registering to query topic rmf_traffic/query_update_1 [schedule_visualizer_node-4] [INFO] [1666352415.010815758] [schedule_data_node]: [rmf_traffic_ros2::MirrorManager::request_update] Requesting changes for query ID [1] since beginning of recorded history [schedule_visualizer_node-4] [WARN] [1666352415.010991620] [schedule_data_node]: [MirrorManager::request_update] Waiting for change request service to reconnect for [15180ad6-7ece-41e2-b1bd-7fc38923a1ed] before sending a change request. [building_map_server-3] [INFO] [1666352415.095967408] [building_map_server]: loading map path: /home/user/ros2_ws/install/barista_rmf_gazebo/share/barista_rmf_gazebo/rmf_config/multirobot_turtle3_map.building.yaml [building_map_server-3] [INFO] [1666352415.133302085] [building_map_server]: opening: /home/user/ros2_ws/install/barista_rmf_gazebo/share/barista_rmf_gazebo/rmf_config/turtle3_map.png [building_map_server-3] [INFO] [1666352415.134657133] [building_map_server]: read 1640 byte image [simple_api_server-14] Set Server IP to: 0.0.0.0 [simple_api_server-14] Set Server port to: 0.0.0.0:8083 [simple_api_server-14] Set RMF Websocket port to: localhost:7878 [simple_api_server-14] Starting Websocket Server [simple_api_server-14] Starting RMF_Demos API Server: 0.0.0.0:8083, with ws://localhost:7878 [simple_api_server-14] Serving Flask app 'rmf_demos_panel.simple_api_server' [simple_api_server-14] Debug mode: off [building_map_server-3] [INFO] [1666352415.160259331] [building_map_server]: unable to generate GeoJSON for this map. [full_control-15] [INFO] [1666352415.172275958] [barista_fleet_adapter]: Parameter [linear_velocity] set to: 0.200000 [full_control-15] [INFO] [1666352415.173701537] [barista_fleet_adapter]: Parameter [angular_velocity] set to: 0.300000 [full_control-15] [INFO] [1666352415.174387904] [barista_fleet_adapter]: Parameter [linear_acceleration] set to: 0.350000 [full_control-15] [INFO] [1666352415.175079299] [barista_fleet_adapter]: Parameter [angular_acceleration] set to: 0.500000 [full_control-15] [INFO] [1666352415.175833382] [barista_fleet_adapter]: Parameter [footprint_radius] set to: 0.200000 [full_control-15] [INFO] [1666352415.176616567] [barista_fleet_adapter]: Parameter [vicinity_radius] set to: 0.220000 [full_control-15] [INFO] [1666352415.178478488] [barista_fleet_adapter]: Parameter [reversible] set to: 0 [full_control-15] ===== We have an irreversible robot [building_map_server-3] [INFO] [1666352415.182556346] [building_map_server]: publishing map... [full_control-15] The fleet [barista] has the following named waypoints: [full_control-15] -- target_1 [full_control-15] -- target_2 [full_control-15] -- barista_2_charging_station [full_control-15] -- mule_charging_station [full_control-15] -- spot_3 [full_control-15] -- spot_2 [full_control-15] -- spot_1 [full_control-15] -- barista_1_charging_station [building_map_server-3] [INFO] [1666352415.185064504] [building_map_server]: ready to serve map: "turtle3_map" Ctrl+C to exit... [schedule_visualizer_node-4] [INFO] [1666352415.219624519] [schedule_visualizer_node]: Successfully connected to rmf_traffic_schedule node. [schedule_visualizer_node-4] [INFO] [1666352415.220152652] [schedule_data_node]: Mirror handling new sync of 1 queries from schedule node [15180ad6-7ece-41e2-b1bd-7fc38923a1ed] [full_control-15] [INFO] [1666352415.257725456] [barista_fleet_adapter]: Parameter [battery_voltage] set to: 12.000000 [full_control-15] [INFO] [1666352415.259439901] [barista_fleet_adapter]: Parameter [battery_capacity] set to: 24.000000 [full_control-15] [INFO] [1666352415.260983757] [barista_fleet_adapter]: Parameter [battery_charging_current] set to: 5.000000 [full_control-15] [INFO] [1666352415.262833441] [barista_fleet_adapter]: Parameter [mass] set to: 20.000000 [full_control-15] [INFO] [1666352415.264416833] [barista_fleet_adapter]: Parameter [inertia] set to: 10.000000 [full_control-15] [INFO] [1666352415.265599094] [barista_fleet_adapter]: Parameter [friction_coefficient] set to: 0.220000 [full_control-15] [INFO] [1666352415.267550774] [barista_fleet_adapter]: Parameter [ambient_power_drain] set to: 20.000000 [full_control-15] [INFO] [1666352415.268997949] [barista_fleet_adapter]: Parameter [tool_power_drain] set to: 0.000000 [full_control-15] [INFO] [1666352415.270139016] [barista_fleet_adapter]: Parameter [drain_battery] set to: 1 [full_control-15] [INFO] [1666352415.271439560] [barista_fleet_adapter]: Parameter [recharge_threshold] set to: 0.300000 [full_control-15] [INFO] [1666352415.272871111] [barista_fleet_adapter]: Parameter [recharge_soc] set to: 1.000000 [full_control-15] [INFO] [1666352415.274669231] [barista_fleet_adapter]: Fleet is not configured to perform any finishing request [full_control-15] [INFO] [1666352415.278581947] [barista_fleet_adapter]: Parameter [delay_threshold] set to: 15.000000 [full_control-15] [INFO] [1666352415.285941081] [barista_fleet_adapter]: Starting Fleet Adapter [full_control-15] [INFO] [1666352415.295924178] [barista_fleet_adapter]: Mirror handling new sync of 1 queries from schedule node [15180ad6-7ece-41e2-b1bd-7fc38923a1ed]

[schedule_visualizer_node-4] [INFO] [1666352434.978014480] [schedule_data_node]: Requesting new schedule update because update timed out [schedule_visualizer_node-4] [INFO] [1666352434.978094104] [schedule_data_node]: [rmf_traffic_ros2::MirrorManager::request_update] Requesting changes for query ID [1] since beginning of recorded history [schedule_visualizer_node-4] [WARN] [1666352434.978260114] [schedule_data_node]: [MirrorManager::request_update] Waiting for change request service to reconnect for [15180ad6-7ece-41e2-b1bd-7fc38923a1ed] before sending a change request.

[full_control-15] [INFO] [1666352435.001088151] [barista_fleet_adapter]: Requesting new schedule update because update timed out [full_control-15] [INFO] [1666352435.001159173] [barista_fleet_adapter]: [rmf_traffic_ros2::MirrorManager::request_update] Requesting changes for query ID[1] since beginning of recorded history [rmf_traffic_schedule-1] [INFO] [1666352435.011204200] [rmf_traffic_schedule_primary]: [ScheduleNode::update_mirrors] Sending remedial update starting from the beginning going to 0 for query 1

Screenshot from 2022-10-21 13-40-29

@aaronchongth and a third consecutive , with another result:

[INFO] [launch]: All log files can be found below /home/user/.ros/log/2022-10-21-11-43-01-563939-1_xterm-129728 [INFO] [launch]: Default logging verbosity is set to INFO [INFO] [rmf_traffic_schedule-1]: process started with pid [129753] [INFO] [rmf_traffic_blockade-2]: process started with pid [129755] [INFO] [building_map_server-3]: process started with pid [129757] [INFO] [schedule_visualizer_node-4]: process started with pid [129759] [INFO] [fleetstates_visualizer_node-5]: process started with pid [129761] [INFO] [rmf_visualization_building_systems-6]: process started with pid [129763] [INFO] [navgraph_visualizer_node-7]: process started with pid [129765] [INFO] [floorplan_visualizer_node-8]: process started with pid [129767] [INFO] [obstacle_visualizer_node-9]: process started with pid [129770] [INFO] [rviz2-10]: process started with pid [129781] [INFO] [door_supervisor-11]: process started with pid [129784] [INFO] [lift_supervisor-12]: process started with pid [129800] [INFO] [rmf_task_dispatcher-13]: process started with pid [129809] [INFO] [simple_api_server-14]: process started with pid [129819] [INFO] [full_control-15]: process started with pid [129829] [INFO] [robot_state_aggregator-16]: process started with pid [129839] [fleetstates_visualizer_node-5] [INFO] [1666352584.568552068] [fleet_states_visualizer]: Configuring fleet_states_visualizer... [fleetstates_visualizer_node-5] [INFO] [1666352584.568764821] [fleet_states_visualizer]: Setting parameter initial_map_name to L1 [fleetstates_visualizer_node-5] [INFO] [1666352584.568810457] [fleet_states_visualizer]: Setting parameter fleet_state_nose_scale to 0.500000 [fleetstates_visualizer_node-5] [INFO] [1666352584.605369619] [fleet_states_visualizer]: Running fleet_states_visualizer... [rviz2-10] QStandardPaths: XDG_RUNTIME_DIR not set, defaulting to '/tmp/runtime-user' [schedule_visualizer_node-4] [INFO] [1666352584.719183467] [schedule_visualizer_node]: Setting parameter rate to 10.000000 [schedule_visualizer_node-4] [INFO] [1666352584.719407485] [schedule_visualizer_node]: Setting parameter path_width to 0.200000 [schedule_visualizer_node-4] [INFO] [1666352584.719468109] [schedule_visualizer_node]: Setting parameter initial_map_name to L1 [schedule_visualizer_node-4] [INFO] [1666352584.719526386] [schedule_visualizer_node]: Setting parameter wait_secs to 10 [schedule_visualizer_node-4] [INFO] [1666352584.719567414] [schedule_visualizer_node]: Setting parameter port to 8006 [schedule_visualizer_node-4] [INFO] [1666352584.719609855] [schedule_visualizer_node]: Setting parameter retained_history_count to 50 [rmf_traffic_blockade-2] [INFO] [1666352584.737797397] [rmf_traffic_blockade_node]: Beginning traffic blockade node [obstacle_visualizer_node-9] [INFO] [1666352584.760268948] [rmf_obstacle_visualizer]: Beginning RMF obstacle visualizer node [navgraph_visualizer_node-7] [INFO] [1666352584.839794688] [navgraph_visualizer]: Setting parameter initial_map_name to L1 [navgraph_visualizer_node-7] [INFO] [1666352584.841558578] [navgraph_visualizer]: Setting parameter lane_width to 0.500000 [navgraph_visualizer_node-7] [INFO] [1666352584.852284106] [navgraph_visualizer]: Setting parameter lane_transparency to 0.600000 [navgraph_visualizer_node-7] [INFO] [1666352584.861957733] [navgraph_visualizer]: Setting parameter waypoint_scale to 1.300000 [navgraph_visualizer_node-7] [INFO] [1666352584.863883165] [navgraph_visualizer]: Setting parameter text_scale to 0.700000 [rmf_task_dispatcher-13] ~Initializing Dispatcher Node~ [navgraph_visualizer_node-7] [INFO] [1666352584.893105131] [navgraph_visualizer]: NavGraph visualizer is running... [rmf_traffic_schedule-1] [INFO] [1666352584.946389974] [rmf_traffic_schedule_primary]: Successfully loaded logfile .rmf_schedule_node.yaml [rmf_traffic_schedule-1] [INFO] [1666352584.966340778] [rmf_traffic_schedule_primary]: Set up heartbeat on /rmf_traffic/heartbeat with liveliness lease duration of 10000 ms and deadline of 10000 ms [rmf_task_dispatcher-13] [INFO] [1666352585.137403399] [rmf_dispatcher_node]: Declared Time Window Param as: 2.000000 secs [rmf_task_dispatcher-13] [INFO] [1666352585.138388369] [rmf_dispatcher_node]: Declared Terminated Tasks Max Size Param as: 100 [rmf_task_dispatcher-13] [INFO] [1666352585.138939533] [rmf_dispatcher_node]: Declared publish_active_tasks_period as: 2 secs [rmf_task_dispatcher-13] [INFO] [1666352585.139558972] [rmf_dispatcher_node]: Use timestamp with task_id: false [rmf_task_dispatcher-13] [INFO] [1666352585.231047874] [rmf_dispatcher_node]: Starting task dispatcher node [rmf_traffic_schedule-1] [INFO] [1666352585.421771834] [rmf_traffic_schedule_primary]: Beginning traffic schedule node [rviz2-10] [INFO] [1666352585.431148222] [rviz2]: Stereo is NOT SUPPORTED [rviz2-10] [INFO] [1666352585.432688251] [rviz2]: OpenGl version: 4.5 (GLSL 4.5) [full_control-15] [INFO] [1666352585.433714739] [barista_fleet_adapter]: Parameter [discovery_timeout] set to: 60.000000 [rviz2-10] [INFO] [1666352585.474036597] [rviz2]: Stereo is NOT SUPPORTED [rmf_visualization_building_systems-6] [INFO] [1666352585.622784211] [building_systems_visualizer]: Building systems visualizer started... [rmf_visualization_building_systems-6] /opt/ros/humble/local/lib/python3.10/dist-packages/rclpy/qos.py:307: UserWarning: HistoryPolicy.RMW_QOS_POLICY_HISTORY_KEEP_LAST is deprecated. Use HistoryPolicy.KEEP_LAST instead. [rmf_visualization_building_systems-6] warnings.warn( [rmf_visualization_building_systems-6] /opt/ros/humble/local/lib/python3.10/dist-packages/rclpy/qos.py:307: UserWarning: ReliabilityPolicy.RMW_QOS_POLICY_RELIABILITY_RELIABLE is deprecated. Use ReliabilityPolicy.RELIABLE instead. [rmf_visualization_building_systems-6] warnings.warn( [rmf_visualization_building_systems-6] /opt/ros/humble/local/lib/python3.10/dist-packages/rclpy/qos.py:307: UserWarning: DurabilityPolicy.RMW_QOS_POLICY_DURABILITY_TRANSIENT_LOCAL is deprecated. Use DurabilityPolicy.TRANSIENT_LOCAL instead. [rmf_visualization_building_systems-6] warnings.warn( [rmf_traffic_schedule-1] [INFO] [1666352585.633897149] [rmf_traffic_schedule_primary]: Registered new query [1] [rmf_traffic_schedule-1] terminate called after throwing an instance of 'rclcpp::exceptions::RCLError' [rmf_traffic_schedule-1] what(): failed to send response: client will not receive response, at /home/user/ros2_ws/src/rmw_fastrtps/rmw_fastrtps_shared_cpp/src/rmw_response.cpp:149, at ./src/rcl/service.c:314 [floorplan_visualizer_node-8] [INFO] [1666352585.921799849] [floorplan_visualizer]: Configuring floorplan_visualizer... [floorplan_visualizer_node-8] [INFO] [1666352585.922300343] [floorplan_visualizer]: Setting parameter initial_map_name to L1 [ERROR] [rmf_traffic_schedule-1]: process has died [pid 129753, exit code -6, cmd '/home/user/ros2_ws/install/rmf_traffic_ros2/lib/rmf_traffic_ros2/rmf_traffic_schedule --ros-args -r __node:=rmf_traffic_schedule_primary --params-file /tmp/launch_params_ekcfq7kk']. [floorplan_visualizer_node-8] [INFO] [1666352585.964382106] [floorplan_visualizer]: Running floorplan_visualizer... [building_map_server-3] [INFO] [1666352586.017692618] [building_map_server]: loading map path: /home/user/ros2_ws/install/barista_rmf_gazebo/share/barista_rmf_gazebo/rmf_config/multirobot_turtle3_map.building.yaml [building_map_server-3] [INFO] [1666352586.075260707] [building_map_server]: opening: /home/user/ros2_ws/install/barista_rmf_gazebo/share/barista_rmf_gazebo/rmf_config/turtle3_map.png [building_map_server-3] [INFO] [1666352586.076722930] [building_map_server]: read 1640 byte image [building_map_server-3] [INFO] [1666352586.083222853] [building_map_server]: unable to generate GeoJSON for this map. [building_map_server-3] [INFO] [1666352586.141665165] [building_map_server]: publishing map... [building_map_server-3] [INFO] [1666352586.148268125] [building_map_server]: ready to serve map: "turtle3_map" Ctrl+C to exit... [simple_api_server-14] Set Server IP to: 0.0.0.0 [simple_api_server-14] Set Server port to: 0.0.0.0:8083 [simple_api_server-14] Set RMF Websocket port to: localhost:7878 [simple_api_server-14] Starting Websocket Server [simple_api_server-14] Starting RMF_Demos API Server: 0.0.0.0:8083, with ws://localhost:7878 [simple_api_server-14] Serving Flask app 'rmf_demos_panel.simple_api_server' [simple_api_server-14] Debug mode: off [rviz2-10] [INFO] [1666352586.561256164] [rviz2]: Trying to create a map of size 384 x 384 using 1 swatches [rviz2-10] [ERROR] [1666352586.580609330] [rviz2]: Vertex Program:rviz/glsl120/indexed_8bit_image.vert Fragment Program:rviz/glsl120/indexed_8bit_image.frag GLSL link result : [rviz2-10] active samplers with a different type refer to the same texture image unit [schedule_visualizer_node-4] [ERROR] [1666352594.721310501] [schedule_data_node]: Mirror was not initialized in enough time [10.000000s]! [schedule_visualizer_node-4] [ERROR] [1666352594.763769099] [schedule_visualizer_node]: Failed to create a Mirror of the RMF Schedule Database after waiting for 10 seconds. Please ensur rmf_traffic_schedule node is running. No schedule markers will be published to RViz.

Screenshot from 2022-10-21 13-43-18

As you can see there is not much consistency in what appears and what not. The only thing that never appeared ( except once) is the planning: Screenshot from 2022-10-21 12-05-54

This ahheppend once... They moved to the designated closest points an then stopped working.

[schedule_visualizer_node-4] [ERROR] [1666352594.763769099] [schedule_visualizer_node]: Failed to create a Mirror of the RMF Schedule Database after waiting for 10 seconds. Please ensur rmf_traffic_schedule node is running. No schedule markers will be published to RViz.

It looks like either you have not spun up the rmf_traffic_schedule node, or discovery is not doing so well on your setup.

If the node is already running (edit: and it still fails), you can try launching everything with export RMW_IMPLEMENTATION=rmw_cyclonedds_cpp. Let me know how it goes.

Please be sure to put long outputs into a https://gist.github.com and then share the link. Navigating an issue thread becomes difficult when there are long terminal outputs. Your earlier comments can be edited to fix that.

The vast majority of inexplicable crashes happen because you've launched nodes that were compiled against inconsistent ROS2 message definitions. In fact that is the only reason I've ever seen the traffic schedule node crash in the last few years, and I see that it's been crashing for you.

Since you said you're using RMF from source, I would recommend the following:

Make sure you do not have any RMF packages installed that could be confusing cmake. This seems unlikely if you're using humble since I don't think we've released on humble yet, but it's still a good idea to make sure.
git pull origin main all of the repos in your RMF colcon workspace.
Do a 100% clean build by deleting the entire build directory of your RMF colcon workspace.

If the issue still persists then we'd need to be able to recreate the issue in order to debug it. We'd need you to provide the maps and launch files that are leading to the crash.

After looking at the terminal outputs more carefully, I'm inclined to agree with @aaronchongth that this may be a discovery issue. It may be worth trying to use CycloneDDS as he recommended. That may also explain why the switch to humble would've broken things since galactic used Cyclone as the default whereas humble is using FastDDS.

Thanks for seeing into this. But then, I assume that humble is not stable at this date? Because being something related to the default DDS implementation of Humble sound as if it's not stable in that release?

I'll see into changing to cyclone, although I'm not sure it will affect other systems...

Just tested it and exactly... When using the cyclone implementation works, although still strange disconnections and navigation goals still not reaching most of the times.

Just executing this command before each launch terminal:

export RMW_IMPLEMENTATION=rmw_cyclonedds_cpp

And installing the needed cyclone packages

Then I would highly recommend to comment on the main page that users should set cyclone DDS in the Humble version.

Thanks a lot for the help

still strange disconnections

Are you able to elaborate on what's disconnecting? Is this a simulated RMF setup running on a single computer, or do you have a more complex setup than that? Is there a network involved and connections between devices are failing?

navigation goals still not reaching most of the times.

Are you saying that path commands from RMF are failing to be delivered to the robot? Or the robot is failing to reach its navigation goals? Or that the robot is reaching the goal but RMF is failing to continue to the next goal?

I think issues with disconnections are going to be related to the choice of the RMW implementation that you use and how it's configured. There won't be much that RMF can do about that. I haven't personally noticed any significant changes after migrating from galactic to humble because my environment has been permanently set up to use Cyclone as the default RMW for both ROS2 distros. If you're still seeing connection/discovery issues with Cyclone then it may be worthwhile to help us recreate your conditions so we can investigate on our end.

Then I would highly recommend to comment on the main page that users should set cyclone DDS in the Humble version.

I try to stay agnostic about the choice of RMW implementation since it can sometimes feel political, but if there's evidence that the default RMW is having issues then we can certainly include some recommendations in the README. It's possible that FastDDS's discovery server could help with the issues, so we could also refer users to that option.

Closing due to inactivity. Feel free to reopen

open-rmf / rmf

full_control crashing #258