search

PX4 / PX4-Autopilot

PX4 Autopilot Software
https://px4.io
BSD 3-Clause "New" or "Revised" License
8.5k stars 13.51k forks source link

System wide replay broken in master #12006

Closed mhkabir closed 5 years ago

mhkabir commented 5 years ago

Describe the bug General system wide replay, is broken on master (and likely v1.9). EKF2 replay works fine.

To Reproduce Steps to reproduce the behavior:

  1. Follow instructions for system-wide replay (not EKF2 replay) here : https://dev.px4.io/master/en/debug/system_wide_replay.html
  2. Set logfile path export replay=~/<path>/41b1370f-0007-4537-b245-2fe3344e4f69.ulg
  3. Run make px4_sitl_default jmavsim

Log Files and Screenshots

[0/1] cd /Users/kabir/Development/PX4/Firmware/build/px4_sitl_default_replay/tmp && /Users/kabir/Development/PX4/Firmware/Tools/sitl_run.sh /Users/kabir/Development/PX4/Firmware/build/px4_sitl_default_replay/bin/px4 none jmavsim none /Users/kabir/Development/PX4/Firmware /Users/kabir/Development/PX4/Firmware/build/px4_sitl_default_replay
SITL ARGS
sitl_bin: /Users/kabir/Development/PX4/Firmware/build/px4_sitl_default_replay/bin/px4
debugger: none
program: jmavsim
model: none
src_path: /Users/kabir/Development/PX4/Firmware
build_path: /Users/kabir/Development/PX4/Firmware/build/px4_sitl_default_replay
empty model, setting iris as default
SITL COMMAND: "/Users/kabir/Development/PX4/Firmware/build/px4_sitl_default_replay/bin/px4" "/Users/kabir/Development/PX4/Firmware"/ROMFS/px4fmu_common -s etc/init.d-posix/rcS -t "/Users/kabir/Development/PX4/Firmware"/test_data
INFO  [uorb] Using orb rules from ./orb_publisher.rules
+ SYS_AUTOSTART: curr: 50001 -> new: 10016
+ BAT_N_CELLS: curr: 8 -> new: 3
+ CAL_ACC0_ID: curr: 0 -> new: 1376264
+ CAL_ACC1_ID: curr: 0 -> new: 1310728
+ CAL_ACC_PRIME: curr: 6488106 -> new: 1376264
+ CAL_GYRO0_ID: curr: 0 -> new: 2293768
+ CAL_GYRO_PRIME: curr: 6553642 -> new: 2293768
+ CAL_MAG0_ID: curr: 466977 -> new: 196616
+ CAL_MAG_PRIME: curr: 466977 -> new: 196616
+ COM_DISARM_LAND: curr: -1.0000 -> new: 0.1000
+ COM_OBL_ACT: curr: 0 -> new: 2
+ COM_OF_LOSS_T: curr: 0.0000 -> new: 5.0000
+ COM_RC_IN_MODE: curr: 0 -> new: 1
+ EKF2_AID_MASK: curr: 24 -> new: 1
+ EKF2_HGT_MODE: curr: 3 -> new: 0
+ EKF2_GBIAS_INIT: curr: 0.1000 -> new: 0.0100
+ MIS_TAKEOFF_ALT: curr: 0.0100 -> new: 2.5000
+ NAV_DLL_ACT: curr: 0 -> new: 2
+ RTL_DESCEND_ALT: curr: 30.0000 -> new: 5.0000
+ RTL_LAND_DELAY: curr: -1.0000 -> new: 5.0000
+ RTL_RETURN_ALT: curr: 60.0000 -> new: 30.0000
+ SDLOG_MODE: curr: 2 -> new: 1
+ SDLOG_DIRS_MAX: curr: 0 -> new: 7
+ SENS_BOARD_X_OFF: curr: -1.4278 -> new: 0.0000
+ SENS_DPRES_OFF: curr: 0.0000 -> new: 0.0010
+ SYS_RESTART_TYPE: curr: 0 -> new: 2
* RTL_DESCEND_ALT: curr: 5.0000 -> new: 10.0000
* RTL_LAND_DELAY: curr: 5.0000 -> new: 0.0000
+ PWM_MAX: curr: 1800 -> new: 1950
+ PWM_MIN: curr: 1200 -> new: 1075
INFO  [replay] using replay log file: /Users/kabir/Development/Driverless/EKFtuning/log_7_2019-5-10-17-48-16.ulg
INFO  [replay] Applying params from ULog file...
Buildfile: /Users/kabir/Development/PX4/Firmware/Tools/jMAVSim/build.xml

make_dirs:

compile:

create_run_jar:

copy_res:

BUILD SUCCESSFUL
Total time: 0 seconds
Options parsed, starting Sim.
Starting GUI...
Init MAVLink
+ MAV_TYPE: curr: 10 -> new: 2
INFO  [init] Mixer: etc/mixers/quad_w.main.mix on /dev/pwm_output0
INFO  [mavlink] MAVLink only on localhost (set param MAV_BROADCAST = 1 to enable network)
INFO  [px4] Creating symlink /Users/kabir/Development/PX4/Firmware/ROMFS/px4fmu_common -> /Users/kabir/Development/PX4/Firmware/build/px4_sitl_default_replay/tmp/rootfs/etc

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

px4 starting.

INFO  [px4] Calling startup script: /bin/sh etc/init.d-posix/rcS 0
INFO  [dataman] Unknown restart, data manager file './dataman' size is 11798680 bytes
INFO  [simulator] Waiting for simulator to connect on TCP port 4560
INFO  [simulator] Simulator connected on TCP port 4560.
INFO  [mavlink] mode: Normal, data rate: 4000000 B/s on udp port 14570 remote port 14550
INFO  [mavlink] mode: Onboard, data rate: 4000000 B/s on udp port 14580 remote port 14540
INFO  [logger] logger started (mode=all)
INFO  [logger] Start file log (type: full)
INFO  [logger] Opened full log file: ./log/2019-05-13/00_31_38_replayed.ulg
INFO  [replay] Applying params from ULog file...
INFO  [px4] Startup script returned successfully
INFO  [replay] Replay in progress...
WARN  pxh> [replay] Formats for vehicle_status don't match. Will ignore it.
WARN  [replay]  Internal format: uint64_t timestamp;uint32_t onboard_control_sensors_present;uint32_t onboard_control_sensors_enabled;uint32_t onboard_control_sensors_health;float arspd_check_level;float load_factor_ratio;uint8_t nav_state;uint8_t arming_state;uint8_t hil_state;bool failsafe;uint8_t system_type;uint8_t system_id;uint8_t component_id;bool is_rotary_wing;bool is_vtol;bool vtol_fw_permanent_stab;bool in_transition_mode;bool in_transition_to_fw;bool rc_signal_lost;uint8_t rc_input_mode;bool data_link_lost;uint8_t data_link_lost_counter;bool high_latency_data_link_lost;bool engine_failure;bool mission_failure;uint8_t failure_detector_status;bool aspd_check_failing;bool aspd_fault_declared;bool aspd_use_inhibit;bool aspd_fail_rtl;uint8_t[4] _padding0;
WARN  [replay]  File format    : uint64_t timestamp;uint32_t onboard_control_sensors_present;uint32_t onboard_control_sensors_enabled;uint32_t onboard_control_sensors_health;uint8_t nav_state;uint8_t arming_state;uint8_t hil_state;bool failsafe;uint8_t system_type;uint8_t system_id;uint8_t component_id;bool is_rotary_wing;bool is_vtol;bool vtol_fw_permanent_stab;bool in_transition_mode;bool in_transition_to_fw;bool rc_signal_lost;uint8_t rc_input_mode;bool data_link_lost;uint8_t data_link_lost_counter;bool high_latency_data_link_lost;bool engine_failure;bool mission_failure;uint8_t failure_detector_status;
WARN  [replay] Formats for vehicle_status_flags don't match. Will ignore it.
WARN  [replay]  Internal format: uint64_t timestamp;bool condition_calibration_enabled;bool condition_system_sensors_initialized;bool condition_system_hotplug_timeout;bool condition_system_returned_to_home;bool condition_auto_mission_available;bool condition_global_position_valid;bool condition_home_position_valid;bool condition_local_position_valid;bool condition_local_velocity_valid;bool condition_local_altitude_valid;bool condition_power_input_valid;bool condition_battery_healthy;bool circuit_breaker_engaged_power_check;bool circuit_breaker_engaged_airspd_check;bool circuit_breaker_engaged_enginefailure_check;bool circuit_breaker_engaged_gpsfailure_check;bool circuit_breaker_flight_termination_disabled;bool circuit_breaker_engaged_usb_check;bool circuit_breaker_engaged_posfailure_check;bool offboard_control_signal_found_once;bool offboard_control_signal_lost;bool offboard_control_set_by_command;bool offboard_control_loss_timeout;bool rc_signal_found_once;bool rc_input_blocked;bool rc_calibration_valid;bool vtol_transition_failure;bool usb_connected;bool avoidance_system_required;bool avoidance_system_valid;uint8_t[2] _padding0;
WARN  [replay]  File format    : uint64_t timestamp;bool condition_calibration_enabled;bool condition_system_sensors_initialized;bool condition_system_hotplug_timeout;bool condition_system_returned_to_home;bool condition_auto_mission_available;bool condition_global_position_valid;bool condition_home_position_valid;bool condition_local_position_valid;bool condition_local_velocity_valid;bool condition_local_altitude_valid;bool condition_power_input_valid;bool condition_battery_healthy;bool circuit_breaker_engaged_power_check;bool circuit_breaker_engaged_airspd_check;bool circuit_breaker_engaged_enginefailure_check;bool circuit_breaker_engaged_gpsfailure_check;bool circuit_breaker_flight_termination_disabled;bool circuit_breaker_engaged_usb_check;bool circuit_breaker_engaged_posfailure_check;bool offboard_control_signal_found_once;bool offboard_control_signal_lost;bool offboard_control_set_by_command;bool offboard_control_loss_timeout;bool rc_signal_found_once;bool rc_input_blocked;bool rc_calibration_valid;bool vtol_transition_failure;bool usb_connected;uint8_t[4] _padding0;
WARN  [replay] Topic vehicle_body_state not found internally. Will ignore it
WARN  [replay] Topic vehicle_ackermann_setpoint not found internally. Will ignore it
WARN  [replay] Topic wheel_odometry not found internally. Will ignore it
ERROR [sensors] Gyro #0 fail:  STALE!
ERROR [sensors] Sensor Gyro #0 failed. Reconfiguring sensor priorities.
WARN  [sensors] Remaining sensors after failover event 0: Gyro #0 priority: 1
ERROR [sensors] Accel #0 fail:  STALE!
ERROR [sensors] Sensor Accel #0 failed. Reconfiguring sensor priorities.
WARN  [sensors] Remaining sensors after failover event 0: Accel #0 priority: 1
WARN  [sensors] Remaining sensors after failover event 0: Accel #1 priority: 75
WARN  [ekf2] accel id changed, resetting IMU bias
ERROR [sensors] Accel #1 fail:  STALE!
ERROR [sensors] Sensor Accel #1 failed. Reconfiguring sensor priorities.
WARN  [sensors] Remaining sensors after failover event 1: Accel #0 priority: 1
WARN  [sensors] Remaining sensors after failover event 1: Accel #1 priority: 1
WARN  [ekf2] accel id changed, resetting IMU bias
ERROR [sensors] Baro #0 fail:  STALE!
ERROR [sensors] Sensor Baro #0 failed. Reconfiguring sensor priorities.
WARN  [sensors] Remaining sensors after failover event 0: Baro #0 priority: 1
ERROR [sensors] Accel #0 fail:  STALE!
ERROR [sensors] Sensor Accel #0 failed. Reconfiguring sensor priorities.
WARN  [sensors] Remaining sensors after failover event 0: Accel #0 priority: 1
WARN  [sensors] Remaining sensors after failover event 0: Accel #1 priority: 1
ERROR [sensors] Accel #0 fail:  STALE!
ERROR [sensors] Sensor Accel #0 failed. Reconfiguring sensor priorities.
WARN  [sensors] Remaining sensors after failover event 0: Accel #0 priority: 1
WARN  [sensors] Remaining sensors after failover event 0: Accel #1 priority: 1
ERROR [sensors] Accel #0 fail:  STALE!
ERROR [sensors] Sensor Accel #0 failed. Reconfiguring sensor priorities.
WARN  [sensors] Remaining sensors after failover event 0: Accel #0 priority: 1
WARN  [sensors] Remaining sensors after failover event 0: Accel #1 priority: 1
INFO  [ekf2] Mag sensor ID changed to 196616
ERROR [sensors] Accel #0 fail:  STALE!
ERROR [sensors] Sensor Accel #0 failed. Reconfiguring sensor priorities.
WARN  [sensors] Remaining sensors after failover event 0: Accel #0 priority: 1
WARN  [sensors] Remaining sensors after failover event 0: Accel #1 priority: 1
ERROR [sensors] Accel #0 fail:  STALE!
ERROR [sensors] Sensor Accel #0 failed. Reconfiguring sensor priorities.
WARN  [sensors] Remaining sensors after failover event 0: Accel #0 priority: 1
WARN  [sensors] Remaining sensors after failover event 0: Accel #1 priority: 1
ERROR [sensors] Accel #0 fail:  STALE!
ERROR [sensors] Sensor Accel #0 failed. Reconfiguring sensor priorities.
WARN  [sensors] Remaining sensors after failover event 0: Accel #0 priority: 1
WARN  [sensors] Remaining sensors after failover event 0: Accel #1 priority: 1
ERROR [sensors] Accel #0 fail:  STALE!
ERROR [sensors] Sensor Accel #0 failed. Reconfiguring sensor priorities.
WARN  [sensors] Remaining sensors after failover event 0: Accel #0 priority: 1
WARN  [sensors] Remaining sensors after failover event 0: Accel #1 priority: 1
ERROR [sensors] Accel #0 fail:  STALE!
ERROR [sensors] Sensor Accel #0 failed. Reconfiguring sensor priorities.
WARN  [sensors] Remaining sensors after failover event 0: Accel #0 priority: 1
WARN  [sensors] Remaining sensors after failover event 0: Accel #1 priority: 1
ERROR [sensors] Accel #0 fail:  STALE!
ERROR [sensors] Sensor Accel #0 failed. Reconfiguring sensor priorities.
WARN  [sensors] Remaining sensors after failover event 0: Accel #0 priority: 1
WARN  [sensors] Remaining sensors after failover event 0: Accel #1 priority: 1

floating point exception
INFO  [log] Backtrace: 3
INFO  [log] 0   px4                                 0x00000001084b6bfc px4_backtrace + 44
INFO  [log] 1   ???                                 0x0000000000000019 0x0 + 25
INFO  [log] 2   ???                                 0x0000700009cc28e8 0x0 + 123145466685672

floating point exception
INFO  [log] Backtrace: 3
INFO  [log] 0   px4                                 0x00000001084b6bfc px4_backtrace + 44
INFO  [log] 1   ???                                 0x0000000000000019 0x0 + 25
INFO  [log] 2   ???                                 0x0000700009cc28e8 0x0 + 123145466685672

...
julianoes commented 5 years ago

Presumably this happens because lockstep is enabled. However, that's confusing because lockstep should not be enabled for replay: https://github.com/PX4/Firmware/blob/77097b6adc70afbe7e5d8ff9797ed3413e96dbf6/boards/px4/sitl/default.cmake#L102

julianoes commented 5 years ago

@mhkabir I assume it would work if you do make clean and then try again. I see how that's a bit unfortunate.

mhkabir commented 5 years ago

@julianoes Nope - it wasn't built with lockstep before. Same issue even after a clean build, and buildsystem claims "Building without lockstep for replay".

Kabirs-MBP:Firmware kabir$ make clean
Kabirs-MBP:Firmware kabir$ make px4_sitl_default jmavsim
-- PX4 config file: /Users/kabir/Development/PX4/Firmware/boards/px4/sitl/default.cmake
Building with uorb publisher rules support
Building without lockstep for replay
-- PX4 config: px4_sitl_default
-- PX4 platform: posix
-- PX4 lockstep: disabled
-- PX4 version: v1.9.0-rc1-59-g2e94b60117
-- cmake build type: RelWithDebInfo
-- The CXX compiler identification is AppleClang 10.0.0.10001145
-- The C compiler identification is AppleClang 10.0.0.10001145
-- The ASM compiler identification is AppleClang
-- Found assembler: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/cc
-- Check for working CXX compiler: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/c++
-- Check for working CXX compiler: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/c++ -- works
-- Detecting CXX compiler ABI info
-- Detecting CXX compiler ABI info - done
-- Detecting CXX compile features
-- Detecting CXX compile features - done
-- Check for working C compiler: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/cc
-- Check for working C compiler: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/cc -- works
-- Detecting C compiler ABI info
-- Detecting C compiler ABI info - done
-- Detecting C compile features
-- Detecting C compile features - done
-- Found PythonInterp: /usr/local/bin/python (found version "2.7.16") 
-- Found PY_jinja2: /usr/local/lib/python2.7/site-packages/jinja2  
-- PX4 ECL: Very lightweight Estimation & Control Library v0.9.0-680-g278f163
-- Configuring done
-- Generating done
-- Build files have been written to: /Users/kabir/Development/PX4/Firmware/build/px4_sitl_default_replay
[9/715] git submodule src/lib/ecl
[19/715] git submodule Tools/jMAVSim
[22/715] git submodule src/drivers/gps/devices
[23/715] git submodule mavlink/include/mavlink/v2.0
[665/715] Linking CXX static library src/drivers/camera_trigger/libdrivers__camera_trigger.a
/Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/ranlib: file: src/drivers/camera_trigger/libdrivers__camera_trigger.a(pwm.cpp.o) has no symbols
/Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/ranlib: file: src/drivers/camera_trigger/libdrivers__camera_trigger.a(seagull_map2.cpp.o) has no symbols
/Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/ranlib: file: src/drivers/camera_trigger/libdrivers__camera_trigger.a(gpio.cpp.o) has no symbols
/Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/ranlib: file: src/drivers/camera_trigger/libdrivers__camera_trigger.a(pwm.cpp.o) has no symbols
/Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/ranlib: file: src/drivers/camera_trigger/libdrivers__camera_trigger.a(seagull_map2.cpp.o) has no symbols
/Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/ranlib: file: src/drivers/camera_trigger/libdrivers__camera_trigger.a(gpio.cpp.o) has no symbols
[714/715] cd /Users/kabir/Development/PX4/Firmware/build/px4_si...rs/kabir/Development/PX4/Firmware/build/px4_sitl_default_repla
SITL ARGS
sitl_bin: /Users/kabir/Development/PX4/Firmware/build/px4_sitl_default_replay/bin/px4
debugger: none
program: jmavsim
model: none
src_path: /Users/kabir/Development/PX4/Firmware
build_path: /Users/kabir/Development/PX4/Firmware/build/px4_sitl_default_replay
empty model, setting iris as default
SITL COMMAND: "/Users/kabir/Development/PX4/Firmware/build/px4_sitl_default_replay/bin/px4" "/Users/kabir/Development/PX4/Firmware"/ROMFS/px4fmu_common -s etc/init.d-posix/rcS -t "/Users/kabir/Development/PX4/Firmware"/test_data
INFO  [px4] Creating symlink /Users/kabir/Development/PX4/Firmware/ROMFS/px4fmu_common -> /Users/kabir/Development/PX4/Firmware/build/px4_sitl_default_replay/tmp/rootfs/etc

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

px4 starting.

INFO  [px4] Calling startup script: /bin/sh etc/init.d-posix/rcS 0
ERROR [uorb] Failed to read publisher rules file ./orb_publisher.rules (No such file or directory)
  SYS_AUTOSTART: curr: 0 -> new: 10016
  BAT_N_CELLS: curr: 0 -> new: 3
  CAL_ACC0_ID: curr: 0 -> new: 1376264
  CAL_ACC1_ID: curr: 0 -> new: 1310728
  CAL_ACC_PRIME: curr: 0 -> new: 1376264
  CAL_GYRO0_ID: curr: 0 -> new: 2293768
  CAL_GYRO_PRIME: curr: 0 -> new: 2293768
  CAL_MAG0_ID: curr: 0 -> new: 196616
  CAL_MAG_PRIME: curr: 0 -> new: 196616
  COM_DISARM_LAND: curr: -1.0000 -> new: 0.1000
  COM_OBL_ACT: curr: 0 -> new: 2
  COM_OF_LOSS_T: curr: 0.0000 -> new: 5.0000
  COM_RC_IN_MODE: curr: 0 -> new: 1
  EKF2_ANGERR_INIT: curr: 0.1000 -> new: 0.0100
  EKF2_GBIAS_INIT: curr: 0.1000 -> new: 0.0100
  MC_PITCH_P: curr: 6.5000 -> new: 6.0000
  MC_PITCHRATE_P: curr: 0.1500 -> new: 0.2000
  MC_ROLL_P: curr: 6.5000 -> new: 6.0000
  MC_ROLLRATE_P: curr: 0.1500 -> new: 0.2000
  MPC_HOLD_MAX_Z: curr: 0.6000 -> new: 2.0000
  MPC_Z_VEL_I: curr: 0.0200 -> new: 0.1500
  MPC_Z_VEL_P: curr: 0.2000 -> new: 0.6000
  MPC_XY_P: curr: 0.9500 -> new: 0.8000
  MPC_XY_VEL_P: curr: 0.0900 -> new: 0.2000
  MPC_XY_VEL_D: curr: 0.0100 -> new: 0.0160
  MPC_JERK_MIN: curr: 8.0000 -> new: 10.0000
  MPC_ACC_HOR_MAX: curr: 10.0000 -> new: 3.0000
  NAV_ACC_RAD: curr: 10.0000 -> new: 2.0000
  NAV_DLL_ACT: curr: 0 -> new: 2
  RTL_DESCEND_ALT: curr: 30.0000 -> new: 5.0000
  RTL_LAND_DELAY: curr: -1.0000 -> new: 5.0000
  RTL_RETURN_ALT: curr: 60.0000 -> new: 30.0000
  SDLOG_MODE: curr: 0 -> new: 1
  SDLOG_PROFILE: curr: 3 -> new: 131
  SDLOG_DIRS_MAX: curr: 0 -> new: 7
  SENS_BOARD_X_OFF: curr: 0.0000 -> new: 0.0000
  SENS_DPRES_OFF: curr: 0.0000 -> new: 0.0010
