mavros fails to start - Githubissues

goodrobots / maverick

UAV Autonomous Systems Management

https://goodrobots.github.io/maverick/

MIT License

171 stars 61 forks source link

mavros fails to start #932

Closed SamuelDudley closed 4 years ago

SamuelDudley commented 4 years ago

pi3b+ master, dev 1.2-b image updated and configured to current master /ros/dev/latest/ rosout-1-stdout.log master.log roslaunch-maverick-raspberrylite-1212.log roslaunch-maverick-raspberrylite-1332.log rosout.log

/ros/dev/mavros.XXX.log

[33m[ WARN] [1584939836.835661962]: TM : RTT too high for timesync: 51.62 ms.[0m
[33m[ WARN] [1584939837.834113248]: TM : RTT too high for timesync: 50.25 ms.[0m
[33m[ WARN] [1584939838.597087867]: TM : RTT too high for timesync: 13.10 ms.[0m
[33m[ WARN] [1584939842.203553978]: TM : RTT too high for timesync: 19.56 ms.[0m
[33m[ WARN] [1584939843.194135987]: TM : RTT too high for timesync: 10.14 ms.[0m
[33m[ WARN] [1584939843.858888657]: TM : RTT too high for timesync: 74.99 ms.[0m
[33m[ WARN] [1584939845.097550432]: TM : RTT too high for timesync: 13.59 ms.[0m
[31m[ERROR] [1584939846.178254795]: tcp0: receive: End of file[0m
terminate called after throwing an instance of 'std::system_error'
  what():  Resource deadlock avoided
[31m================================================================================REQUIRED process [mavros-1] has died!
process has died [pid 1348, exit code -6, cmd /srv/maverick/software/ros/current/lib/mavros/mavros_node __name:=mavros __log:=/srv/maverick/var/log/ros/dev/687e0544-6cc2-11ea-b6a0-b827eb2b499a/mavros-1.log].
log file: /srv/maverick/var/log/ros/dev/687e0544-6cc2-11ea-b6a0-b827eb2b499a/mavros-1*.log
Initiating shutdown!
================================================================================[0m
... logging to /srv/maverick/var/log/ros/dev/687e0544-6cc2-11ea-b6a0-b827eb2b499a/roslaunch-maverick-raspberrylite-1332.log
Checking log directory for disk usage. This may take a while.
Press Ctrl-C to interrupt
Done checking log file disk usage. Usage is <1GB.
]2;/srv/maverick/software/ros/current/share/mavros/launch/apm.launch
[1mstarted roslaunch server http://maverick-raspberrylite:44455/[0m

SUMMARY
========

CLEAR PARAMETERS
 * /mavros/

PARAMETERS
 * /mavros/cmd/use_comp_id_system_control: False
 * /mavros/conn/heartbeat_mav_type: ONBOARD_CONTROLLER
 * /mavros/conn/heartbeat_rate: 1.0
 * /mavros/conn/system_time_rate: 1.0
 * /mavros/conn/timeout: 10.0
 * /mavros/conn/timesync_rate: 10.0
 * /mavros/distance_sensor/rangefinder_pub/field_of_view: 0.0
 * /mavros/distance_sensor/rangefinder_pub/frame_id: lidar
 * /mavros/distance_sensor/rangefinder_pub/id: 0
 * /mavros/distance_sensor/rangefinder_pub/send_tf: False
 * /mavros/distance_sensor/rangefinder_pub/sensor_position/x: 0.0
 * /mavros/distance_sensor/rangefinder_pub/sensor_position/y: 0.0
 * /mavros/distance_sensor/rangefinder_pub/sensor_position/z: -0.1
 * /mavros/distance_sensor/rangefinder_sub/id: 1
 * /mavros/distance_sensor/rangefinder_sub/orientation: PITCH_270
 * /mavros/distance_sensor/rangefinder_sub/subscriber: True
 * /mavros/fake_gps/eph: 2.0
 * /mavros/fake_gps/epv: 2.0
 * /mavros/fake_gps/fix_type: 3
 * /mavros/fake_gps/geo_origin/alt: 408.0
 * /mavros/fake_gps/geo_origin/lat: 47.3667
 * /mavros/fake_gps/geo_origin/lon: 8.55
 * /mavros/fake_gps/gps_rate: 5.0
 * /mavros/fake_gps/mocap_transform: True
 * /mavros/fake_gps/satellites_visible: 5
 * /mavros/fake_gps/tf/child_frame_id: fix
 * /mavros/fake_gps/tf/frame_id: map
 * /mavros/fake_gps/tf/listen: False
 * /mavros/fake_gps/tf/rate_limit: 10.0
 * /mavros/fake_gps/tf/send: False
 * /mavros/fake_gps/use_mocap: True
 * /mavros/fake_gps/use_vision: False
 * /mavros/fcu_protocol: v2.0
 * /mavros/fcu_url: tcp://localhost:6000
 * /mavros/gcs_url: 
 * /mavros/global_position/child_frame_id: base_link
 * /mavros/global_position/frame_id: map
 * /mavros/global_position/gps_uere: 1.0
 * /mavros/global_position/rot_covariance: 99999.0
 * /mavros/global_position/tf/child_frame_id: base_link
 * /mavros/global_position/tf/frame_id: map
 * /mavros/global_position/tf/global_frame_id: earth
 * /mavros/global_position/tf/send: False
 * /mavros/global_position/use_relative_alt: True
 * /mavros/image/frame_id: px4flow
 * /mavros/imu/angular_velocity_stdev: 0.0003490659 // 0...
 * /mavros/imu/frame_id: base_link
 * /mavros/imu/linear_acceleration_stdev: 0.0003
 * /mavros/imu/magnetic_stdev: 0.0
 * /mavros/imu/orientation_stdev: 1.0
 * /mavros/landing_target/camera/fov_x: 2.0071286398
 * /mavros/landing_target/camera/fov_y: 2.0071286398
 * /mavros/landing_target/image/height: 480
 * /mavros/landing_target/image/width: 640
 * /mavros/landing_target/land_target_type: VISION_FIDUCIAL
 * /mavros/landing_target/listen_lt: False
 * /mavros/landing_target/mav_frame: LOCAL_NED
 * /mavros/landing_target/target_size/x: 0.3
 * /mavros/landing_target/target_size/y: 0.3
 * /mavros/landing_target/tf/child_frame_id: camera_center
 * /mavros/landing_target/tf/frame_id: landing_target
 * /mavros/landing_target/tf/listen: False
 * /mavros/landing_target/tf/rate_limit: 10.0
 * /mavros/landing_target/tf/send: True
 * /mavros/local_position/frame_id: map
 * /mavros/local_position/tf/child_frame_id: base_link
 * /mavros/local_position/tf/frame_id: map
 * /mavros/local_position/tf/send: False
 * /mavros/local_position/tf/send_fcu: False
 * /mavros/mission/pull_after_gcs: True
 * /mavros/mocap/use_pose: True
 * /mavros/mocap/use_tf: False
 * /mavros/odometry/estimator_type: 3
 * /mavros/odometry/frame_tf/desired_frame: ned
 * /mavros/plugin_blacklist: ['actuator_contro...
 * /mavros/plugin_whitelist: []
 * /mavros/px4flow/frame_id: px4flow
 * /mavros/px4flow/ranger_fov: 0.118682
 * /mavros/px4flow/ranger_max_range: 5.0
 * /mavros/px4flow/ranger_min_range: 0.3
 * /mavros/safety_area/p1/x: 1.0
 * /mavros/safety_area/p1/y: 1.0
 * /mavros/safety_area/p1/z: 1.0
 * /mavros/safety_area/p2/x: -1.0
 * /mavros/safety_area/p2/y: -1.0
 * /mavros/safety_area/p2/z: -1.0
 * /mavros/setpoint_accel/send_force: False
 * /mavros/setpoint_attitude/reverse_thrust: False
 * /mavros/setpoint_attitude/tf/child_frame_id: target_attitude
 * /mavros/setpoint_attitude/tf/frame_id: map
 * /mavros/setpoint_attitude/tf/listen: False
 * /mavros/setpoint_attitude/tf/rate_limit: 50.0
 * /mavros/setpoint_attitude/use_quaternion: False
 * /mavros/setpoint_position/mav_frame: LOCAL_NED
 * /mavros/setpoint_position/tf/child_frame_id: target_position
 * /mavros/setpoint_position/tf/frame_id: map
 * /mavros/setpoint_position/tf/listen: False
 * /mavros/setpoint_position/tf/rate_limit: 50.0
 * /mavros/setpoint_raw/thrust_scaling: 1.0
 * /mavros/setpoint_velocity/mav_frame: LOCAL_NED
 * /mavros/startup_px4_usb_quirk: False
 * /mavros/sys/disable_diag: False
 * /mavros/sys/min_voltage: 10.0
 * /mavros/target_component_id: 1
 * /mavros/target_system_id: 1
 * /mavros/tdr_radio/low_rssi: 40
 * /mavros/time/time_ref_source: fcu
 * /mavros/time/timesync_avg_alpha: 0.6
 * /mavros/time/timesync_mode: MAVLINK
 * /mavros/vibration/frame_id: base_link
 * /mavros/vision_pose/tf/child_frame_id: vision_estimate
 * /mavros/vision_pose/tf/frame_id: map
 * /mavros/vision_pose/tf/listen: False
 * /mavros/vision_pose/tf/rate_limit: 10.0
 * /mavros/vision_speed/listen_twist: True
 * /mavros/vision_speed/twist_cov: True
 * /mavros/wheel_odometry/child_frame_id: base_link
 * /mavros/wheel_odometry/count: 2
 * /mavros/wheel_odometry/frame_id: map
 * /mavros/wheel_odometry/send_raw: True
 * /mavros/wheel_odometry/send_twist: False
 * /mavros/wheel_odometry/tf/child_frame_id: base_link
 * /mavros/wheel_odometry/tf/frame_id: map
 * /mavros/wheel_odometry/tf/send: True
 * /mavros/wheel_odometry/use_rpm: False
 * /mavros/wheel_odometry/vel_error: 0.1
 * /mavros/wheel_odometry/wheel0/radius: 0.05
 * /mavros/wheel_odometry/wheel0/x: 0.0
 * /mavros/wheel_odometry/wheel0/y: -0.15
 * /mavros/wheel_odometry/wheel1/radius: 0.05
 * /mavros/wheel_odometry/wheel1/x: 0.0
 * /mavros/wheel_odometry/wheel1/y: 0.15
 * /rosdistro: melodic
 * /rosversion: 1.14.4

NODES
  /
    mavros (mavros/mavros_node)

[1mROS_MASTER_URI=http://localhost:11000[0m
]2;/srv/maverick/software/ros/current/share/mavros/launch/apm.launch http://localhost:11000
[1mprocess[mavros-1]: started with pid [1348][0m
[mavros-1] killing on exit
shutting down processing monitor...
... shutting down processing monitor complete
[1mdone[0m

sudo journalctl potential hints:

Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]: RLException: ERROR: could not contact master [http://maverick-raspberrylite:11000/]
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]: The traceback for the exception was written to the log file
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]: ... logging to /srv/maverick/var/log/ros/dev/48e8f220-6cc2-11ea-97bc-b827eb2b499a/roslaunch-maverick-raspberrylite-775.log
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]: Checking log directory for disk usage. This may take a while.
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]: Press Ctrl-C to interrupt
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]: Done checking log file disk usage. Usage is <1GB.
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]: 
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]: started roslaunch server http://maverick-raspberrylite:34163/
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]: ros_comm version 1.14.4
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]: SUMMARY
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]: ========
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]: PARAMETERS
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]:  * /rosdistro: melodic
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]:  * /rosversion: 1.14.4
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]: NODES
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]: auto-starting new master
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]: process[master]: started with pid [1027]
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]: Traceback (most recent call last):
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]:   File "/srv/maverick/software/ros/current/bin/rosmaster", line 35, in <module>
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]:     rosmaster.rosmaster_main()
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]:   File "/opt/ros/current/lib/python2.7/dist-packages/rosmaster/main.py", line 84, in rosmaster_main
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]:     configure_logging()
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]:   File "/opt/ros/current/lib/python2.7/dist-packages/rosmaster/main.py", line 58, in configure_logging
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]:     _log_filename = rosgraph.roslogging.configure_logging('rosmaster', logging.DEBUG, filename=filename)
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]:   File "/opt/ros/current/lib/python2.7/dist-packages/rosgraph/roslogging.py", line 162, in configure_logging
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]:     rospkg.RosPack().get_path('rosgraph'), 'conf'))
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]:   File "/usr/lib/python2.7/dist-packages/rospkg/rospack.py", line 201, in get_path
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]:     self._update_location_cache()
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]:   File "/usr/lib/python2.7/dist-packages/rospkg/rospack.py", line 184, in _update_location_cache
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]:     list_by_path(self._manifest_name, path, cache)
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]:   File "/usr/lib/python2.7/dist-packages/rospkg/rospack.py", line 67, in list_by_path
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]:     root = ElementTree(None, os.path.join(d, PACKAGE_FILE))
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]:   File "/usr/lib/python2.7/xml/etree/ElementTree.py", line 611, in __init__
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]:     self.parse(file)
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]:   File "<string>", line 38, in parse
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]: KeyboardInterrupt
Mar 23 04:54:08 maverick-raspberrylite rosmaster.sh[704]: [master] killing on exit
Mar 23 04:54:09 maverick-raspberrylite systemd[1]: maverick-rosmaster@dev.service: Main process exited, code=exited, status=1/FAILURE
Mar 23 04:54:09 maverick-raspberrylite systemd[1]: maverick-rosmaster@dev.service: Failed with result 'exit-code'.

fnoop commented 4 years ago

Ah, this is because of the port refactor. I'll add a note to either clear out the config entirely: find /srv/maverick/config -path /srv/maverick/config/maverick -prune -o -type f -exec rm -f {} \; or better yet just start with a fresh image with the next beta. Theoretically it's possible to upgrade from 1.1.x but it's probably easier to just advise to start again with fresh image.