mavlink / mavros

MAVLink to ROS gateway with proxy for Ground Control Station
Other
902 stars 993 forks source link

High latency with intel joule #825

Closed gui2dev closed 6 years ago

gui2dev commented 7 years ago

Issue details

I'm using mavros on an intel joule. I am experiencing very high latency and timeouts with waypoints and param plugins. My first guess is that it's hardware related, because changing the computer that executes the launch file seems to solve the issue. In addition to that, uploading waypoints from UGS seems flawless. For now my only way around that issue is to increase LIST_TIMEOUT_MS to 600 000 to be able to load a waypoint table of about 605 elements.

MAVROS version and platform

Mavros: 0.21.2 ROS: Kinetic Ubuntu: 16.04

Autopilot type and version

[X] ArduPilot [ ] PX4

Version: 3.5

Node logs

roslaunch falcon_v2 start.launch 
... logging to /home/gdev/.ros/log/e337335a-a285-11e7-9847-a0c5893bcefa/roslaunch-jBoard-3312.log
Checking log directory for disk usage. This may take awhile.
Press Ctrl-C to interrupt
Done checking log file disk usage. Usage is <1GB.

started roslaunch server http://jBoard:45966/

SUMMARY
========

CLEAR PARAMETERS
 * /mavros/

PARAMETERS
 * /alexmos/baudrate: 115200
 * /alexmos/device: /dev/ttyUSB0
 * /falcon/altitude: 100.0
 * /falcon/distance: 18000.0
 * /falcon/heading: 270.0
 * /falcon/log_path: /media/gdev/7976-...
 * /falcon/mission_path: /media/gdev/7976-...
 * /mavros/cmd/use_comp_id_system_control: False
 * /mavros/conn/heartbeat_rate: 1.0
 * /mavros/conn/system_time_rate: 0.0
 * /mavros/conn/timeout: 10.0
 * /mavros/conn/timesync_rate: 0.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/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: /dev/ttyACM0:57600
 * /mavros/gcs_url: udp://10.42.0.1:1...
 * /mavros/global_position/frame_id: map
 * /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: True
 * /mavros/global_position/use_relative_alt: True
 * /mavros/image/frame_id: px4flow
 * /mavros/imu/angular_velocity_stdev: 0.000349065850399
 * /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/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: True
 * /mavros/local_position/tf/send_fcu: False
 * /mavros/mission/enable_partial_push: True
 * /mavros/mission/pull_after_gcs: True
 * /mavros/mission/trig_after_reached: True
 * /mavros/mission/trig_srv_name: /falcon/trig
 * /mavros/mocap/use_pose: True
 * /mavros/mocap/use_tf: False
 * /mavros/odometry/estimator_type: 3
 * /mavros/plugin_blacklist: ['actuator_contro...
 * /mavros/plugin_whitelist: []
 * /mavros/px4flow/frame_id: px4flow
 * /mavros/px4flow/ranger_fov: 0.118682389136
 * /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: True
 * /mavros/setpoint_attitude/tf/rate_limit: 50.0
 * /mavros/setpoint_attitude/use_quaternion: False
 * /mavros/setpoint_position/tf/child_frame_id: target_position
 * /mavros/setpoint_position/tf/frame_id: map
 * /mavros/setpoint_position/tf/listen: True
 * /mavros/setpoint_position/tf/rate_limit: 50.0
 * /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: NONE
 * /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: False
 * /rosdistro: kinetic
 * /rosversion: 1.12.7
 * /visualization/arm_length: 0.3
 * /visualization/body_height: 0.1
 * /visualization/body_with: 0.15
 * /visualization/child_frame_id: base_link
 * /visualization/fixed_frame_id: map
 * /visualization/num_rotors: 6

NODES
  /
    alexmos (alexmos/alexmos)
    falcon (falcon_v2/falcon)
    mavros (mavros/mavros_node)
    visualization (mavros_extras/copter_visualization)

auto-starting new master
process[master]: started with pid [3323]
ROS_MASTER_URI=http://localhost:11311

setting /run_id to e337335a-a285-11e7-9847-a0c5893bcefa
process[rosout-1]: started with pid [3336]
started core service [/rosout]
process[mavros-2]: started with pid [3354]
process[visualization-3]: started with pid [3355]
process[falcon-4]: started with pid [3356]
process[alexmos-5]: started with pid [3364]
[ INFO] [1506408159.659030453]: Initializing serial
[ INFO] [1506408159.660703815]: SERIAL succesfully opened
[ INFO] [1506408159.660785336]: Initializing parser
[ INFO] [1506408159.660826339]: Special message 86 - 2
[ INFO] [1506408159.660853349]: 0 - 0
[ INFO] [1506408159.660887379]: 1 - 0
[ INFO] [1506408159.666018996]: Initialiazing GPIO on INTEL JOULE EXPANSION
[ INFO] [1506408159.669144140]: Special message 86 - 2
[ INFO] [1506408159.669244292]: 0 - 0
[ INFO] [1506408159.669269054]: 1 - 0
[ INFO] [1506408159.679074476]: Special message 86 - 2
[ INFO] [1506408159.679150075]: 0 - 0
[ INFO] [1506408159.679172971]: 1 - 0
[ INFO] [1506408159.679310295]: Connected to board 30, firmware 44-10
[ INFO] [1506408159.689071173]: Special message 85 - 21
[ INFO] [1506408159.689155182]: 0 - 17
[ INFO] [1506408159.689186678]: 1 - 4b
[ INFO] [1506408159.689215155]: 2 - 0
[ INFO] [1506408159.689253056]: 3 - 0
[ INFO] [1506408159.689281877]: 4 - 0
[ INFO] [1506408159.689317421]: 5 - 0
[ INFO] [1506408159.689352829]: 6 - 0
[ INFO] [1506408159.689390479]: 7 - 0
[ INFO] [1506408159.689459424]: 8 - 0
[ INFO] [1506408159.689488629]: 9 - 0
[ INFO] [1506408159.689516944]: 10 - 0
[ INFO] [1506408159.689545524]: 11 - 0
[ INFO] [1506408159.689574094]: 12 - 0
[ INFO] [1506408159.689610752]: 13 - 0
[ INFO] [1506408159.689640316]: 14 - 0
[ INFO] [1506408159.689675623]: 15 - 0
[ INFO] [1506408159.689711491]: 16 - 0
[ INFO] [1506408159.689739892]: 17 - 0
[ INFO] [1506408159.689765429]: 18 - 0
[ INFO] [1506408159.689792972]: 19 - 0
[ INFO] [1506408159.689820812]: 20 - 0
[ INFO] [1506408159.690003804]: Connected to board 30, firmware 44-10
[ INFO] [1506408159.699124720]: Connected to board 30, firmware 44-10
[ INFO] [1506408159.709061180]: BGC - Confirm
[ INFO] [1506408159.776099190]: Waiting for FCU
[ INFO] [1506408159.799478321]: FCU URL: /dev/ttyACM0:57600
[ WARN] [1506408159.801457514]: init: message from ASLUAV, MSG-ID 201 ignored! Table has different entry.
[ WARN] [1506408159.801894078]: init: message from autoquad, MSG-ID 150 ignored! Table has different entry.
[ WARN] [1506408159.801969458]: init: message from autoquad, MSG-ID 152 ignored! Table has different entry.
[ WARN] [1506408159.802353556]: init: message from matrixpilot, MSG-ID 150 ignored! Table has different entry.
[ WARN] [1506408159.802438571]: init: message from matrixpilot, MSG-ID 151 ignored! Table has different entry.
[ WARN] [1506408159.802506015]: init: message from matrixpilot, MSG-ID 152 ignored! Table has different entry.
[ WARN] [1506408159.802571728]: init: message from matrixpilot, MSG-ID 153 ignored! Table has different entry.
[ WARN] [1506408159.802636553]: init: message from matrixpilot, MSG-ID 155 ignored! Table has different entry.
[ WARN] [1506408159.802697094]: init: message from matrixpilot, MSG-ID 156 ignored! Table has different entry.
[ WARN] [1506408159.802734730]: init: message from matrixpilot, MSG-ID 157 ignored! Table has different entry.
[ WARN] [1506408159.802775001]: init: message from matrixpilot, MSG-ID 158 ignored! Table has different entry.
[ WARN] [1506408159.802818146]: init: message from matrixpilot, MSG-ID 170 ignored! Table has different entry.
[ WARN] [1506408159.802856459]: init: message from matrixpilot, MSG-ID 171 ignored! Table has different entry.
[ WARN] [1506408159.802898798]: init: message from matrixpilot, MSG-ID 172 ignored! Table has different entry.
[ WARN] [1506408159.802936327]: init: message from matrixpilot, MSG-ID 173 ignored! Table has different entry.
[ WARN] [1506408159.802978074]: init: message from matrixpilot, MSG-ID 174 ignored! Table has different entry.
[ WARN] [1506408159.803014007]: init: message from matrixpilot, MSG-ID 175 ignored! Table has different entry.
[ WARN] [1506408159.803051304]: init: message from matrixpilot, MSG-ID 176 ignored! Table has different entry.
[ WARN] [1506408159.803092905]: init: message from matrixpilot, MSG-ID 177 ignored! Table has different entry.
[ WARN] [1506408159.803160317]: init: message from matrixpilot, MSG-ID 178 ignored! Table has different entry.
[ WARN] [1506408159.803204178]: init: message from matrixpilot, MSG-ID 179 ignored! Table has different entry.
[ WARN] [1506408159.803242099]: init: message from matrixpilot, MSG-ID 180 ignored! Table has different entry.
[ WARN] [1506408159.803277696]: init: message from matrixpilot, MSG-ID 181 ignored! Table has different entry.
[ WARN] [1506408159.803322462]: init: message from matrixpilot, MSG-ID 182 ignored! Table has different entry.
[ WARN] [1506408159.803358459]: init: message from matrixpilot, MSG-ID 183 ignored! Table has different entry.
[ WARN] [1506408159.803395598]: init: message from matrixpilot, MSG-ID 184 ignored! Table has different entry.
[ WARN] [1506408159.803455891]: init: message from matrixpilot, MSG-ID 185 ignored! Table has different entry.
[ WARN] [1506408159.803499410]: init: message from matrixpilot, MSG-ID 186 ignored! Table has different entry.
[ WARN] [1506408159.803806462]: init: message from paparazzi, MSG-ID 180 ignored! Table has different entry.
[ WARN] [1506408159.803848839]: init: message from paparazzi, MSG-ID 181 ignored! Table has different entry.
[ WARN] [1506408159.803885398]: init: message from paparazzi, MSG-ID 182 ignored! Table has different entry.
[ WARN] [1506408159.803921534]: init: message from paparazzi, MSG-ID 183 ignored! Table has different entry.
[ WARN] [1506408159.803957635]: init: message from paparazzi, MSG-ID 184 ignored! Table has different entry.
[ WARN] [1506408159.804339394]: init: message from slugs, MSG-ID 170 ignored! Table has different entry.
[ WARN] [1506408159.804387351]: init: message from slugs, MSG-ID 172 ignored! Table has different entry.
[ WARN] [1506408159.804441253]: init: message from slugs, MSG-ID 173 ignored! Table has different entry.
[ WARN] [1506408159.804483940]: init: message from slugs, MSG-ID 176 ignored! Table has different entry.
[ WARN] [1506408159.804521282]: init: message from slugs, MSG-ID 177 ignored! Table has different entry.
[ WARN] [1506408159.804562157]: init: message from slugs, MSG-ID 179 ignored! Table has different entry.
[ WARN] [1506408159.804601806]: init: message from slugs, MSG-ID 180 ignored! Table has different entry.
[ WARN] [1506408159.804643054]: init: message from slugs, MSG-ID 181 ignored! Table has different entry.
[ WARN] [1506408159.804680260]: init: message from slugs, MSG-ID 184 ignored! Table has different entry.
[ WARN] [1506408159.804721766]: init: message from slugs, MSG-ID 185 ignored! Table has different entry.
[ WARN] [1506408159.804761408]: init: message from slugs, MSG-ID 186 ignored! Table has different entry.
[ WARN] [1506408159.804802637]: init: message from slugs, MSG-ID 188 ignored! Table has different entry.
[ WARN] [1506408159.804846238]: init: message from slugs, MSG-ID 191 ignored! Table has different entry.
[ WARN] [1506408159.804886739]: init: message from slugs, MSG-ID 192 ignored! Table has different entry.
[ WARN] [1506408159.804926027]: init: message from slugs, MSG-ID 193 ignored! Table has different entry.
[ WARN] [1506408159.804966883]: init: message from slugs, MSG-ID 194 ignored! Table has different entry.
[ INFO] [1506408159.805993310]: serial0: device: /dev/ttyACM0 @ 57600 bps
[ INFO] [1506408159.806970394]: GCS URL: udp://10.42.0.1:14555@10.42.0.20:14550
[ INFO] [1506408159.807847522]: udp1: Bind address: 10.42.0.1:14555
[ INFO] [1506408159.808003687]: udp1: Remote address: 10.42.0.20:14550
[ INFO] [1506408159.876256735]: Waiting for FCU
[ INFO] [1506408159.893302574]: Plugin 3dr_radio loaded
[ INFO] [1506408159.900895906]: Plugin 3dr_radio initialized
[ INFO] [1506408159.901194481]: Plugin actuator_control blacklisted
[ INFO] [1506408159.962659938]: Plugin adsb loaded
[ INFO] [1506408159.976350653]: Waiting for FCU
[ INFO] [1506408159.978359233]: Plugin adsb initialized
[ INFO] [1506408159.978648386]: Plugin altitude blacklisted
[ INFO] [1506408159.979148465]: Plugin cam_imu_sync loaded
[ INFO] [1506408159.982595118]: Plugin cam_imu_sync initialized
[ INFO] [1506408159.983441028]: Plugin command loaded
[ INFO] [1506408160.009588339]: Plugin command initialized
[ INFO] [1506408160.010139641]: Plugin distance_sensor loaded
[ INFO] [1506408160.053585669]: Plugin distance_sensor initialized
[ INFO] [1506408160.053963527]: Plugin fake_gps loaded
[ INFO] [1506408160.076329038]: Waiting for FCU
[ INFO] [1506408160.126006775]: Plugin fake_gps initialized
[ INFO] [1506408160.126092072]: Plugin ftp blacklisted
[ INFO] [1506408160.126538661]: Plugin global_position loaded
[ INFO] [1506408160.176260112]: Waiting for FCU
[ INFO] [1506408160.202764846]: Plugin global_position initialized
[ INFO] [1506408160.203220220]: Plugin hil loaded
[ INFO] [1506408160.276282776]: Waiting for FCU
[ INFO] [1506408160.277989916]: Plugin hil initialized
[ INFO] [1506408160.278703902]: Plugin home_position loaded
[ INFO] [1506408160.299150368]: Plugin home_position initialized
[ INFO] [1506408160.299849856]: Plugin imu loaded
[ INFO] [1506408160.336248321]: Plugin imu initialized
[ INFO] [1506408160.336742410]: Plugin local_position loaded
[ INFO] [1506408160.366230356]: Plugin local_position initialized
[ INFO] [1506408160.366340139]: Plugin manual_control blacklisted
[ INFO] [1506408160.366393022]: Plugin mocap_pose_estimate blacklisted
[ INFO] [1506408160.366936110]: Plugin odom loaded
[ INFO] [1506408160.376211132]: Waiting for FCU
[ INFO] [1506408160.385918818]: Plugin odom initialized
[ INFO] [1506408160.386005764]: Plugin param blacklisted
[ INFO] [1506408160.386046518]: Plugin px4flow blacklisted
[ INFO] [1506408160.386368497]: Plugin rangefinder loaded
[ INFO] [1506408160.389493472]: Plugin rangefinder initialized
[ INFO] [1506408160.389982904]: Plugin rc_io loaded
[ INFO] [1506408160.408687806]: Plugin rc_io initialized
[ INFO] [1506408160.408789864]: Plugin safety_area blacklisted
[ INFO] [1506408160.408835016]: Plugin setpoint_accel blacklisted
[ INFO] [1506408160.409573137]: Plugin setpoint_attitude loaded
[ INFO] [1506408160.444251544]: Listen to desired attitude transform map -> target_attitude
[ INFO] [1506408160.444788327]: Plugin setpoint_attitude initialized
[ INFO] [1506408160.445155012]: Plugin setpoint_position loaded
[ INFO] [1506408160.462612012]: Listen to position setpoint transform map -> target_position
[ INFO] [1506408160.463247450]: Plugin setpoint_position initialized
[ INFO] [1506408160.463318448]: Plugin setpoint_raw blacklisted
[ INFO] [1506408160.463373327]: Plugin setpoint_velocity blacklisted
[ INFO] [1506408160.464085221]: Plugin sys_status loaded
[ INFO] [1506408160.476199062]: Waiting for FCU
[ INFO] [1506408160.493518430]: Plugin sys_status initialized
[ INFO] [1506408160.494039562]: Plugin sys_time loaded
[ INFO] [1506408160.510777375]: TM: Timesync mode: NONE
[ INFO] [1506408160.513656985]: Plugin sys_time initialized
[ INFO] [1506408160.514077568]: Plugin vfr_hud loaded
[ INFO] [1506408160.520060564]: Plugin vfr_hud initialized
[ INFO] [1506408160.520161066]: Plugin vibration blacklisted
[ INFO] [1506408160.520205097]: Plugin vision_pose_estimate blacklisted
[ INFO] [1506408160.520264262]: Plugin vision_speed_estimate blacklisted
[ INFO] [1506408160.520734517]: Plugin waypoint loaded
[ INFO] [1506408160.549316008]: Plugin waypoint initialized
[ INFO] [1506408160.549591082]: Built-in SIMD instructions: SSE, SSE2
[ INFO] [1506408160.549654111]: Built-in MAVLink package version: 2017.9.9
[ INFO] [1506408160.549711573]: Known MAVLink dialects: common ardupilotmega ASLUAV autoquad matrixpilot paparazzi slugs standard uAvionix ualberta
[ INFO] [1506408160.549770461]: MAVROS started. MY ID 1.240, TARGET ID 1.1
[ INFO] [1506408160.576322012]: Waiting for FCU
[ WARN] [1506408160.577926084]: IMU: linear acceleration on RAW_IMU known on APM only.
[ WARN] [1506408160.578033653]: IMU: ~imu/data_raw stores unscaled raw acceleration report.
[ INFO] [1506408160.584811781]: RC_CHANNELS message detected!
[ INFO] [1506408160.676638126]: Waiting for FCU
[ INFO] [1506408160.776668671]: Waiting for FCU
[ INFO] [1506408160.876661367]: Waiting for FCU
[ INFO] [1506408160.976669974]: Waiting for FCU
[ INFO] [1506408161.076663576]: Waiting for FCU
[ INFO] [1506408161.176680237]: Waiting for FCU
[ INFO] [1506408161.276713979]: Waiting for FCU
[ INFO] [1506408161.284930114]: CON: Got HEARTBEAT, connected. FCU: ArduPilotMega / ArduCopter
[ INFO] [1506408161.293873110]: RC_CHANNELS message detected!
[ INFO] [1506408161.376314910]: Waiting for FCU
[ INFO] [1506408161.376471455]: FCU connected
[ INFO] [1506408161.376564287]: Changine stream rate
[ INFO] [1506408161.381294989]: Checking for history
[ INFO] [1506408161.381605882]: History found, loading
[ INFO] [1506408161.381713067]: Reading from /media/gdev/7976-E714/Sensilize/mission/mission45.waypoints
[ INFO] [1506408161.395493267]: Done
[ INFO] [1506408161.395556883]: Read 1802 waypoints
[ INFO] [1506408161.395698842]: Stream rate changed
[ INFO] [1506408161.395746742]: Clearing waypoints in FCU
[ INFO] [1506408161.405771041]: WP: mission cleared
[ INFO] [1506408161.406272985]: no more wayoints in FCU
[ INFO] [1506408161.406396052]: You can arm UAV now !
[ INFO] [1506408161.476710661]: FCU armed !
[ INFO] [1506408161.477043605]: Generating waypoints
[ INFO] [1506408161.478513094]: 301 Waypoints selected out of 1802, 2 discarded and 0 outside - 604 waypoints
[ INFO] [1506408161.478597931]: Uploading Waypoints to FCU
[ INFO] [1506408162.302001454]: VER: 1.1: Capabilities         0x0000000000003bcf
[ INFO] [1506408162.302111714]: VER: 1.1: Flight software:     030502ff (4322ffda1d6bf64c1a99ba58)
[ INFO] [1506408162.302170532]: VER: 1.1: Middleware software: 00000000 (1d6bf64c1a99ba58)
[ INFO] [1506408162.302247459]: VER: 1.1: OS software:         00000000 (1a99ba58)
[ INFO] [1506408162.302672104]: VER: 1.1: Board hardware:      00000000
[ INFO] [1506408162.302730926]: VER: 1.1: VID/PID:             0000:0000
[ INFO] [1506408162.303027555]: VER: 1.1: UID:                 0000000000000000
[ WARN] [1506408162.303581682]: CMD: Unexpected command 520, result 0
[ WARN] [1506408164.236050280]: WP: timeout, retries left 2
[ WARN] [1506408166.245273127]: WP: timeout, retries left 2
[ WARN] [1506408167.250742785]: WP: timeout, retries left 2
[ WARN] [1506408169.267731891]: WP: timeout, retries left 2
[ WARN] [1506408171.281626789]: WP: timeout, retries left 2
[ INFO] [1506408171.286382909]: HP: requesting home position
[ WARN] [1506408172.295788580]: WP: timeout, retries left 2
[ WARN] [1506408173.297003202]: WP: timeout, retries left 1
[ WARN] [1506408174.297753673]: WP: timeout, retries left 0
[ERROR] [1506408175.298551316]: WP: timed out.
[ERROR] [1506408175.299768256]: Error while transfering waypoints into FCU, 15/605
[ INFO] [1506408175.320013607]: FCU armed !
[ INFO] [1506408175.320077640]: Generating waypoints
[ INFO] [1506408175.320671104]: 301 Waypoints selected out of 1802, 2 discarded and 0 outside - 604 waypoints
[ INFO] [1506408175.320705929]: Uploading Waypoints to FCU
[ WARN] [1506408176.292244952]: CMD: Unexpected command 410, result 0
[ERROR] [1506408176.292773004]: WP: upload failed: received waypoint out of sequence
[ERROR] [1506408176.293286194]: Error while transfering waypoints into FCU, 1/605
[ERROR] [1506408176.293669674]: FCU: PreArm: Check mag field
[ERROR] [1506408176.293871149]: FCU: PreArm: Throttle below Failsafe
[ INFO] [1506408176.312321737]: FCU armed !
[ INFO] [1506408176.312374136]: Generating waypoints
[ INFO] [1506408176.312969792]: 301 Waypoints selected out of 1802, 2 discarded and 0 outside - 604 waypoints
[ INFO] [1506408176.313021520]: Uploading Waypoints to FCU
[ WARN] [1506408178.311390820]: WP: timeout, retries left 2
[ WARN] [1506408180.320554139]: WP: timeout, retries left 2
[ WARN] [1506408182.331194313]: WP: timeout, retries left 2
[ WARN] [1506408184.343025752]: WP: timeout, retries left 2
[ WARN] [1506408186.354143266]: WP: timeout, retries left 2
[ WARN] [1506408188.365744648]: WP: timeout, retries left 2
[ WARN] [1506408190.375305900]: WP: timeout, retries left 2
[ WARN] [1506408192.383309896]: WP: timeout, retries left 2
[ WARN] [1506408194.392562067]: WP: timeout, retries left 2
[ WARN] [1506408195.395717942]: WP: timeout, retries left 2
[ WARN] [1506408196.399357041]: WP: timeout, retries left 2
[ WARN] [1506408198.408758806]: WP: timeout, retries left 2
[ WARN] [1506408200.417578566]: WP: timeout, retries left 2
[ WARN] [1506408201.420583377]: WP: timeout, retries left 2
[ERROR] [1506408202.430179719]: FCU: PreArm: Check mag field
[ERROR] [1506408202.430713208]: FCU: PreArm: Throttle below Failsafe
[ WARN] [1506408203.433515889]: WP: timeout, retries left 2
[ WARN] [1506408205.446941767]: WP: timeout, retries left 2
[ WARN] [1506408207.460607571]: WP: timeout, retries left 2
[ WARN] [1506408210.483591138]: WP: timeout, retries left 2
[ WARN] [1506408212.493829875]: WP: timeout, retries left 2
[ WARN] [1506408214.503042260]: WP: timeout, retries left 2
[ WARN] [1506408216.514344116]: WP: timeout, retries left 2
[ WARN] [1506408217.520617180]: WP: timeout, retries left 2
[ WARN] [1506408219.529193801]: WP: timeout, retries left 2
[ WARN] [1506408221.541069804]: WP: timeout, retries left 2
[ WARN] [1506408223.554888085]: WP: timeout, retries left 2
[ WARN] [1506408225.567910357]: WP: timeout, retries left 2
[ WARN] [1506408227.578987284]: WP: timeout, retries left 2
[ WARN] [1506408229.590855830]: WP: timeout, retries left 2
[ WARN] [1506408231.597076700]: WP: timeout, retries left 2
[ERROR] [1506408232.602056113]: FCU: PreArm: Check mag field
[ERROR] [1506408232.602358166]: FCU: PreArm: Throttle below Failsafe
[ WARN] [1506408233.606820088]: WP: timeout, retries left 2
[ WARN] [1506408234.612484658]: WP: timeout, retries left 2
[ WARN] [1506408236.619778806]: WP: timeout, retries left 2
[ WARN] [1506408238.628318912]: WP: timeout, retries left 2
[ WARN] [1506408240.640708089]: WP: timeout, retries left 2
[ WARN] [1506408242.654004946]: WP: timeout, retries left 2
[ WARN] [1506408244.668255677]: WP: timeout, retries left 2
[ WARN] [1506408246.682012628]: WP: timeout, retries left 2
[ WARN] [1506408248.692061500]: WP: timeout, retries left 2
[ WARN] [1506408249.696720821]: WP: timeout, retries left 2
[ WARN] [1506408251.705074730]: WP: timeout, retries left 2
[ WARN] [1506408253.718226850]: WP: timeout, retries left 2
[ WARN] [1506408254.723632001]: WP: timeout, retries left 2
[ WARN] [1506408256.732751811]: WP: timeout, retries left 2
[ WARN] [1506408258.742284941]: WP: timeout, retries left 2
[ WARN] [1506408260.753952770]: WP: timeout, retries left 2
[ERROR] [1506408262.770293369]: FCU: PreArm: Check mag field
[ERROR] [1506408262.770669806]: FCU: PreArm: Throttle below Failsafe
[ WARN] [1506408263.775378742]: WP: timeout, retries left 2
[ WARN] [1506408265.786942864]: WP: timeout, retries left 2
[ WARN] [1506408266.790654663]: WP: timeout, retries left 2
[ WARN] [1506408268.800653630]: WP: timeout, retries left 2
[ WARN] [1506408270.811284680]: WP: timeout, retries left 2
[ WARN] [1506408272.820767252]: WP: timeout, retries left 2
[ WARN] [1506408273.825093634]: WP: timeout, retries left 2
[ WARN] [1506408275.834499162]: WP: timeout, retries left 2
[ WARN] [1506408277.848028943]: WP: timeout, retries left 2
[ WARN] [1506408278.862781550]: WP: timeout, retries left 2
[ WARN] [1506408279.864218088]: WP: timeout, retries left 2
[ WARN] [1506408280.869577992]: WP: timeout, retries left 2
[ WARN] [1506408282.881557546]: WP: timeout, retries left 2
[ WARN] [1506408283.884572740]: WP: timeout, retries left 2
[ WARN] [1506408285.893854253]: WP: timeout, retries left 2
[ WARN] [1506408286.897797824]: WP: timeout, retries left 2
[ WARN] [1506408288.908710358]: WP: timeout, retries left 2
[ WARN] [1506408290.919733534]: WP: timeout, retries left 2
[ERROR] [1506408292.925510277]: FCU: PreArm: Check mag field
[ERROR] [1506408292.925788648]: FCU: PreArm: Throttle below Failsafe
[ WARN] [1506408293.932759163]: WP: timeout, retries left 2
[ WARN] [1506408295.944692221]: WP: timeout, retries left 2
^C[alexmos-5] killing on exit
[falcon-4] killing on exit
[visualization-3] killing on exit
[mavros-2] killing on exit
terminate called after throwing an instance of 'boost::exception_detail::clone_impl<boost::exception_detail::error_info_injector<boost::lock_error> >'
  what():  boost: mutex lock failed in pthread_mutex_lock: Invalid argument
[mavros-2] escalating to SIGTERM
[rosout-1] killing on exit
[master] killing on exit
shutting down processing monitor...
... shutting down processing monitor complete
done

Diagnostics

header: 
  seq: 22
  stamp: 
    secs: 1506408384
    nsecs: 582009705
  frame_id: ''
status: 
  - 
    level: 0
    name: mavros: FCU connection
    message: connected
    hardware_id: /dev/ttyACM0:57600
    values: 
      - 
        key: Received packets:
        value: 717
      - 
        key: Dropped packets:
        value: 0
      - 
        key: Buffer overruns:
        value: 0
      - 
        key: Parse errors:
        value: 0
      - 
        key: Rx sequence number:
        value: 63
      - 
        key: Tx sequence number:
        value: 34
      - 
        key: Rx total bytes:
        value: 21203
      - 
        key: Tx total bytes:
        value: 1280
      - 
        key: Rx speed:
        value: 201.000000
      - 
        key: Tx speed:
        value: 119.000000
  - 
    level: 0
    name: mavros: GPS
    message: 3D fix
    hardware_id: /dev/ttyACM0:57600
    values: 
      - 
        key: Satellites visible
        value: 12
      - 
        key: Fix type
        value: 4
      - 
        key: EPH (m)
        value: 0.93
      - 
        key: EPV (m)
        value: 1.26
  - 
    level: 0
    name: mavros: Heartbeat
    message: Normal
    hardware_id: /dev/ttyACM0:57600
    values: 
      - 
        key: Heartbeats since startup
        value: 10
      - 
        key: Frequency (Hz)
        value: 0.944566
      - 
        key: Vehicle type
        value: Hexarotor
      - 
        key: Autopilot type
        value: ArduPilotMega / ArduCopter
      - 
        key: Mode
        value: STABILIZE
      - 
        key: System status
        value: Standby
  - 
    level: 0
    name: mavros: System
    message: Normal
    hardware_id: /dev/ttyACM0:57600
    values: 
      - 
        key: Sensor present
        value: 0x0360FC2F
      - 
        key: Sensor enabled
        value: 0x02609C2F
      - 
        key: Sensor helth
        value: 0x0360FC2F
      - 
        key: 3D gyro
        value: Ok
      - 
        key: 3D accelerometer
        value: Ok
      - 
        key: 3D magnetometer
        value: Ok
      - 
        key: absolute pressure
        value: Ok
      - 
        key: GPS
        value: Ok
      - 
        key: 3D angular rate control
        value: Ok
      - 
        key: attitude stabilization
        value: Ok
      - 
        key: yaw position
        value: Ok
      - 
        key: motor outputs / control
        value: Ok
      - 
        key: AHRS subsystem health
        value: Ok
      - 
        key: Terrain subsystem health
        value: Ok
      - 
        key: Battery
        value: Ok
      - 
        key: CPU Load (%)
        value: 50.2
      - 
        key: Drop rate (%)
        value: 0.0
      - 
        key: Errors comm
        value: 0
      - 
        key: Errors count #1
        value: 0
      - 
        key: Errors count #2
        value: 0
      - 
        key: Errors count #3
        value: 0
      - 
        key: Errors count #4
        value: 0
  - 
    level: 0
    name: mavros: Battery
    message: Normal
    hardware_id: /dev/ttyACM0:57600
    values: 
      - 
        key: Voltage
        value: 24.95
      - 
        key: Current
        value: 0.0
      - 
        key: Remaining
        value: 99.0
---

Check ID

OK. I got messages from 1:1.

---
Received 84 messages, from 1 addresses
sys:comp   list of messages
  1:1     40, 0, 253, 22, 47
TSC21 commented 7 years ago

/dev/ttyACM0:57600 -> try to increase to baudrate to 921600. Also set SERIAL1_BAUD to 921.

gui2dev commented 7 years ago

Thanks for the answer. I just tried it, without success. And I guess it's SERIAL0_BAUD that I should change as I'm connected to my pixhawk 2 USB port ?

gui2dev commented 7 years ago

Putting waypoint plugin output level to DEBUG, I got something like this:

[DEBUG] [1506422968.584678109]: WP: send item #232  F:0 C:115 p: 135.000000 0.000000 -1.000000 0.000000 x: 0.000000 y: 0.000000 z: 0.000000
[DEBUG] [1506422968.593246869]: WP: FCU requested waypoint 232
[DEBUG] [1506422968.593594694]: WP: send item #232  F:0 C:115 p: 135.000000 0.000000
-1.000000 0.000000 x: 0.000000 y: 0.000000 z: 0.000000
[DEBUG] [1506422968.598412674]: WP: FCU requested waypoint 233
[DEBUG] [1506422968.598799423]: WP: send item #233  F:3 C: 16 p: 0.000000 0.000000 0.000000
0.000000 x: 45.051233 y: 5.800261 z: 100.000000
[DEBUG] [1506422968.604025764]: WP: Received INVALID_SEQUENCE ack
[DEBUG] [1506422969.610167177]: WP: FCU requested waypoint 234
[DEBUG] [1506422969.610542945]: WP: send item #234  F:0 C:115 p: 135.000000 0.000000
-1.000000 0.000000 x: 0.000000 y: 0.000000 z: 0.000000
[DEBUG] [1506422969.616371093]: WP: FCU requested waypoint 234
[DEBUG] [1506422969.616760118]: WP: send item #234  F:0 C:115 p: 135.000000 0.000000
-1.000000 0.000000 x: 0.000000 y: 0.000000 z: 0.000000
[DEBUG] [1506422969.621158504]: WP: FCU requested waypoint 235
[DEBUG] [1506422969.621405778]: WP: send item #235  F:3 C: 16 p: 0.000000 0.000000 0.000000
0.000000 x: 45.051282 y: 5.800336 z: 100.000000
[DEBUG] [1506422969.626836776]: WP: Received INVALID_SEQUENCE ack

So my first guess is that's transfer is somehow ok, but just very slow.

vooon commented 7 years ago

Lets calculate, 605 waypoints it is: 605 (MISSION_INTEM + MISSION_REQUEST) + MISSION_REQUEST_LIST + MISSION_COUT bytes to exchange.

605 * (38 + 10 + 5 + 10) + 3 + 10 + 5 + 10 = 38143 bytes, for 115200 you can pass about 10 kiB/sec. So transmission takes at least 3 sec. Hm that's look okay, 10x less than default timeout (30 sec).

Launch htop and look on CPU load.

vooon commented 7 years ago

Double requesting of same wp item seems invalid, check wiring.

TSC21 commented 7 years ago

115200 you can pass about 10 kiB/sec.

Is serial connection is set to 57600.

TSC21 commented 7 years ago

Thanks for the answer. I just tried it, without success. And I guess it's SERIAL0_BAUD that I should change as I'm connected to my pixhawk 2 USB port ?

Try both.

gui2dev commented 7 years ago

Actually, it does not seems to be linked with connectivity at whatever speed I have the same issue while connected to the joule, but not when connected to another machine (my laptop).

It's really as if each first try of sending WP times out. Setting WP_TIMEOUT_MS to 25 let me upload all the waypoints with only one timeout.

What I also don't understand is that the waypoint plugin seems to be not happy with my first WP (takeoff) as I got this INFO:

[ INFO] [1506423994.490924413]: WP: item #0 F:0 C: 16 p: 0.000000 0.000000 0.000000 0.000000 x: 45.051647 y: 5.801180 z: 328.070007

When my first waypoint should be a takeoff:

currentWps.clear(); [...] mavros_msgs::Waypoint wpTakeOff; wpTakeOff.frame = 3; wpTakeOff.command = 22; // MAV_CMD_NAV_TAKEOFF; wpTakeOff.param4 = 0.0; wpTakeOff.x_lat = 0.0; wpTakeOff.y_long = 0.0; wpTakeOff.z_alt = global_alt; wpTakeOff.autocontinue = true; currentWps.push_back(wpTakeOff);

TSC21 commented 7 years ago

@JMare could any of your changes have influence here?

gui2dev commented 7 years ago

The only think I added to the original package is some lines that calls a service with the waypoint sequence number on ITEM_MISSION_REACHED form the the appropriate handler

JMare commented 7 years ago

So @gui2dev first off waypoint 0 is home position so your takeoff waypoint should be in position 1.

This is curious. The handling of WP: Received INVALID_SEQUENCE ack is something that we added in #798 , but the previous behaviour was to abort the transfer in this circumstance.

And the order of the debug messages seems strange here.

@gui2dev you mention you have modified the wp plugin, can you show us the branch you are working off?

Its worth noting that parameter and waypoint transfers are surprisingly intolerant of any significant link loss. From my testing even 10% link loss makes significant transfers basically impossible.

Are you able to show us the code that is calling the WaypointPush service?

[ WARN] [1506408178.311390820]: WP: timeout, retries left 2
[ WARN] [1506408180.320554139]: WP: timeout, retries left 2
[ WARN] [1506408182.331194313]: WP: timeout, retries left 2
[ WARN] [1506408184.343025752]: WP: timeout, retries left 2
[ WARN] [1506408186.354143266]: WP: timeout, retries left 2
[ WARN] [1506408188.365744648]: WP: timeout, retries left 2
[ WARN] [1506408190.375305900]: WP: timeout, retries left 2
[ WARN] [1506408192.383309896]: WP: timeout, retries left 2
[ WARN] [1506408194.392562067]: WP: timeout, retries left 2

I don't know why this is happening but it looks bad.

@JamesStewy what do you think of this

JamesStewy commented 7 years ago

the order of the debug messages seems strange here.

@gui2dev, do the DEBUG log messages consistently follow the pattern you posted? The pattern being:

  1. send item #x
  2. FCU requested waypoint x
  3. send item #x
  4. FCU requested waypoint x+1
  5. send item #x+1
  6. Received INVALID_SEQUENCE ack
  7. Repeat with x=x+2

Its worth noting that parameter and waypoint transfers are surprisingly intolerant of any significant link loss. From my testing even 10% link loss makes significant transfers basically impossible.

I also have to echo this. We changed the waypoint module to ignore the INVALID_SEQUENCE ack to increase the fault tolerance, as, despite the retry mechanism implemented at both ends, dropping a single message could cause the waypoint transfer to fail completely. Just looking at that small snippet of debug logs suggests there are messages that are failing to be sent. If this test is run on a mavros version without our changes I would suspect the transfer would fail long before you get to the 232nd waypoint.

gui2dev commented 7 years ago

@jmare I issued a pull request -- #826 @JamesStewy the pattern is somehow the same, sometimes one waypoint is accepted without receivingINVALID_SEQUENCE ack. I first worked on a version that would not include the INVALID_SEQUENCE ignore. At that time transfer just failed after first waypoint. After updating my sources, transfer would just timeout on LIST_TIMEOUT_MS, so I started to play with the timeouts duration to allow a full transfer. Increasing LIST_TIMEOUT_MS and WP_TIMEOUT_MS would do it, but it was awfully slow (5 minutes or more) and sometimes causes an HEARTBEAT drop. Lowering WP_TIMEOUT_MS to 25 is my best option so far. As it only happens with the intel joule but not when using SITL, I am starting to think that it's somehow kernel-related and how /dev/ttyACM0 is managed but that sounds pretty odd.

JMare commented 7 years ago

@gui2dev It seems more likely to me that the issue only occurs on low powered computers, than it being specific to the joule.

If you share the code you are using to call the WaypointPush service from I could test it on a Raspberry Pi or Odroid and see if I can replicate.

gui2dev commented 7 years ago

@JMare that's the other option. You can get the code here: https://github.com/gui2dev/mavros

lamping7 commented 7 years ago

Just to share my experience, our team had no issues when we used the Joule in the past with:

We were using a Pixhawk 2.1 connected via UART on the GPIO @ 921600 baud. We didn't push nearly as many WPs though.

gui2dev commented 7 years ago

@lamping7 Did you use pullups?

lamping7 commented 7 years ago

Did you used pullups?

@gui2dev I'm not sure what you're asking. I used pins 22/24 for TX/RX and pin 36 for GND.

gui2dev commented 7 years ago

@lamping7 GPIO levels are at 1.8V right? Or maybe you were not using the dev board.

lamping7 commented 7 years ago

@gui2dev From my understanding, the Joule itself is 1.8v, but the dev kit expansion board is 3.3v. We didn't use a level shifter, like one you'd use for the ODROID XU4, for example. We have the dev kit, if that wasn't clear.

EDIT: Yup. See -> https://communities.intel.com/thread/111850

gui2dev commented 7 years ago

@lamping7, so we have a similar use of the joule + dev kit except you're using serial while I'm using usb. We are using gpio 55 (j13 15) for trigging purposes and high level is definitely 1.8V. Maybe 22/24 is 3.3V.

lamping7 commented 7 years ago

@gui2dev Checkout the Intel post above. We didn't use any of the other GPIO, but again, we had no communication issues the way we had it setup once we figured out how to do it. You need the Ubuntu flavor packed with the Joule specific kernel in order to use the UART on /dev/ttyS1 for the pins I listed previously.

Another, but unrelated, issue that we found was that using a USB type C hub (we tried two different manufacturers) connected to the Joule introduced odd EMI to the system, causing GPS signal loss and compass errors.

gui2dev commented 7 years ago

@lamping7 Thanks for the link. I relied on an intel reference for GPIO Signal Termination and Conditioning We are using the type A with a usb hub and we did not observe EMI issues (pixhawk 2.1).

gui2dev commented 7 years ago

@lamping7 I am also running a joule flavored kernel (latest I guess) along with latest bios.

lamping7 commented 7 years ago

@gui2dev No problem. The Joule is known for terrible documentation. I'd see if your problem exists with that hardware interface. Should be a quick test if you have the correct software, which you say you do. Good luck.

Also, we switched to the type A and had no issues with interference.

gui2dev commented 7 years ago

@lamping7 allright. By any chance did you had any connectivity issue when using usb connection to pixhawk ?

lamping7 commented 7 years ago

@gui2dev We used a USB FTDI serial converter connected from the Joule USB A port to the telem2 on the Pixhawk at first and had no issues @ 921600 baud.

TSC21 commented 7 years ago

@gui2dev is this solved to you already?

gui2dev commented 7 years ago

sorry @TSC21 I've been too busy to make tests again. It really looks as if it's power related, I'll confirm asap, but feel free to close the issue if I'm taking too long.

TSC21 commented 7 years ago

We can wait some days. We just usually don't like to keep the bug tracking stalled for long (except with feature requests).

TSC21 commented 6 years ago

@gui2dev I'm closing this as stale. Let us know if this still persists.