* RTL_DESCEND_ALT: curr: 5.0000 -> new: 10.0000
* RTL_LAND_DELAY: curr: 5.0000 -> new: 0.0000
  PWM_MAX: curr: 2000 -> new: 1950
  PWM_MIN: curr: 1000 -> new: 1075
INFO  [dataman] Unknown restart, data manager file './dataman' size is 11798680 bytes
INFO  [replay] using replay log file: /Users/kabir/Development/Driverless/EKFtuning/log_7_2019-5-10-17-48-16.ulg
INFO  [replay] Applying params from ULog file...
INFO  [simulator] Waiting for simulator to connect on TCP port 4560
Buildfile: /Users/kabir/Development/PX4/Firmware/Tools/jMAVSim/build.xml

make_dirs:

compile:

create_run_jar:

copy_res:

BUILD SUCCESSFUL
Total time: 0 seconds
Options parsed, starting Sim.
Starting GUI...
3D [dev] 1.6.0-pre12-daily-experimental daily

INFO  [simulator] Simulator connected on TCP port 4560.
Init MAVLink
+ MAV_TYPE: curr: 10 -> new: 2
INFO  [init] Mixer: etc/mixers/quad_w.main.mix on /dev/pwm_output0
INFO  [mavlink] mode: Normal, data rate: 4000000 B/s on udp port 14570 remote port 14550
INFO  [mavlink] mode: Onboard, data rate: 4000000 B/s on udp port 14580 remote port 14540
INFO  [logger] logger started (mode=all)
INFO  [logger] Start file log (type: full)
INFO  [logger] Opened full log file: ./log/2019-05-13/13_49_22_replayed.ulg
INFO  [mavlink] MAVLink only on localhost (set param MAV_BROADCAST = 1 to enable network)
INFO  [replay] Applying params from ULog file...
INFO  [px4] Startup script returned successfully
INFO  [replay] Replay in progress...
WARN  [replay] Formats for vehicle_status don't match. Will ignore it.
WARN  [replay]  Internal format: uint64_t timestamp;uint32_t onboard_control_sensors_present;uint32_t onboard_control_sensors_enabled;uint32_t onboard_control_sensors_health;float arspd_check_level;float load_factor_ratio;uint8_t nav_state;uint8_t arming_state;uint8_t hil_state;bool failsafe;uint8_t system_type;uint8_t system_id;uint8_t component_id;bool is_rotary_wing;bool is_vtol;bool vtol_fw_permanent_stab;bool in_transition_mode;bool in_transition_to_fw;bool rc_signal_lost;uint8_t rc_input_mode;bool data_link_lost;uint8_t data_link_lost_counter;bool high_latency_data_link_lost;bool engine_failure;bool mission_failure;uint8_t failure_detector_status;bool aspd_check_failing;bool aspd_fault_declared;bool aspd_use_inhibit;bool aspd_fail_rtl;uint8_t[4] _padding0;
WARN  [replay]  File format    : uint64_t timestamp;uint32_t onboard_control_sensors_present;uint32_t onboard_control_sensors_enabled;uint32_t onboard_control_sensors_health;uint8_t nav_state;uint8_t arming_state;uint8_t hil_state;bool failsafe;uint8_t system_type;uint8_t system_id;uint8_t component_id;bool is_rotary_wing;bool is_vtol;bool vtol_fw_permanent_stab;bool in_transition_mode;bool in_transition_to_fw;bool rc_signal_lost;uint8_t rc_input_mode;bool data_link_lost;uint8_t data_link_lost_counter;bool high_latency_data_link_lost;bool engine_failure;bool mission_failure;uint8_t failure_detector_status;
WARN  [replay] Formats for vehicle_status_flags don't match. Will ignore it.
WARN  [replay]  Internal format: uint64_t timestamp;bool condition_calibration_enabled;bool condition_system_sensors_initialized;bool condition_system_hotplug_timeout;bool condition_system_returned_to_home;bool condition_auto_mission_available;bool condition_global_position_valid;bool condition_home_position_valid;bool condition_local_position_valid;bool condition_local_velocity_valid;bool condition_local_altitude_valid;bool condition_power_input_valid;bool condition_battery_healthy;bool circuit_breaker_engaged_power_check;bool circuit_breaker_engaged_airspd_check;bool circuit_breaker_engaged_enginefailure_check;bool circuit_breaker_engaged_gpsfailure_check;bool circuit_breaker_flight_termination_disabled;bool circuit_breaker_engaged_usb_check;bool circuit_breaker_engaged_posfailure_check;bool offboard_control_signal_found_once;bool offboard_control_signal_lost;bool offboard_control_set_by_command;bool offboard_control_loss_timeout;bool rc_signal_found_once;bool rc_input_blocked;bool rc_calibration_valid;bool vtol_transition_failure;bool usb_connected;bool avoidance_system_required;bool avoidance_system_valid;uint8_t[2] _padding0;
WARN  [replay]  File format    : uint64_t timestamp;bool condition_calibration_enabled;bool condition_system_sensors_initialized;bool condition_system_hotplug_timeout;bool condition_system_returned_to_home;bool condition_auto_mission_available;bool condition_global_position_valid;bool condition_home_position_valid;bool condition_local_position_valid;bool condition_local_velocity_valid;bool condition_local_altitude_valid;bool condition_power_input_valid;bool condition_battery_healthy;bool circuit_breaker_engaged_power_check;bool circuit_breaker_engaged_airspd_check;bool circuit_breaker_engaged_enginefailure_check;bool circuit_breaker_engaged_gpsfailure_check;bool circuit_breaker_flight_termination_disabled;bool circuit_breaker_engaged_usb_check;bool circuit_breaker_engaged_posfailure_check;bool offboard_control_signal_found_once;bool offboard_control_signal_lost;bool offboard_control_set_by_command;bool offboard_control_loss_timeout;bool rc_signal_found_once;bool rc_input_blocked;bool rc_calibration_valid;bool vtol_transition_failure;bool usb_connected;uint8_t[4] _padding0;
pxh> ERROR [sensors] Gyro #0 fail:  STALE!
ERROR [sensors] Sensor Gyro #0 failed. Reconfiguring sensor priorities.
WARN  [sensors] Remaining sensors after failover event 0: Gyro #0 priority: 1
ERROR [sensors] Accel #0 fail:  STALE!
WARN  ERROR [ekf2] [sensors] accel id changed, resetting IMU biasSensor Accel #0 failed. Reconfiguring sensor priorities.

