Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Node takes a very long time to boot and load all plugins in Docker with network=host #1689

Closed
Vicidel opened this issue Jan 7, 2022 · 5 comments

Comments

@Vicidel
Copy link

Vicidel commented Jan 7, 2022

Issue details

The MAVROS2 node takes a very long time to fully boot with all plugins. There are no other intensive processes running in my machine (need to run alongside PX4 SITL, but it's not running in my tests).
The full boot time was as much as 7 minutes, which is not usable in my setup (currently using MAVROS1+ros1_bridge).

I'm putting boot logs below as well as the ros2 run command I'm using to start the nodes, but I don't really know what else may be needed to debug the issue.
In the logs below the nodes started at ts=16443554116 and finished it's boot at ts=1641554543, which gives us 543-116 = 427s ~= 7mn of booting time.

I'm running this in Docker (host networking), could this influence the results?

MAVROS version and platform

Mavros: 2.0.5
ROS: Galactic
Ubuntu: 20.04

Autopilot type and version

[ ] ArduPilot
[x] PX4

Node logs

I'm starting MAVROS2 with these lines:

ros2 run mavros mavros_node \
    --ros-args \
        -r __ns:="/SIM_DEV_VICTOR/mavros" \
        -p fcu_url:=udp://:14540@localhost:14557 \
        -p tgt_system:=1 \
        --params-file /home/workspace/config/px4_pluginlists.yaml

My plugin blacklist/whitelist file /home/workspace/config/px4_pluginlists.yaml is as follows:

/**:    
  ros__parameters:  
    plugin_denylist: [cam_imu_sync,camera,companion_process_status,debug_value,esc_status,esc_telemetry,fake_gps,ftp,gps_input,gps_rtk,gps_status,hil,landing_target,log_transfer,mag_calibration_status,manual_control,mocap_pose_estimate,mount_control,nav_controller_output,obstacle_distance,odometry,onboard_computer_status,play_tune,px,rangefinder,setpoint_accel,setpoint_attitude,setpoint_position,setpoint_trajectory,setpoint_velocity,tdr_radio,trajectory,tunnel,vibration,vision_pose,vision_speed,wheel_odomotry]
    # plugin_allowlist: []
[INFO] [1641554116.905111572] [SIM_DEV_VICTOR.mavros.mavros_node]: Starting mavros_node container
[INFO] [1641554116.905225624] [SIM_DEV_VICTOR.mavros.mavros_node]: FCU URL: udp://:14540@localhost:14557
[INFO] [1641554116.905245529] [SIM_DEV_VICTOR.mavros.mavros_node]: GCS URL: 
[INFO] [1641554116.905266062] [SIM_DEV_VICTOR.mavros.mavros_node]: UAS Prefix: /uas1
[INFO] [1641554116.905279472] [SIM_DEV_VICTOR.mavros.mavros_node]: Starting mavros router node
[INFO] [1641554116.912121863] [SIM_DEV_VICTOR.mavros.mavros_router]: Built-in SIMD instructions: SSE, SSE2
[INFO] [1641554116.912178575] [SIM_DEV_VICTOR.mavros.mavros_router]: Built-in MAVLink package version: 2021.12.12
[INFO] [1641554116.912199527] [SIM_DEV_VICTOR.mavros.mavros_router]: Known MAVLink dialects: common ardupilotmega ASLUAV all development icarous matrixpilot paparazzi standard uAvionix ualberta
[INFO] [1641554116.912217337] [SIM_DEV_VICTOR.mavros.mavros_router]: MAVROS Router started
[INFO] [1641554116.912416805] [SIM_DEV_VICTOR.mavros.mavros_router]: Requested to add endpoint: type: 0, url: udp://:14540@localhost:14557
[INFO] [1641554116.912775372] [SIM_DEV_VICTOR.mavros.mavros_router]: Endpoint link[1000] created
[INFO] [1641554116.914733873] [SIM_DEV_VICTOR.mavros.mavros_router]: link[1000] opened successfully
[INFO] [1641554116.914935436] [SIM_DEV_VICTOR.mavros.mavros_router]: Requested to add endpoint: type: 2, url: /uas1
[INFO] [1641554116.915114650] [SIM_DEV_VICTOR.mavros.mavros_router]: Endpoint link[1001] created
[INFO] [1641554116.916966922] [SIM_DEV_VICTOR.mavros.mavros_router]: link[1001] opened successfully
[INFO] [1641554116.917087050] [SIM_DEV_VICTOR.mavros.mavros_node]: Starting mavros uas node
[INFO] [1641554117.055951559] [SIM_DEV_VICTOR.mavros.mavros]: UAS Executor started
[INFO] [1641554117.091928207] [SIM_DEV_VICTOR.mavros.mavros]: Plugin actuator_control created
[INFO] [1641554117.092451461] [SIM_DEV_VICTOR.mavros.mavros]: Plugin actuator_control added to executor
[INFO] [1641554117.092501886] [SIM_DEV_VICTOR.mavros.mavros]: Plugin actuator_control initialized
[INFO] [1641554119.412569599] [SIM_DEV_VICTOR.mavros.mavros]: Plugin adsb created
[INFO] [1641554119.413264943] [SIM_DEV_VICTOR.mavros.mavros]: Plugin adsb added to executor
[INFO] [1641554119.413386817] [SIM_DEV_VICTOR.mavros.mavros]: Plugin adsb initialized
[INFO] [1641554119.445472444] [SIM_DEV_VICTOR.mavros.mavros]: Plugin altitude created
[INFO] [1641554119.445821513] [SIM_DEV_VICTOR.mavros.mavros]: Plugin altitude added to executor
[INFO] [1641554119.445880040] [SIM_DEV_VICTOR.mavros.mavros]: Plugin altitude initialized
[INFO] [1641554119.445922015] [SIM_DEV_VICTOR.mavros.mavros]: Plugin cam_imu_sync ignored
[INFO] [1641554119.445954840] [SIM_DEV_VICTOR.mavros.mavros]: Plugin camera ignored
[INFO] [1641554140.926859944] [SIM_DEV_VICTOR.mavros.mavros]: Plugin command created
[INFO] [1641554140.927314055] [SIM_DEV_VICTOR.mavros.mavros]: Plugin command added to executor
[INFO] [1641554140.927417909] [SIM_DEV_VICTOR.mavros.mavros]: Plugin command initialized
[INFO] [1641554140.927483351] [SIM_DEV_VICTOR.mavros.mavros]: Plugin companion_process_status ignored
[INFO] [1641554140.927539504] [SIM_DEV_VICTOR.mavros.mavros]: Plugin debug_value ignored
[INFO] [1641554150.140488588] [SIM_DEV_VICTOR.mavros.distance_sensor]: DS: Plugin not configured!
[INFO] [1641554150.140921956] [SIM_DEV_VICTOR.mavros.mavros]: Plugin distance_sensor created
[INFO] [1641554150.141381584] [SIM_DEV_VICTOR.mavros.mavros]: Plugin distance_sensor added to executor
[INFO] [1641554150.141478873] [SIM_DEV_VICTOR.mavros.mavros]: Plugin distance_sensor initialized
[INFO] [1641554150.141545502] [SIM_DEV_VICTOR.mavros.mavros]: Plugin esc_status ignored
[INFO] [1641554150.141600677] [SIM_DEV_VICTOR.mavros.mavros]: Plugin esc_telemetry ignored
[INFO] [1641554150.141652221] [SIM_DEV_VICTOR.mavros.mavros]: Plugin fake_gps ignored
[INFO] [1641554150.141707395] [SIM_DEV_VICTOR.mavros.mavros]: Plugin ftp ignored
[INFO] [1641554165.497115674] [SIM_DEV_VICTOR.mavros.mavros]: Plugin geofence created
[INFO] [1641554165.498212608] [SIM_DEV_VICTOR.mavros.mavros]: Plugin geofence added to executor
[INFO] [1641554165.498428279] [SIM_DEV_VICTOR.mavros.mavros]: Plugin geofence initialized
[INFO] [1641554190.071612226] [SIM_DEV_VICTOR.mavros.mavros]: Plugin global_position created
[INFO] [1641554190.072744151] [SIM_DEV_VICTOR.mavros.mavros]: Plugin global_position added to executor
[INFO] [1641554190.072883276] [SIM_DEV_VICTOR.mavros.mavros]: Plugin global_position initialized
[INFO] [1641554190.073000121] [SIM_DEV_VICTOR.mavros.mavros]: Plugin gps_input ignored
[INFO] [1641554190.073092591] [SIM_DEV_VICTOR.mavros.mavros]: Plugin gps_rtk ignored
[INFO] [1641554190.073193303] [SIM_DEV_VICTOR.mavros.mavros]: Plugin gps_status ignored
[INFO] [1641554190.073338643] [SIM_DEV_VICTOR.mavros.mavros]: Plugin hil ignored
[INFO] [1641554205.434783932] [SIM_DEV_VICTOR.mavros.mavros]: Plugin home_position created
[INFO] [1641554205.435269681] [SIM_DEV_VICTOR.mavros.mavros]: Plugin home_position added to executor
[INFO] [1641554205.435395117] [SIM_DEV_VICTOR.mavros.mavros]: Plugin home_position initialized
[INFO] [1641554230.006232889] [SIM_DEV_VICTOR.mavros.mavros]: Plugin imu created
[INFO] [1641554230.007515043] [SIM_DEV_VICTOR.mavros.mavros]: Plugin imu added to executor
[INFO] [1641554230.007638593] [SIM_DEV_VICTOR.mavros.mavros]: Plugin imu initialized
[INFO] [1641554230.007726384] [SIM_DEV_VICTOR.mavros.mavros]: Plugin landing_target ignored
[INFO] [1641554251.517203770] [SIM_DEV_VICTOR.mavros.mavros]: Plugin local_position created
[INFO] [1641554251.517971610] [SIM_DEV_VICTOR.mavros.mavros]: Plugin local_position added to executor
[INFO] [1641554251.518094671] [SIM_DEV_VICTOR.mavros.mavros]: Plugin local_position initialized
[INFO] [1641554251.518238685] [SIM_DEV_VICTOR.mavros.mavros]: Plugin log_transfer ignored
[INFO] [1641554251.518316977] [SIM_DEV_VICTOR.mavros.mavros]: Plugin mag_calibration_status ignored
[INFO] [1641554251.518393663] [SIM_DEV_VICTOR.mavros.mavros]: Plugin manual_control ignored
[INFO] [1641554251.518471607] [SIM_DEV_VICTOR.mavros.mavros]: Plugin mocap_pose_estimate ignored
[INFO] [1641554251.518544032] [SIM_DEV_VICTOR.mavros.mavros]: Plugin mount_control ignored
[INFO] [1641554251.518638528] [SIM_DEV_VICTOR.mavros.mavros]: Plugin nav_controller_output ignored
[INFO] [1641554251.518739938] [SIM_DEV_VICTOR.mavros.mavros]: Plugin obstacle_distance ignored
[INFO] [1641554251.518815228] [SIM_DEV_VICTOR.mavros.mavros]: Plugin odometry ignored
[INFO] [1641554251.518900085] [SIM_DEV_VICTOR.mavros.mavros]: Plugin onboard_computer_status ignored
[INFO] [1641554273.029745109] [SIM_DEV_VICTOR.mavros.mavros]: Plugin param created
[INFO] [1641554273.030023707] [SIM_DEV_VICTOR.mavros.mavros]: Plugin param added to executor
[INFO] [1641554273.030082654] [SIM_DEV_VICTOR.mavros.mavros]: Plugin param initialized
[INFO] [1641554273.030126305] [SIM_DEV_VICTOR.mavros.mavros]: Plugin play_tune ignored
[INFO] [1641554273.030161645] [SIM_DEV_VICTOR.mavros.mavros]: Plugin px ignored
[INFO] [1641554294.523149815] [SIM_DEV_VICTOR.mavros.mavros]: Plugin rallypoint created
[INFO] [1641554294.523612376] [SIM_DEV_VICTOR.mavros.mavros]: Plugin rallypoint added to executor
[INFO] [1641554294.523707710] [SIM_DEV_VICTOR.mavros.mavros]: Plugin rallypoint initialized
[INFO] [1641554294.523827070] [SIM_DEV_VICTOR.mavros.mavros]: Plugin rangefinder ignored
[INFO] [1641554316.029351258] [SIM_DEV_VICTOR.mavros.mavros]: Plugin rc_io created
[INFO] [1641554316.029841896] [SIM_DEV_VICTOR.mavros.mavros]: Plugin rc_io added to executor
[INFO] [1641554316.029907757] [SIM_DEV_VICTOR.mavros.mavros]: Plugin rc_io initialized
[INFO] [1641554316.029962094] [SIM_DEV_VICTOR.mavros.mavros]: Plugin setpoint_accel ignored
[INFO] [1641554316.030013218] [SIM_DEV_VICTOR.mavros.mavros]: Plugin setpoint_attitude ignored
[INFO] [1641554316.030065111] [SIM_DEV_VICTOR.mavros.mavros]: Plugin setpoint_position ignored
[INFO] [1641554343.672152940] [SIM_DEV_VICTOR.mavros.mavros]: Plugin setpoint_raw created
[INFO] [1641554343.672921268] [SIM_DEV_VICTOR.mavros.mavros]: Plugin setpoint_raw added to executor
[INFO] [1641554343.673073104] [SIM_DEV_VICTOR.mavros.mavros]: Plugin setpoint_raw initialized
[INFO] [1641554343.673183314] [SIM_DEV_VICTOR.mavros.mavros]: Plugin setpoint_trajectory ignored
[INFO] [1641554368.275954500] [SIM_DEV_VICTOR.mavros.mavros]: Plugin setpoint_velocity created
[INFO] [1641554368.276135181] [SIM_DEV_VICTOR.mavros.mavros]: Plugin setpoint_velocity added to executor
[INFO] [1641554368.276257334] [SIM_DEV_VICTOR.mavros.mavros]: Plugin setpoint_velocity initialized
[INFO] [1641554405.112106436] [SIM_DEV_VICTOR.mavros.mavros]: Plugin sys_status created
[INFO] [1641554405.113514933] [SIM_DEV_VICTOR.mavros.mavros]: Plugin sys_status added to executor
[INFO] [1641554405.113649518] [SIM_DEV_VICTOR.mavros.mavros]: Plugin sys_status initialized
[INFO] [1641554426.620369954] [SIM_DEV_VICTOR.mavros.time]: TM: Timesync mode: MAVLINK
[INFO] [1641554429.692863055] [SIM_DEV_VICTOR.mavros.mavros]: Plugin sys_time created
[INFO] [1641554429.693269534] [SIM_DEV_VICTOR.mavros.mavros]: Plugin sys_time added to executor
[INFO] [1641554429.693350062] [SIM_DEV_VICTOR.mavros.mavros]: Plugin sys_time initialized
[INFO] [1641554454.293985368] [SIM_DEV_VICTOR.mavros.mavros]: Plugin tdr_radio created
[INFO] [1641554454.294538445] [SIM_DEV_VICTOR.mavros.mavros]: Plugin tdr_radio added to executor
[INFO] [1641554454.294648725] [SIM_DEV_VICTOR.mavros.mavros]: Plugin tdr_radio initialized
[INFO] [1641554454.294756979] [SIM_DEV_VICTOR.mavros.mavros]: Plugin trajectory ignored
[INFO] [1641554454.294896383] [SIM_DEV_VICTOR.mavros.mavros]: Plugin tunnel ignored
[INFO] [1641554475.774284234] [SIM_DEV_VICTOR.mavros.mavros]: Plugin vfr_hud created
[INFO] [1641554475.774608439] [SIM_DEV_VICTOR.mavros.mavros]: Plugin vfr_hud added to executor
[INFO] [1641554475.774682472] [SIM_DEV_VICTOR.mavros.mavros]: Plugin vfr_hud initialized
[INFO] [1641554475.774743513] [SIM_DEV_VICTOR.mavros.mavros]: Plugin vibration ignored
[INFO] [1641554475.774790656] [SIM_DEV_VICTOR.mavros.mavros]: Plugin vision_pose ignored
[INFO] [1641554475.774843736] [SIM_DEV_VICTOR.mavros.mavros]: Plugin vision_speed ignored
[INFO] [1641554512.632716768] [SIM_DEV_VICTOR.mavros.mavros]: Plugin waypoint created
[INFO] [1641554512.633700768] [SIM_DEV_VICTOR.mavros.mavros]: Plugin waypoint added to executor
[INFO] [1641554512.633852394] [SIM_DEV_VICTOR.mavros.mavros]: Plugin waypoint initialized
[INFO] [1641554512.633984605] [SIM_DEV_VICTOR.mavros.mavros]: Plugin wheel_odomotry ignored
[INFO] [1641554537.211617244] [SIM_DEV_VICTOR.mavros.mavros]: Plugin wind_estimation created
[INFO] [1641554537.212376633] [SIM_DEV_VICTOR.mavros.mavros]: Plugin wind_estimation added to executor
[INFO] [1641554537.212496691] [SIM_DEV_VICTOR.mavros.mavros]: Plugin wind_estimation initialized
[INFO] [1641554543.349042167] [SIM_DEV_VICTOR.mavros.mavros]: Built-in SIMD instructions: SSE, SSE2
[INFO] [1641554543.349144206] [SIM_DEV_VICTOR.mavros.mavros]: Built-in MAVLink package version: 2021.12.12
[INFO] [1641554543.349196168] [SIM_DEV_VICTOR.mavros.mavros]: Known MAVLink dialects: common ardupilotmega ASLUAV all development icarous matrixpilot paparazzi standard uAvionix ualberta
[INFO] [1641554543.349251622] [SIM_DEV_VICTOR.mavros.mavros]: MAVROS UAS via /uas1 started. MY ID 1.191, TARGET ID 1.1
[INFO] [1641554543.349314829] [SIM_DEV_VICTOR.mavros.mavros_router]: link[1001] detected remote address 1.191
@Vicidel Vicidel changed the title Node takes a very long time to boot and load all plugins [ros2,question] Node takes a very long time to boot and load all plugins Jan 7, 2022
@vooon
Copy link
Member

vooon commented Jan 8, 2022

Hmm, on log i see 10-15 sec freezes. But absolutely unclear why. I'll try to reproduce, but might be hard to catch...

@Vicidel
Copy link
Author

Vicidel commented Jan 8, 2022

Ok at least good to know that it should not be the case. I'll try to debug also on Monday
Do you think it might be related to running it in Docker?

@vooon
Copy link
Member

vooon commented Jan 9, 2022

Usually i do not see any performance related troubles with docker. And i use docker for development a lot because i love to have newest os release...

@Vicidel Vicidel changed the title [ros2,question] Node takes a very long time to boot and load all plugins Node takes a very long time to boot and load all plugins Jan 10, 2022
@Vicidel
Copy link
Author

Vicidel commented Jan 10, 2022

I found the root of the issue, which is running Docker with --network=host, modifying the issue name accordingly.
With host network I have the boot time reported up, without it everything boots in ~500ms
Please test if this is enough to reproduce the bug on your side.

I can modify my working setup to work without the host networking in the meantime

@Vicidel Vicidel changed the title Node takes a very long time to boot and load all plugins Node takes a very long time to boot and load all plugins in Docker with network=host Jan 10, 2022
@Vicidel
Copy link
Author

Vicidel commented Apr 27, 2022

I did some more debugging on unrelated networking tasks and it seems like the issue is "just" an underlying ROS2 issue. As MAVROS2 uses one node for each plugin, each node tries to communicate with the outside with ROS2 simple participant discovery protocol (SPDP).

The SPDP was the thing that caused the long boot time, mainly because each MAVROS2 node boots one by one and tries to connect to the previous ones. When in network=bridge the MAVROS2 nodes don't try to reach the whole network, so it gies much faster

I'll close this issue as this is not a MAVROS2 issue, but a ROS2 issue. If it can help other people, the two solutions I found are using the FastDDS RMW and two of their features: Discovery Server and Interface Whitelisting

@Vicidel Vicidel closed this as completed Apr 27, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants