px4_raspberrypi 1.11.0 with Navio2 - trace level info in the logs and QGroundControl warning flashes

[blazczak]

Describe the bug A lot of small (debug) crud in the log and QGC warning flashes

To Reproduce Steps to reproduce the behavior: Build 1.11.0 PX4 on Ubuntu 20, use instructions in https://community.emlid.com/t/navio2-support-for-ubuntu-20-04/19956 to create the spidev stuff if needed. Perform activity with the drone, like calibration, arming, etc. See lots of extraneous messages in the logs and in the QGC warning flashes (the more annoying part) - possibly in-flight debug logging that was not cleaned up.

Expected behavior Level of log sanitation seen in 1.10.1 for navio2 and fmu-v5

Log Files and Screenshots

mpu9250 #0 on SPI bus 0 (devid=0x1)
lsm9ds1 #0 on SPI bus 0 (devid=0x3)
lsm9ds1_mag #0 on SPI bus 0 (devid=0x2)
ms5611 #0 on I2C bus 1 (external, equal to '-b 1')
INFO  [px4] assuming working directory is rootfs, no symlinks needed.

______  __   __    ___ 
| ___ \ \ \ / /   /   |
| |_/ /  \ V /   / /| |
|  __/   /   \  / /_| |
| |     / /^\ \ \___  |
\_|     \/   \/     |_/

px4 starting.

INFO  [px4] Calling startup script: /bin/sh posix-configs/rpi/px4.config 0
INFO  [dataman] Unknown restart, data manager file './dataman' size is 11798680 bytes
INFO  [commander] LED: open /dev/led0 failed (22)
INFO  [mavlink] mode: Normal, data rate: 1000000 B/s on udp port 14556 remote port 14550
INFO  [linux_pwm_out] Loaded mixer from file ROMFS/px4fmu_common/mixers/quad_x.main.mix
INFO  [linux_pwm_out] Starting PWM output in Navio mode
INFO  [logger] logger started (mode=all)
INFO  [px4] Startup script returned successfully
INFO  [mavlink] using network interface wlan0, IP: 10.0.0.2
INFO  [mavlink] with netmask: 255.255.255.0
INFO  [mavlink] and broadcast IP: 10.0.0.255
INFO  [ekf2] Mag sensor ID changed to 4522498
INFO  [mavlink] partner IP: 10.0.0.24
INFO  [ecl/EKF] 1190242003: reset position to last known position
INFO  [ecl/EKF] 1190242003: reset velocity to zero
INFO  [ecl/EKF] 1197222218: EKF aligned, (baro hgt, IMU buf: 18, OBS buf: 14)
INFO  [commander] [cal] calibration started: 2 accel
INFO  [commander] [cal] pending: back front left right up down
INFO  [commander] [cal] hold vehicle still on a pending side
INFO  [commander] [cal] detected rest position, hold still...
INFO  [commander] [cal] down orientation detected
INFO  [commander] [cal] down orientation detected
INFO  [commander] [cal] Hold still, measuring down side
INFO  [commander] [cal] down side result: [  0.1153  -0.0607  -9.5143]
INFO  [commander] [cal] progress <17>
INFO  [commander] [cal] down side done, rotate to a different side
INFO  [commander] [cal] down side done, rotate to a different side
INFO  [commander] [cal] pending: back front left right up
INFO  [commander] [cal] hold vehicle still on a pending side
INFO  [commander] [cal] detected rest position, hold still...
INFO  [commander] [cal] detected motion, hold still...
INFO  [commander] [cal] detected rest position, hold still...
INFO  [commander] [cal] left orientation detected
INFO  [commander] [cal] left orientation detected
INFO  [commander] [cal] Hold still, measuring left side
INFO  [commander] [cal] left side result: [ -0.7990   9.7712   0.5110]
INFO  [commander] [cal] progress <34>
INFO  [commander] [cal] left side done, rotate to a different side
INFO  [commander] [cal] left side done, rotate to a different side
INFO  [commander] [cal] pending: back front right up
INFO  [commander] [cal] hold vehicle still on a pending side
INFO  [commander] [cal] detected rest position, hold still...
INFO  [commander] [cal] back orientation detected
INFO  [commander] [cal] back orientation detected
INFO  [commander] [cal] Hold still, measuring back side
INFO  [commander] [cal] back side result: [  9.8681   0.6664  -0.6171]
INFO  [commander] [cal] progress <51>
INFO  [commander] [cal] back side done, rotate to a different side
INFO  [commander] [cal] back side done, rotate to a different side
INFO  [commander] [cal] pending: front right up
INFO  [commander] [cal] hold vehicle still on a pending side
INFO  [commander] [cal] detected rest position, hold still...
INFO  [commander] [cal] front orientation detected
INFO  [commander] [cal] front orientation detected
INFO  [commander] [cal] Hold still, measuring front side
INFO  [commander] [cal] front side result: [ -9.6814   0.3965  -0.2469]
INFO  [commander] [cal] progress <68>
INFO  [commander] [cal] front side done, rotate to a different side
INFO  [commander] [cal] front side done, rotate to a different side
INFO  [commander] [cal] pending: right up
INFO  [commander] [cal] hold vehicle still on a pending side
INFO  [commander] [cal] detected rest position, hold still...
INFO  [commander] [cal] right orientation detected
INFO  [commander] [cal] right orientation detected
INFO  [commander] [cal] Hold still, measuring right side
INFO  [commander] [cal] right side result: [ -0.7393  -9.7922   0.2114]
INFO  [commander] [cal] progress <85>
INFO  [commander] [cal] right side done, rotate to a different side
INFO  [commander] [cal] right side done, rotate to a different side
INFO  [commander] [cal] pending: up
INFO  [commander] [cal] hold vehicle still on a pending side
INFO  [commander] [cal] detected rest position, hold still...
INFO  [commander] [cal] up orientation detected
INFO  [commander] [cal] up orientation detected
INFO  [commander] [cal] Hold still, measuring up side
INFO  [commander] [cal] up side result: [  0.1020  -0.1524  10.2787]
INFO  [commander] [cal] progress <102>
INFO  [commander] [cal] up side done, rotate to a different side
INFO  [commander] [cal] up side done, rotate to a different side
INFO  [commander] found offset 0: x: 0.093316, y: -0.010503, z: 0.382225
INFO  [commander] found scale 0: x: 0.997009, y: 0.996204, z: 0.990778
INFO  [commander] found offset 1: x: 0.089966, y: 0.053685, z: 0.051628
INFO  [commander] found scale 1: x: 1.003711, y: 0.999259, z: 1.000338
INFO  [commander] [cal] calibration done: accel
INFO  [commander] [cal] calibration started: 2 gyro
INFO  [commander] [cal] progress <4>
INFO  [commander] [cal] progress <9>
INFO  [commander] [cal] progress <14>
INFO  [commander] [cal] progress <19>
INFO  [commander] [cal] progress <24>
INFO  [commander] [cal] progress <28>
INFO  [commander] [cal] progress <33>
INFO  [commander] [cal] progress <38>
INFO  [commander] [cal] progress <43>
INFO  [commander] [cal] progress <48>
INFO  [commander] [cal] progress <52>
INFO  [commander] [cal] progress <57>
INFO  [commander] [cal] progress <62>
INFO  [commander] [cal] progress <67>
INFO  [commander] [cal] progress <72>
INFO  [commander] [cal] progress <76>
INFO  [commander] [cal] progress <81>
INFO  [commander] [cal] progress <86>
INFO  [commander] [cal] progress <91>
INFO  [commander] [cal] progress <96>
INFO  [commander] [cal] calibration done: gyro
INFO  [commander] [cal] calibration started: 2 level
INFO  [commander] [cal] progress <0>
INFO  [commander] [cal] progress <20>
INFO  [commander] [cal] progress <40>
INFO  [commander] [cal] progress <60>
INFO  [commander] [cal] progress <80>
INFO  [commander] [cal] progress <100>
INFO  [commander] [cal] progress <100>
INFO  [commander] [cal] calibration done: level
ERROR [sensors] Accel #0 fail:  TIMEOUT!
INFO  [commander] [cal] calibration started: 2 mag
INFO  [commander] [cal] pending: back front left right up down
INFO  [commander] [cal] hold vehicle still on a pending side
INFO  [commander] [cal] detected rest position, hold still...
INFO  [commander] [cal] down orientation detected
INFO  [commander] [cal] down orientation detected
INFO  [commander] [cal] Rotate vehicle around the detected orientation
INFO  [commander] [cal] Continue rotation for down 7 s
ERROR [sensors] Accel #1 fail:  TIMEOUT!
INFO  [commander] [cal] down side calibration: progress <4>
INFO  [commander] [cal] down side done, rotate to a different side
INFO  [commander] [cal] progress <16>
INFO  [commander] [cal] down side done, rotate to a different side
INFO  [commander] [cal] down side done, rotate to a different side
INFO  [commander] [cal] pending: back front left right up
INFO  [commander] [cal] hold vehicle still on a pending side
INFO  [commander] [cal] detected rest position, hold still...
INFO  [commander] [cal] up orientation detected
INFO  [commander] [cal] up orientation detected
INFO  [commander] [cal] Rotate vehicle around the detected orientation
INFO  [commander] [cal] Continue rotation for up 7 s
INFO  [commander] [cal] up side calibration: progress <16>
INFO  [commander] [cal] up side calibration: progress <20>
INFO  [commander] [cal] up side calibration: progress <24>
INFO  [commander] [cal] up side done, rotate to a different side
INFO  [commander] [cal] progress <33>
INFO  [commander] [cal] up side done, rotate to a different side
INFO  [commander] [cal] up side done, rotate to a different side
INFO  [commander] [cal] pending: back front left right
INFO  [commander] [cal] hold vehicle still on a pending side
INFO  [commander] [cal] detected rest position, hold still...
INFO  [commander] [cal] front orientation detected
INFO  [commander] [cal] front orientation detected
INFO  [commander] [cal] Rotate vehicle around the detected orientation
INFO  [commander] [cal] Continue rotation for front 7 s
INFO  [commander] [cal] front side calibration: progress <33>
INFO  [commander] [cal] front side calibration: progress <37>
INFO  [commander] [cal] front side done, rotate to a different side
INFO  [commander] [cal] progress <50>
INFO  [commander] [cal] front side done, rotate to a different side
INFO  [commander] [cal] front side done, rotate to a different side
INFO  [commander] [cal] pending: back left right
INFO  [commander] [cal] hold vehicle still on a pending side
INFO  [commander] [cal] detected rest position, hold still...
INFO  [commander] [cal] back orientation detected
INFO  [commander] [cal] back orientation detected
INFO  [commander] [cal] Rotate vehicle around the detected orientation
INFO  [commander] [cal] Continue rotation for back 7 s
INFO  [commander] [cal] back side calibration: progress <50>
INFO  [commander] [cal] back side calibration: progress <54>
INFO  [commander] [cal] back side calibration: progress <58>
INFO  [commander] [cal] back side done, rotate to a different side
INFO  [commander] [cal] progress <66>
INFO  [commander] [cal] back side done, rotate to a different side
INFO  [commander] [cal] back side done, rotate to a different side
INFO  [commander] [cal] pending: left right
INFO  [commander] [cal] hold vehicle still on a pending side
INFO  [commander] [cal] detected rest position, hold still...
INFO  [commander] [cal] right orientation detected
INFO  [commander] [cal] right orientation detected
INFO  [commander] [cal] Rotate vehicle around the detected orientation
INFO  [commander] [cal] Continue rotation for right 7 s
INFO  [commander] [cal] right side calibration: progress <66>
INFO  [commander] [cal] right side calibration: progress <70>
INFO  [commander] [cal] right side done, rotate to a different side
INFO  [commander] [cal] progress <83>
INFO  [commander] [cal] right side done, rotate to a different side
INFO  [commander] [cal] right side done, rotate to a different side
INFO  [commander] [cal] pending: left
INFO  [commander] [cal] hold vehicle still on a pending side
INFO  [commander] [cal] detected rest position, hold still...
INFO  [commander] [cal] left orientation detected
INFO  [commander] [cal] left orientation detected
INFO  [commander] [cal] Rotate vehicle around the detected orientation
INFO  [commander] [cal] Continue rotation for left 7 s
INFO  [commander] [cal] left side calibration: progress <83>
INFO  [commander] [cal] left side calibration: progress <87>
INFO  [commander] [cal] left side calibration: progress <91>
INFO  [commander] [cal] left side done, rotate to a different side
INFO  [commander] [cal] progress <100>
INFO  [commander] [cal] left side done, rotate to a different side
INFO  [commander] [cal] left side done, rotate to a different side
INFO  [commander] [cal] mag #0 off: x:0.06 y:-0.05 z:-0.05 Ga
INFO  [commander] [cal] mag #0 scale: x:0.98 y:1.01 z:1.02
INFO  [commander] [cal] progress <100>
INFO  [commander] [cal] calibration done: mag
ERROR [sensors] Accel #0 fail:  TIMEOUT!
WARN  [commander] REJECT AUTO MISSION
WARN  [commander] REJECT AUTO RTL
WARN  [commander] REJECT POSITION CONTROL
WARN  [commander] REJECT AUTO MISSION
WARN  [commander] REJECT AUTO MISSION
ERROR [sensors] Accel #0 fail:  TIMEOUT!
WARN  [commander] REJECT OFFBOARD
WARN  [commander] REJECT POSITION CONTROL
WARN  [commander] REJECT AUTO MISSION
WARN  [commander] REJECT POSITION CONTROL
ERROR [sensors] Accel #0 fail:  TIMEOUT!
ERROR [sensors] Accel #0 fail:  TIMEOUT!
WARN  [commander] Connection to ground station lost
WARN  [PreFlightCheck] Preflight: GPS Horizontal Pos Error too high
INFO  [commander] Data link regained
WARN  [PreFlightCheck] Preflight Fail: no valid data from Accel #1
WARN  [PreFlightCheck] Preflight Fail: no valid data from Gyro #1
WARN  [PreFlightCheck] Preflight: GPS Horizontal Pos Error too high
INFO  [logger] Start file log (type: full)
INFO  [logger] [logger] ./log/2020-10-20/04_42_29.ulg
INFO  [logger] Opened full log file: ./log/2020-10-20/04_42_29.ulg
INFO  [logger] Start mavlink log
INFO  [commander] Disarmed by auto preflight disarming
ERROR [logger] Ack timeout. Stopping mavlink log
INFO  [logger] closed logfile, bytes written: 180414
INFO  [logger] Stop mavlink log

PX4 Exiting...
Exiting NOW.

Drone Quadcopter, DJI F450 airframe with DJI motors/ESCs Navio2 on Ubuntu 20

[dagar]

If you just let it run without calibration do the accels continue working with no timeout? You can check with listener sensor_accel or sensors status. What's the cpu load like with px4 running?

[blazczak]

Still present in v1.11.1 and master.

@dagar Yes, I just let it sit there and got "ERROR [sensors] Accel #0 fail: TIMEOUT!" out of the blue. Restarted, got the same error again.

In terms of cpu load, it's comparable to the load v1.10.1 generates and that deployment works and flies. It's the same clean Ubuntu 20 install, same uSD card, v1.10.1 and v1.11.1 checked out side-by-side, nothing else running on that instance - no offboard processes anything like that that would cause delays in sensor processing.

[dagar]

I've only ever used the navio2 will the raspbian build from Emlid. With Ubuntu 20.04 are you using PREEMPT_RT? Are you running px4 as root?

[blazczak]

When either 1.10.1 or 1.11.1 was selected it was run as root. No PREEMPT_RT, no ROS, just good ol' arm Ubuntu 20.04 LTS from https://ubuntu.com/download/raspberry-pi.

PX4 1.10.1 flies lively and issue-free in the same environment and on the same hardware: https://logs.px4.io/plot_app?log=4523b1b6-a0eb-41f1-9216-5c23d129a96b

[dagar]

One notable difference for Navio2 since v1.11 is the switch to the unified drivers that are shared across Nuttx, Linux, Qurt. This applies to the mpu9250, lsm9ds1, ms5611, etc. In the case of the IMU drivers they actually transfer significantly more data now using the FIFOs (8 kHz vs 1 kHz). I'm wondering if that combined with no real time threads could be the problem.

What do you see in uorb top? While px4 is running can you share the output of top or htop (set to show all threads within px4)? Then try stopping one of the lsm9ds1 or mpu9250.

[blazczak]

Posted in #16006