WARN  WARN  [ekf2] [sensors] gyro id changed, resetting IMU biasRemaining sensors after failover event 0: Accel #0 priority: 1

WARN  [sensors] Remaining sensors after failover event 0: Accel #1 priority: 75
ERROR [sensors] Gyro #0 fail:  STALE!
ERROR [sensors] Sensor Gyro #0 failed. Reconfiguring sensor priorities.
WARN  [sensors] Remaining sensors after failover event 0: Gyro #0 priority: 1
INFO  [ekf2] Mag sensor ID changed to 196616

floating point exception
INFO  [log] Backtrace: 3
INFO  [log] 0   px4                                 0x0000000101f4a3bc px4_backtrace + 44
INFO  [log] 1   ???                                 0x0000000000000019 0x0 + 25
INFO  [log] 2   ???                                 0xbd2beda33c962d47 0x0 + 13631249982518865223

floating point exception
INFO  [log] Backtrace: 3
INFO  [log] 0   px4                                 0x0000000101f4a3bc px4_backtrace + 44
INFO  [log] 1   ???                                 0x0000000000000019 0x0 + 25
INFO  [log] 2   ???                                 0xbd2beda33c962d47 0x0 + 13631249982518865223
dagar commented 5 years ago

We need basic automated testing for things like this.

julianoes commented 5 years ago

@mhkabir what commit are you using when trying the replay here? I get that many topics have changed but no floating point exception:

SITL ARGS
sitl_bin: /home/julianoes/src/Firmware/build/px4_sitl_default_replay/bin/px4
debugger: none
program: jmavsim
model: none
src_path: /home/julianoes/src/Firmware
build_path: /home/julianoes/src/Firmware/build/px4_sitl_default_replay
empty model, setting iris as default
SITL COMMAND: "/home/julianoes/src/Firmware/build/px4_sitl_default_replay/bin/px4" "/home/julianoes/src/Firmware"/ROMFS/px4fmu_common -s etc/init.d-posix/rcS -t "/home/julianoes/src/Firmware"/test_data
INFO  [px4] Creating symlink /home/julianoes/src/Firmware/ROMFS/px4fmu_common -> /home/julianoes/src/Firmware/build/px4_sitl_default_replay/tmp/rootfs/etc
88 WARNING: setRealtimeSched failed (not run as root?)

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

px4 starting.

