log.txt

~$ ros2 launch test_map test_map_gz.launch.xml server_uri:="ws://localhost:8000/_internal"
[INFO] [launch]: All log files can be found below /home/fsi/.ros/log/2022-12-02-20-22-13-993284-fsi-ThinkPad-E15-Gen-2-54002
[INFO] [launch]: Default logging verbosity is set to INFO
[INFO] [rmf_traffic_schedule-1]: process started with pid [54004]
[INFO] [rmf_traffic_schedule_monitor-2]: process started with pid [54006]
[INFO] [rmf_traffic_blockade-3]: process started with pid [54008]
[INFO] [building_map_server-4]: process started with pid [54010]
[INFO] [schedule_visualizer-5]: process started with pid [54012]
[INFO] [rmf_visualization_fleet_states-6]: process started with pid [54014]
[INFO] [rmf_visualization_building_systems-7]: process started with pid [54016]
[INFO] [rviz2-8]: process started with pid [54018]
[INFO] [door_supervisor-9]: process started with pid [54021]
[INFO] [lift_supervisor-10]: process started with pid [54023]
[INFO] [rmf_task_dispatcher-11]: process started with pid [54033]
[INFO] [simple_api_server-12]: process started with pid [54035]
[INFO] [full_control-13]: process started with pid [54038]
[INFO] [robot_state_aggregator-14]: process started with pid [54040]
[INFO] [free_fleet_server_ros2-15]: process started with pid [54042]
[rmf_traffic_blockade-3] [INFO] [1669980134.697621351] [rmf_traffic_blockade_node]: Beginning traffic blockade node
[rmf_traffic_schedule-1] [INFO] [1669980134.797223532] [rmf_traffic_schedule_primary]: Successfully loaded logfile .rmf_schedule_node.yaml 
[rmf_traffic_schedule-1] [INFO] [1669980134.798817204] [rmf_traffic_schedule_primary]: Set up heartbeat on /rmf_traffic/heartbeat with liveliness lease duration of 1000 ms and deadline of 1000 ms
[rmf_traffic_schedule_monitor-2] [INFO] [1669980134.802791551] [rmf_traffic_schedule_backup]: Set up heartbeat listener on /rmf_traffic/heartbeat with liveliness lease duration of 1000 ms
[rmf_traffic_schedule-1] [INFO] [1669980134.809409783] [rmf_traffic_schedule_primary]: Beginning traffic schedule node
[rmf_traffic_schedule_monitor-2] [INFO] [1669980134.815348075] [rmf_traffic_schedule_backup]: Liveliness changed event:
[full_control-13] [INFO] [1669980134.816117534] [lightrover_fleet_adapter]: Parameter [discovery_timeout] set to: 60.000000
[rmf_traffic_schedule_monitor-2] [INFO] [1669980134.816632599] [rmf_traffic_schedule_backup]:   alive_count: 1
[rmf_traffic_schedule_monitor-2] [INFO] [1669980134.817011510] [rmf_traffic_schedule_backup]:   not_alive_count: 0
[rmf_traffic_schedule_monitor-2] [INFO] [1669980134.817357806] [rmf_traffic_schedule_backup]:   alive_count_change: 1
[rmf_traffic_schedule_monitor-2] [INFO] [1669980134.817750882] [rmf_traffic_schedule_backup]:   not_alive_count_change: 0
[rmf_traffic_schedule_monitor-2] [INFO] [1669980134.824143779] [rmf_traffic_schedule_backup]: Handling new sync of 0 queries from primary node
[rmf_traffic_schedule-1] [INFO] [1669980134.835397928] [rmf_traffic_schedule_primary]: Registered new query [1]
[rmf_traffic_schedule-1] [INFO] [1669980134.836050170] [rmf_traffic_schedule_primary]: A new mirror is tracking query ID [1]
[rmf_traffic_schedule_monitor-2] [INFO] [1669980134.836104693] [rmf_traffic_schedule_backup]: Handling new sync of 1 queries from primary node
[rmf_traffic_schedule_monitor-2] [INFO] [1669980134.836441239] [rmf_traffic_schedule_backup]: Handling new sync of 1 queries from primary node
[rmf_traffic_schedule_monitor-2] [INFO] [1669980134.836746405] [rmf_traffic_schedule_backup]: Got mirror for monitor node
[rmf_task_dispatcher-11] ~Initializing Dispatcher Node~
[rmf_traffic_schedule-1] [INFO] [1669980134.851159183] [rmf_traffic_schedule_primary]: A new mirror is tracking query ID [1]
[rmf_traffic_schedule_monitor-2] [INFO] [1669980134.851474946] [rmf_traffic_schedule_backup]: Handling new sync of 1 queries from primary node
[rmf_traffic_schedule_monitor-2] [INFO] [1669980134.851596884] [rmf_traffic_schedule_backup]: Mirror handling new sync of 1 queries from schedule node version [0]
[rmf_task_dispatcher-11] [INFO] [1669980134.851779190] [rmf_dispatcher_node]:  Declared Time Window Param as: 2.000000 secs
[rmf_task_dispatcher-11] [INFO] [1669980134.851951976] [rmf_dispatcher_node]:  Declared Terminated Tasks Max Size Param as: 100
[rmf_task_dispatcher-11] [INFO] [1669980134.851987943] [rmf_dispatcher_node]:  Declared publish_active_tasks_period as: 2 secs
[rmf_task_dispatcher-11] [INFO] [1669980134.852023502] [rmf_dispatcher_node]:  Use timestamp with task_id: false
[free_fleet_server_ros2-15] Greetings from free_fleet_server_ros2
[rmf_task_dispatcher-11] [INFO] [1669980134.858785619] [rmf_dispatcher_node]: Starting task dispatcher node
[free_fleet_server_ros2-15] ROS 2 SERVER CONFIGURATION
[free_fleet_server_ros2-15]   fleet name: lightrover
[free_fleet_server_ros2-15]   update state frequency: 20.0
[free_fleet_server_ros2-15]   publish state frequency: 2.0
[free_fleet_server_ros2-15]   TOPICS
[free_fleet_server_ros2-15]     fleet state: fleet_states
[free_fleet_server_ros2-15]     mode request: robot_mode_requests
[free_fleet_server_ros2-15]     path request: robot_path_requests
[free_fleet_server_ros2-15]     destination request: robot_destination_requests
[free_fleet_server_ros2-15] SERVER-CLIENT DDS CONFIGURATION
[free_fleet_server_ros2-15]   dds domain: 42
[free_fleet_server_ros2-15]   TOPICS
[free_fleet_server_ros2-15]     robot state: robot_state
[free_fleet_server_ros2-15]     mode request: mode_request
[free_fleet_server_ros2-15]     path request: path_request
[free_fleet_server_ros2-15]     destination request: destination_request
[free_fleet_server_ros2-15] COORDINATE TRANSFORMATION
[free_fleet_server_ros2-15]   translation x (meters): 0.000
[free_fleet_server_ros2-15]   translation y (meters): 0.000
[free_fleet_server_ros2-15]   rotation (radians): 0.000
[free_fleet_server_ros2-15]   scale: 1.000
[full_control-13] [INFO] [1669980134.874862890] [lightrover_fleet_adapter]: Parameter [linear_velocity] set to: 0.220000
[full_control-13] [INFO] [1669980134.875571092] [lightrover_fleet_adapter]: Parameter [angular_velocity] set to: 1.000000
[full_control-13] [INFO] [1669980134.875798924] [lightrover_fleet_adapter]: Parameter [linear_acceleration] set to: 2.500000
[full_control-13] [INFO] [1669980134.875995814] [lightrover_fleet_adapter]: Parameter [angular_acceleration] set to: 3.200000
[full_control-13] [INFO] [1669980134.876237875] [lightrover_fleet_adapter]: Parameter [footprint_radius] set to: 0.300000
[full_control-13] [INFO] [1669980134.876499961] [lightrover_fleet_adapter]: Parameter [vicinity_radius] set to: 0.500000
[full_control-13] [INFO] [1669980134.876734681] [lightrover_fleet_adapter]: Parameter [reversible] set to: 0
[full_control-13]  ===== We have an irreversible robot
[rmf_task_dispatcher-11] [INFO] [1669980134.878759238] [rmf_dispatcher_node]: Add Task [patrol.dispatch-0] to a bidding queue
[full_control-13] The fleet [lightrover] has the following named waypoints:
[full_control-13]  -- goal2
[full_control-13]  -- goal3
[full_control-13]  -- goal1
[full_control-13]  -- start
[full_control-13] [INFO] [1669980134.879615411] [lightrover_fleet_adapter]: API server URI: [ws://localhost:8000/_internal]
[schedule_visualizer-5] [INFO] [1669980134.897916876] [rmf_visualization_schedule_data_node]: rmf_visualization_schedule_data_node started...
[schedule_visualizer-5] [INFO] [1669980134.903653816] [rmf_visualization_schedule_data_node]: Websocket server started on port: 8006
[full_control-13] [INFO] [1669980134.909953305] [lightrover_fleet_adapter]: Parameter [battery_voltage] set to: 12.000000
[full_control-13] [INFO] [1669980134.910332059] [lightrover_fleet_adapter]: Parameter [battery_capacity] set to: 24.000000
[full_control-13] [INFO] [1669980134.910652867] [lightrover_fleet_adapter]: Parameter [battery_charging_current] set to: 5.000000
[full_control-13] [INFO] [1669980134.910937593] [lightrover_fleet_adapter]: Parameter [mass] set to: 20.000000
[full_control-13] [INFO] [1669980134.911070409] [lightrover_fleet_adapter]: Parameter [inertia] set to: 10.000000
[full_control-13] [INFO] [1669980134.911574052] [lightrover_fleet_adapter]: Parameter [friction_coefficient] set to: 0.220000
[full_control-13] [INFO] [1669980134.911694802] [lightrover_fleet_adapter]: Parameter [ambient_power_drain] set to: 20.000000
[full_control-13] [INFO] [1669980134.911803738] [lightrover_fleet_adapter]: Parameter [tool_power_drain] set to: 0.000000
[full_control-13] [INFO] [1669980134.911924310] [lightrover_fleet_adapter]: Parameter [drain_battery] set to: 0
[full_control-13] [INFO] [1669980134.912060333] [lightrover_fleet_adapter]: Parameter [recharge_threshold] set to: 0.100000
[full_control-13] [INFO] [1669980134.912419553] [lightrover_fleet_adapter]: Parameter [recharge_soc] set to: 1.000000
[full_control-13] [INFO] [1669980134.912551495] [lightrover_fleet_adapter]: Fleet is not configured to perform any finishing request
[full_control-13] [INFO] [1669980134.917489520] [lightrover_fleet_adapter]: Parameter [delay_threshold] set to: 15.000000
[rmf_visualization_fleet_states-6] [INFO] [1669980134.917968837] [fleet_state_visualizer]: hello i am fleet state visualizer
[full_control-13] [WARN] [1669980134.919297735] [lightrover_fleet_adapter]: BroadcastClient unable to connect to [ws://localhost:8000/_internal]. Please make sure server is running. Error msg: invalid state
[full_control-13] [INFO] [1669980134.920684313] [lightrover_fleet_adapter]: Starting Fleet Adapter
[schedule_visualizer-5] [INFO] [1669980134.923475787] [rmf_visualization_schedule_data_node]: Mirror handling new sync of 1 queries from schedule node version [0]
[full_control-13] [INFO] [1669980134.927961382] [lightrover_fleet_adapter]: Mirror handling new sync of 1 queries from schedule node version [0]
[full_control-13] [INFO] [1669980134.937587970] [lightrover_fleet_adapter]: BroadcastClient successfully connected to uri: [ws://localhost:8000/_internal]
[rmf_task_dispatcher-11] [INFO] [1669980135.057585191] [rmf_dispatcher_node]:  - Start new bidding task: patrol.dispatch-0
[full_control-13] [INFO] [1669980135.058391604] [lightrover_fleet_adapter]: [Bidder] Received Bidding notice for task_id [patrol.dispatch-0]
[full_control-13] [INFO] [1669980135.058491833] [lightrover_fleet_adapter]: Fleet [lightrover] does not have any robots to accept task [patrol.dispatch-0]. Use FleetUpdateHadndle::add_robot(~) to add robots to this fleet. 
[rmf_visualization_building_systems-7] [INFO] [1669980135.119063159] [building_systems_visualizer]: Building systems visualizer started...
[rviz2-8] [INFO] [1669980135.139858420] [rviz2]: Stereo is NOT SUPPORTED
[rviz2-8] [INFO] [1669980135.139944999] [rviz2]: OpenGl version: 4.6 (GLSL 4.6)
[rviz2-8] [INFO] [1669980135.160152081] [rviz2]: Stereo is NOT SUPPORTED
[simple_api_server-12] Set Server IP to: 0.0.0.0
[simple_api_server-12] Set Server port to: 0.0.0.0:8083
[simple_api_server-12] Set RMF Websocket port to: localhost:7878
[simple_api_server-12] Starting Websocket Server
[simple_api_server-12] Starting RMF_Demos API Server: 0.0.0.0:8083, with ws://localhost:7878
[simple_api_server-12]  * Serving Flask app "rmf_demos_panel.simple_api_server" (lazy loading)
[simple_api_server-12]  * Environment: production
[simple_api_server-12]    WARNING: This is a development server. Do not use it in a production deployment.
[simple_api_server-12]    Use a production WSGI server instead.
[simple_api_server-12]  * Debug mode: off
[schedule_visualizer-5] [INFO] [1669980135.274509466] [rmf_visualization_schedule_marker_publisher]: Rviz parameters updated
[building_map_server-4] [INFO] [1669980135.408295706] [building_map_server]: loading map path: /home/fsi/rmf_ws/install/test_map/share/test_map/maps/map_test/map_test.building.yaml
[building_map_server-4] [INFO] [1669980135.411063175] [building_map_server]: opening: /home/fsi/rmf_ws/install/test_map/share/test_map/maps/map_test/../map_test.png
[building_map_server-4] [INFO] [1669980135.413912914] [building_map_server]: read 21735 byte image
[building_map_server-4] [INFO] [1669980135.414651719] [building_map_server]: unable to generate GeoJSON for this map.
[building_map_server-4] [INFO] [1669980135.419505002] [building_map_server]: publishing map...
[building_map_server-4] [INFO] [1669980135.420136932] [building_map_server]: ready to serve map: "map_test"  Ctrl+C to exit...
[schedule_visualizer-5] [INFO] [1669980135.420719214] [rmf_visualization_schedule_marker_publisher]: Received map "map_test" containing 1 level(s)
[schedule_visualizer-5] [INFO] [1669980135.420806075] [rmf_visualization_schedule_marker_publisher]: Level cache updated
[schedule_visualizer-5] [INFO] [1669980135.420928898] [rmf_visualization_schedule_marker_publisher]: Loading floorplan Image:  png
[free_fleet_server_ros2-15] [INFO] [1669980135.475450696] [lightrover_fleet_server_node]: registered a new robot: [lightrover1]
[rviz2-8] [INFO] [1669980135.559924851] [rviz2]: Trying to create a map of size 1984 x 1984 using 1 swatches
[rviz2-8] [ERROR] [1669980135.588876050] [rviz2]: Vertex Program:rviz/glsl120/indexed_8bit_image.vert Fragment Program:rviz/glsl120/indexed_8bit_image.frag GLSL link result : 
[rviz2-8] active samplers with a different type refer to the same texture image unit
[rmf_traffic_schedule-1] [INFO] [1669980135.888245427] [rmf_traffic_schedule_primary]: Registered participant [0] named [lightrover1] owned by [lightrover]
[full_control-13] [ERROR] [1669980135.897724910] [lightrover_fleet_adapter]: Malformed outgoing fleet state json message: At /data/robots of null - unexpected instance type
[full_control-13] 
[full_control-13] Message:
[full_control-13] {
[full_control-13]   "data": {
[full_control-13]     "name": "lightrover",
[full_control-13]     "robots": null
[full_control-13]   },
[full_control-13]   "type": "fleet_state_update"
[full_control-13] }
[full_control-13] [INFO] [1669980135.898679560] [lightrover_fleet_adapter]: Added a robot named [lightrover1] with participant ID [0]