INFO  [px4] Calling startup script: /bin/sh etc/init.d-posix/rcS 0
ERROR [uorb] Failed to read publisher rules file ./orb_publisher.rules (No such file or directory)
+ SYS_AUTOSTART: curr: 50001 -> new: 10016
+ BAT_N_CELLS: curr: 8 -> new: 3
+ CAL_ACC0_ID: curr: 6488106 -> new: 1376264
+ CAL_ACC_PRIME: curr: 6488106 -> new: 1376264
+ CAL_GYRO0_ID: curr: 6553642 -> new: 2293768
+ CAL_GYRO_PRIME: curr: 6553642 -> new: 2293768
+ CAL_MAG0_ID: curr: 466977 -> new: 196616
+ CAL_MAG_PRIME: curr: 466977 -> new: 196616
+ COM_DISARM_LAND: curr: -1.0000 -> new: 0.1000
+ COM_OBL_ACT: curr: 0 -> new: 2
+ COM_OF_LOSS_T: curr: 0.0000 -> new: 5.0000
+ COM_RC_IN_MODE: curr: 0 -> new: 1
+ EKF2_AID_MASK: curr: 24 -> new: 1
+ EKF2_HGT_MODE: curr: 3 -> new: 0
+ EKF2_GBIAS_INIT: curr: 0.1000 -> new: 0.0100
+ MIS_TAKEOFF_ALT: curr: 0.0100 -> new: 2.5000
+ NAV_DLL_ACT: curr: 0 -> new: 2
+ RTL_DESCEND_ALT: curr: 30.0000 -> new: 5.0000
+ RTL_LAND_DELAY: curr: -1.0000 -> new: 5.0000
+ RTL_RETURN_ALT: curr: 60.0000 -> new: 30.0000
+ SDLOG_MODE: curr: 2 -> new: 1
+ SDLOG_DIRS_MAX: curr: 0 -> new: 7
+ SENS_BOARD_X_OFF: curr: -1.4278 -> new: 0.0000
+ SENS_DPRES_OFF: curr: 0.0000 -> new: 0.0010
+ SYS_RESTART_TYPE: curr: 0 -> new: 2
* RTL_DESCEND_ALT: curr: 5.0000 -> new: 10.0000
* RTL_LAND_DELAY: curr: 5.0000 -> new: 0.0000
+ PWM_MAX: curr: 1800 -> new: 1950
+ PWM_MIN: curr: 1200 -> new: 1075
INFO  [dataman] Unknown restart, data manager file './dataman' size is 11798680 bytes
INFO  [replay] using replay log file: /home/julianoes/Downloads/41b1370f-0007-4537-b245-2fe3344e4f69.ulg
INFO  [replay] Applying params from ULog file...
INFO  [simulator] Waiting for simulator to connect on TCP port 4560
Buildfile: /home/julianoes/src/Firmware/Tools/jMAVSim/build.xml

make_dirs:

compile:

create_run_jar:

copy_res:

BUILD SUCCESSFUL
Total time: 0 seconds
Options parsed, starting Sim.
Starting GUI...
3D [dev] 1.6.0-pre12-daily-experimental daily

INFO  [simulator] Simulator connected on TCP port 4560.
Init MAVLink
+ MAV_TYPE: curr: 10 -> new: 2
INFO  [init] Mixer: etc/mixers/quad_w.main.mix on /dev/pwm_output0
INFO  [mavlink] mode: Normal, data rate: 4000000 B/s on udp port 14570 remote port 14550
INFO  [mavlink] mode: Onboard, data rate: 4000000 B/s on udp port 14580 remote port 14540
INFO  [logger] logger started (mode=all)
INFO  [logger] Start file log (type: full)
INFO  [logger] Opened full log file: ./log/2019-05-14/13_10_26_replayed.ulg
INFO  [mavlink] MAVLink only on localhost (set param MAV_BROADCAST = 1 to enable network)
INFO  [replay] Applying params from ULog file...
INFO  [px4] Startup script returned successfully
pxh> INFO  [replay] Replay in progress...
WARN  [replay] Formats for vehicle_status don't match. Will ignore it.
WARN  [replay]  Internal format: uint64_t timestamp;uint32_t onboard_control_sensors_present;uint32_t onboard_control_sensors_enabled;uint32_t onboard_control_sensors_health;float arspd_check_level;float load_factor_ratio;uint8_t nav_state;uint8_t arming_state;uint8_t hil_state;bool failsafe;uint8_t system_type;uint8_t system_id;uint8_t component_id;bool is_rotary_wing;bool is_vtol;bool vtol_fw_permanent_stab;bool in_transition_mode;bool in_transition_to_fw;bool rc_signal_lost;uint8_t rc_input_mode;bool data_link_lost;uint8_t data_link_lost_counter;bool high_latency_data_link_lost;bool engine_failure;bool mission_failure;uint8_t failure_detector_status;bool aspd_check_failing;bool aspd_fault_declared;bool aspd_use_inhibit;bool aspd_fail_rtl;uint8_t[4] _padding0;
WARN  [replay]  File format    : uint64_t timestamp;uint32_t onboard_control_sensors_present;uint32_t onboard_control_sensors_enabled;uint32_t onboard_control_sensors_health;uint8_t nav_state;uint8_t arming_state;uint8_t hil_state;bool failsafe;uint8_t system_type;uint8_t system_id;uint8_t component_id;bool is_rotary_wing;bool is_vtol;bool vtol_fw_permanent_stab;bool in_transition_mode;bool in_transition_to_fw;bool rc_signal_lost;uint8_t rc_input_mode;bool data_link_lost;uint8_t data_link_lost_counter;bool high_latency_data_link_lost;bool engine_failure;bool mission_failure;uint8_t failure_detector_status;
WARN  [replay] Formats for vehicle_status_flags don't match. Will ignore it.
WARN  [replay]  Internal format: uint64_t timestamp;bool condition_calibration_enabled;bool condition_system_sensors_initialized;bool condition_system_hotplug_timeout;bool condition_system_returned_to_home;bool condition_auto_mission_available;bool condition_global_position_valid;bool condition_home_position_valid;bool condition_local_position_valid;bool condition_local_velocity_valid;bool condition_local_altitude_valid;bool condition_power_input_valid;bool condition_battery_healthy;bool circuit_breaker_engaged_power_check;bool circuit_breaker_engaged_airspd_check;bool circuit_breaker_engaged_enginefailure_check;bool circuit_breaker_engaged_gpsfailure_check;bool circuit_breaker_flight_termination_disabled;bool circuit_breaker_engaged_usb_check;bool circuit_breaker_engaged_posfailure_check;bool offboard_control_signal_found_once;bool offboard_control_signal_lost;bool offboard_control_set_by_command;bool offboard_control_loss_timeout;bool rc_signal_found_once;bool rc_input_blocked;bool rc_calibration_valid;bool vtol_transition_failure;bool usb_connected;bool avoidance_system_required;bool avoidance_system_valid;uint8_t[2] _padding0;
WARN  [replay]  File format    : uint64_t timestamp;bool condition_calibration_enabled;bool condition_system_sensors_initialized;bool condition_system_hotplug_timeout;bool condition_system_returned_to_home;bool condition_auto_mission_available;bool condition_global_position_valid;bool condition_home_position_valid;bool condition_local_position_valid;bool condition_local_velocity_valid;bool condition_local_altitude_valid;bool condition_power_input_valid;bool condition_battery_healthy;bool circuit_breaker_engaged_power_check;bool circuit_breaker_engaged_airspd_check;bool circuit_breaker_engaged_enginefailure_check;bool circuit_breaker_engaged_gpsfailure_check;bool circuit_breaker_flight_termination_disabled;bool circuit_breaker_engaged_usb_check;bool circuit_breaker_engaged_posfailure_check;bool offboard_control_signal_found_once;bool offboard_control_signal_lost;bool offboard_control_set_by_command;bool offboard_control_loss_timeout;bool rc_signal_found_once;bool rc_input_blocked;bool rc_calibration_valid;bool vtol_transition_failure;bool usb_connected;uint8_t[4] _padding0;
WARN  [replay] Topic vehicle_body_state not found internally. Will ignore it
WARN  [replay] Topic vehicle_ackermann_setpoint not found internally. Will ignore it
WARN  [replay] Topic wheel_odometry not found internally. Will ignore it
ERROR [sensors] Gyro #0 fail:  STALE!
ERROR [sensors] Sensor Gyro #0 failed. Reconfiguring sensor priorities.
WARN  [sensors] Remaining sensors after failover event 0: Gyro #0 priority: 1
ERROR [sensors] Accel #1 fail:  STALE!
ERROR [sensors] Sensor Accel #1 failed. Reconfiguring sensor priorities.
WARN  [sensors] Remaining sensors after failover event 1: Accel #0 priority: 75
WARN  [sensors] Remaining sensors after failover event 1: Accel #1 priority: 1
WARN  [ekf2] accel id changed, resetting IMU bias
WARN  [ekf2] gyro id changed, resetting IMU bias
ERROR [sensors] Accel #0 fail:  STALE!
ERROR [sensors] Sensor Accel #0 failed. Reconfiguring sensor priorities.
WARN  [sensors] Remaining sensors after failover event 0: Accel #0 priority: 1
WARN  [sensors] Remaining sensors after failover event 0: Accel #1 priority: 1
WARN  [ekf2] accel id changed, resetting IMU bias
WARN  [ekf2] accel id changed, resetting IMU bias
ERROR [sensors] Gyro #0 fail:  STALE!
ERROR [sensors] Sensor Gyro #0 failed. Reconfiguring sensor priorities.
WARN  [sensors] Remaining sensors after failover event 0: Gyro #0 priority: 1
INFO  [ecl/EKF] EKF aligned, (pressure height, IMU buf: 38, OBS buf: 23)
INFO  [ekf2] Mag sensor ID changed to 196616
WARN  [ecl/EKF] EKF stopping navigation
WARN  [ecl/EKF] EKF stopping navigation

pxh> 
pxh> 
pxh> WARN  [ecl/EKF] EKF baro hgt timeout - reset to baro
WARN  [ecl/EKF] EKF stopping navigation
bkueng commented 5 years ago

@mhkabir I don't get a crash with the same log. Can you run with GDB to get a proper stack trace?

mhkabir commented 5 years ago

@bkueng @julianoes Interesting - will run with GDB.

I also tried with a SITL log from master which I tried to replay, and the same crash occurs, so it seems to be something related to my system, rather than the log. I'm on MacOS High Sierra 10.13.6.

mhkabir commented 5 years ago 
Thread 21 received signal SIGFPE, Arithmetic exception.
[Switching to Thread 0x240b of process 71683]
0x000000010005ac4e in Ekf2::run (this=0x103802c00) at ../../src/modules/ekf2/ekf2_main.cpp:910
910                 int32_t mag_time_ms = _mag_time_sum_ms / _mag_sample_count;
(gdb)
mhkabir commented 5 years ago

Looks like _mag_sample_count eventually wraps around to 0: image

Cause TBD.

stale[bot] commented 5 years ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

julianoes commented 5 years ago

@mhkabir is this still broken?

mhkabir commented 5 years ago

I believe this may have been due to local parameters. Will reopen if encountered again.