search

PX4 / PX4-Autopilot

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

Save `.ulg' failed with POSIX and MAVROS? #6222

Closed weiweikong closed 7 years ago

weiweikong commented 7 years ago

I tried to use current master version to test the my algorithms by .ulg log file using

 roslaunch px4 mavros_posix_sitl.launch

The system worked well as follwoing

... logging to /home/amax/.ros/log/04bea1e2-cf0b-11e6-a4ea-002590fdcfd7/roslaunch-amax-X10DRi-10770.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://amax-X10DRi:49418/

SUMMARY
========

CLEAR PARAMETERS
 * /mavros/

PARAMETERS
 * /mavros/cmd/use_comp_id_system_control: False
 * /mavros/conn/heartbeat_rate: 1.0
 * /mavros/conn/system_time_rate: 1.0
 * /mavros/conn/timeout: 10.0
 * /mavros/conn/timesync_rate: 10.0
 * /mavros/distance_sensor/hrlv_ez4_pub/field_of_view: 0.0
 * /mavros/distance_sensor/hrlv_ez4_pub/frame_id: hrlv_ez4_sonar
 * /mavros/distance_sensor/hrlv_ez4_pub/id: 0
 * /mavros/distance_sensor/hrlv_ez4_pub/orientation: ROLL_180
 * /mavros/distance_sensor/hrlv_ez4_pub/send_tf: True
 * /mavros/distance_sensor/hrlv_ez4_pub/sensor_position/x: 0.0
 * /mavros/distance_sensor/hrlv_ez4_pub/sensor_position/y: 0.0
 * /mavros/distance_sensor/hrlv_ez4_pub/sensor_position/z: -0.1
 * /mavros/distance_sensor/laser_1_sub/id: 3
 * /mavros/distance_sensor/laser_1_sub/orientation: ROLL_180
 * /mavros/distance_sensor/laser_1_sub/subscriber: True
 * /mavros/distance_sensor/lidarlite_pub/field_of_view: 0.0
 * /mavros/distance_sensor/lidarlite_pub/frame_id: lidarlite_laser
 * /mavros/distance_sensor/lidarlite_pub/id: 1
 * /mavros/distance_sensor/lidarlite_pub/orientation: ROLL_180
 * /mavros/distance_sensor/lidarlite_pub/send_tf: True
 * /mavros/distance_sensor/lidarlite_pub/sensor_position/x: 0.0
 * /mavros/distance_sensor/lidarlite_pub/sensor_position/y: 0.0
 * /mavros/distance_sensor/lidarlite_pub/sensor_position/z: -0.1
 * /mavros/distance_sensor/sonar_1_sub/id: 2
 * /mavros/distance_sensor/sonar_1_sub/orientation: ROLL_180
 * /mavros/distance_sensor/sonar_1_sub/subscriber: True
 * /mavros/fcu_url: udp://:14540@loca...
 * /mavros/gcs_url: 
 * /mavros/global_position/frame_id: fcu
 * /mavros/global_position/rot_covariance: 99999.0
 * /mavros/global_position/tf/child_frame_id: fcu_utm
 * /mavros/global_position/tf/frame_id: local_origin
 * /mavros/global_position/tf/send: False
 * /mavros/image/frame_id: px4flow
 * /mavros/imu/angular_velocity_stdev: 0.000349065850399
 * /mavros/imu/frame_id: fcu
 * /mavros/imu/linear_acceleration_stdev: 0.0003
 * /mavros/imu/magnetic_stdev: 0.0
 * /mavros/imu/orientation_stdev: 1.0
 * /mavros/local_position/frame_id: fcu
 * /mavros/local_position/tf/child_frame_id: fcu
 * /mavros/local_position/tf/frame_id: local_origin
 * /mavros/local_position/tf/send: False
 * /mavros/local_position/tf/send_fcu: False
 * /mavros/mission/pull_after_gcs: True
 * /mavros/mocap/use_pose: True
 * /mavros/mocap/use_tf: False
 * /mavros/plugin_blacklist: ['safety_area', '...
 * /mavros/plugin_whitelist: []
 * /mavros/px4flow/frame_id: px4flow
 * /mavros/px4flow/ranger_fov: 0.0
 * /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_throttle: False
 * /mavros/setpoint_attitude/tf/child_frame_id: attitude
 * /mavros/setpoint_attitude/tf/frame_id: local_origin
 * /mavros/setpoint_attitude/tf/listen: False
 * /mavros/setpoint_attitude/tf/rate_limit: 10.0
 * /mavros/setpoint_position/tf/child_frame_id: setpoint
 * /mavros/setpoint_position/tf/frame_id: local_origin
 * /mavros/setpoint_position/tf/listen: False
 * /mavros/setpoint_position/tf/rate_limit: 50.0
 * /mavros/startup_px4_usb_quirk: True
 * /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/vibration/frame_id: vibration
 * /mavros/vision_pose/tf/child_frame_id: vision
 * /mavros/vision_pose/tf/frame_id: local_origin
 * /mavros/vision_pose/tf/listen: False
 * /mavros/vision_pose/tf/rate_limit: 10.0
 * /mavros/vision_speed/listen_twist: False
 * /rosdistro: jade
 * /rosversion: 1.11.20
 * /use_sim_time: True

NODES
  /
    gazebo (gazebo_ros/gzserver)
    gazebo_gui (gazebo_ros/gzclient)
    mavros (mavros/mavros_node)
    sitl (px4/px4)
    vehicle_spawn_amax_X10DRi_10770_1154193950404211463 (gazebo_ros/spawn_model)

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

setting /run_id to 04bea1e2-cf0b-11e6-a4ea-002590fdcfd7
process[rosout-1]: started with pid [10795]
started core service [/rosout]
process[sitl-2]: started with pid [10820]
node name: sitl
data path: /home/amax/Workspace/53.PX4_New/Firmware
commands file: /home/amax/Workspace/53.PX4_New/Firmware/posix-configs/SITL/init/lpe/iris
18446744073709551392 WARNING: setRealtimeSched failed (not run as root?)

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

px4 starting.

process[gazebo-3]: started with pid [10828]
process[gazebo_gui-4]: started with pid [10831]
process[vehicle_spawn_amax_X10DRi_10770_1154193950404211463-5]: started with pid [10836]
process[mavros-6]: started with pid [10839]
INFO  [dataman] Unkown restart, data manager file 'rootfs/fs/microsd/dataman' size is 47640 bytes
[ INFO] [1483155692.278406439]: FCU URL: udp://:14540@localhost:14557
[ INFO] [1483155692.278922479]: udp0: Bind address: 0.0.0.0:14540
[ INFO] [1483155692.279089922]: udp0: Remote address: 127.0.0.1:14557
[ INFO] [1483155692.279306405]: GCS bridge disabled
INFO  [platforms__posix__drivers__ledsim] LED::init
INFO  [platforms__posix__drivers__ledsim] LED::init
INFO  [simulator] Waiting for initial data on UDP port 14560. Please start the flight simulator to proceed..
[ INFO] [1483155692.342393042]: Plugin 3dr_radio loaded and initialized
[ INFO] [1483155692.348086037]: Plugin actuator_control loaded and initialized
[ INFO] [1483155692.350135519]: Plugin altitude loaded and initialized
[ INFO] [1483155692.461397073]: Plugin cam_imu_sync loaded and initialized
[ INFO] [1483155692.467270520]: Plugin command loaded and initialized
[ INFO] [1483155692.467314458]: Plugin distance_sensor blacklisted
[ INFO] [1483155692.476227104]: Plugin ftp loaded and initialized
[ INFO] [1483155692.486664018]: Plugin global_position loaded and initialized
[ INFO] [1483155692.487514362]: Plugin hil_controls loaded and initialized
[ INFO] [1483155692.487554525]: Plugin image_pub blacklisted
spawn_model script started
[ INFO] [1483155692.498628542]: Plugin imu_pub loaded and initialized
[ INFO] [1483155692.507418612]: Plugin local_position loaded and initialized
[ INFO] [1483155692.508392040]: Plugin manual_control loaded and initialized
[ INFO] [1483155692.515014496]: Plugin mocap_pose_estimate loaded and initialized
[ INFO] [1483155692.518759158]: Plugin param loaded and initialized
[ INFO] [1483155692.526743464]: Plugin px4flow loaded and initialized
[ INFO] [1483155692.532242434]: Plugin rc_io loaded and initialized
[ INFO] [1483155692.532306129]: Plugin safety_area blacklisted
[ INFO] [1483155692.537567768]: Plugin setpoint_accel loaded and initialized
[ INFO] [1483155692.561851942]: Finished loading Gazebo ROS API Plugin.
[ INFO] [1483155692.562557715]: waitForService: Service [/gazebo/set_physics_properties] has not been advertised, waiting...
[ INFO] [1483155692.567761856]: Plugin setpoint_attitude loaded and initialized
[ INFO] [1483155692.575395397]: Plugin setpoint_position loaded and initialized
[ INFO] [1483155692.586759065]: Plugin setpoint_raw loaded and initialized
[ INFO] [1483155692.590020774]: Plugin setpoint_velocity loaded and initialized
[ INFO] [1483155692.603734059]: Plugin sys_status loaded and initialized
[ INFO] [1483155692.607945444]: Plugin sys_time loaded and initialized
[ INFO] [1483155692.610123206]: Plugin vfr_hud loaded and initialized
[ INFO] [1483155692.610197737]: Plugin vibration blacklisted
[ INFO] [1483155692.621481833]: Plugin vision_pose_estimate loaded and initialized
[ INFO] [1483155692.627647296]: Plugin vision_speed_estimate loaded and initialized
[ INFO] [1483155692.632283480]: Plugin waypoint loaded and initialized
[ INFO] [1483155692.632344925]: Autostarting mavlink via USB on PX4
[ INFO] [1483155692.632390186]: Built-in SIMD instructions: SSE, SSE2
[ INFO] [1483155692.632415080]: Built-in MAVLink package version: 2016.5.20
[ INFO] [1483155692.632440960]: Built-in MAVLink dialect: ardupilotmega
[ INFO] [1483155692.632544473]: MAVROS started. MY ID 1.240, TARGET ID 1.1
[INFO] [WallTime: 1483155692.654845] [0.000000] Loading model xml from file
[INFO] [WallTime: 1483155692.655222] [0.000000] Waiting for service /gazebo/spawn_sdf_model
[ INFO] [1483155693.718176397, 0.022000000]: waitForService: Service [/gazebo/set_physics_properties] is now available.
[ INFO] [1483155693.769787941, 0.074000000]: Physics dynamic reconfigure ready.
[INFO] [WallTime: 1483155693.865014] [0.166000] Calling service /gazebo/spawn_sdf_model
[INFO] [WallTime: 1483155694.112686] [0.322000] Spawn status: SpawnModel: Successfully spawned model
[vehicle_spawn_amax_X10DRi_10770_1154193950404211463-5] process has finished cleanly
log file: /home/amax/.ros/log/04bea1e2-cf0b-11e6-a4ea-002590fdcfd7/vehicle_spawn_amax_X10DRi_10770_1154193950404211463-5*.log
INFO  [simulator] Got initial simuation data, running sim..
INFO  [pwm_out_sim] MODE_8PWM
Sleeping for 1 s; (1000000 us).
[lpe] fuse gps: 1, flow: 1, vis_pos: 1, vis_yaw: 0, land: 1, pub_agl_z: 1, flow_gyro: 1
INFO  [mavlink] mode: Normal, data rate: 4000000 B/s on udp port 14556 remote port 14550
INFO  [mavlink] mode: Onboard, data rate: 4000000 B/s on udp port 14557 remote port 14540
INFO  [mavlink] MAVLink only on localhost (set param MAV_BROADCAST = 1 to enable network)
INFO  [logger] logger started (mode=all)
pxh> INFO  [logger] Start file log
INFO  [logger] Opened log file: rootfs/fs/microsd/log/2016-12-31/03_41_36.ulg
[ INFO] [1483155696.300781006, 2.484000000]: udp0: Remote address: 127.0.0.1:14557
[ INFO] [1483155696.309178099, 2.494000000]: IMU: High resolution IMU detected!
INFO  [local_position_estimator] [lpe] land init
INFO  [mavlink] partner IP: 127.0.0.1
[ INFO] [1483155696.349248369, 2.534000000]: FCU: [lpe] land init
WARN  [mavlink] [timesync] Hard setting offset.
INFO  [tone_alarm] startup
[ INFO] [1483155697.247928005, 3.428000000]: CON: Got HEARTBEAT, connected. FCU: PX4
[ INFO] [1483155697.248249319, 3.428000000]: IMU: High resolution IMU detected!
[ INFO] [1483155698.252710250, 4.430000000]: VER: 1.1: Capabilities 0x00000000000024ef
[ INFO] [1483155698.252813343, 4.430000000]: VER: 1.1: Flight software:     01050200 (0205492a247faa05)
[ INFO] [1483155698.252855850, 4.430000000]: VER: 1.1: Middleware software: 01050200 (0205492a247faa05)
[ INFO] [1483155698.252890316, 4.430000000]: VER: 1.1: OS software:         010600ff (0000000000000000)
[ INFO] [1483155698.252940128, 4.430000000]: VER: 1.1: Board hardware:      00000001
[ INFO] [1483155698.252967365, 4.430000000]: VER: 1.1: VID/PID: 0000:0000
[ INFO] [1483155698.252996197, 4.430000000]: VER: 1.1: UID: 0000000100000002
INFO  [local_position_estimator] [lpe] gps init lat  47.40 lon   8.55 alt 488.1 m
INFO  [local_position_estimator] [lpe] baro init 0 m std 7 cm
INFO  [commander] home: 47.3977432, 8.5455942, 0.11
INFO  [tone_alarm] home_set
[ INFO] [1483155698.597933064, 4.776000000]: FCU: [lpe] baro init 0 m std 7 cm
INFO  [tone_alarm] neutral
[ INFO] [1483155712.272610543, 18.428000000]: WP: mission received
INFO  [commander] home: 47.3977420, 8.5455937, 0.11
INFO  [tone_alarm] positive
INFO  [commander] home: 47.3977420, 8.5455937, 0.11
INFO  [commander] no RC
WARN  [commander] failsafe mode on
INFO  [tone_alarm] arming
[ WARN] [1483155746.913537643, 53.012000000]: CMD: Unexpected command 400, result 0
WARN  [navigator] Already landed, not executing RTL
[ INFO] [1483155746.948893842, 53.046000000]: FCU: ARMED by arm/disarm component command
[ INFO] [1483155746.998971780, 53.096000000]: FCU: no RC
[ERROR] [1483155747.049096529, 53.146000000]: FCU: failsafe mode on
[ERROR] [1483155747.099086137, 53.198000000]: FCU: Already landed, not executing RTL
[ INFO] [1483155747.149208432, 53.248000000]: FCU: RTL: completed, landed
INFO  [local_position_estimator] [lpe] land timeout 
[ INFO] [1483155748.147902309, 54.244000000]: FCU: [lpe] land timeout 
INFO  [tone_alarm] positive
WARN  [commander] failsafe mode off
[ERROR] [1483155748.349170067, 54.446000000]: FCU: failsafe mode off
INFO  [commander] Takeoff detected
[ INFO] [1483155751.347595790, 57.438000000]: FCU: Takeoff detected
INFO  [tone_alarm] positive
INFO  [tone_alarm] neutral
[ WARN] [1483155763.333991619, 69.406000000]: CMD: Unexpected command 400, result 0
INFO  [logger] closed logfile, bytes written: 4357056
[ INFO] [1483155763.348739377, 69.420000000]: FCU: DISARMED by arm/disarm component command
INFO  [local_position_estimator] [lpe] land init
[ INFO] [1483155763.898135845, 69.968000000]: FCU: [lpe] land init
INFO  [commander] Landing detected
[ INFO] [1483155765.399206218, 71.468000000]: FCU: Landing detected

I could ARM and DISARM correctly through MAVROS, but the system did not save the log file correctly even though the terminal told me

INFO  [logger] Opened log file: rootfs/fs/microsd/log/2016-12-31/03_41_36.ulg

I checked that the folder Firmware/build_posix_sitl_default/tmp/rootfs/fs/microsd/log/2016-12-31 was clean. Also, I searched the whole Fimware folder by

✔ amax@amax-X10DRi|~/Workspace/53.PX4_New/Firmware [master|✚ ] 
11:43:21 $ find . -name "*ulg*"
✔ amax@amax-X10DRi|~/Workspace/53.PX4_New/Firmware [master|✚ ] 
11:43:24 $

but got nothing.

bkueng commented 7 years ago

I don't have ROS installed, so I cannot test it. It seems ROS uses $ROS_HOME as working directory, so you can start to look in there if you find an .ulg file.

weiweikong commented 7 years ago

@bkueng Thank you for your reply.

In my opinion, the $ROS_HOME folder only recorded the related terminal feedback. I tried and checked the folder, but there are 

✔ amax@amax-X10DRi|~/.ros/log/04bea1e2-cf0b-11e6-a4ea-002590fdcfd7 
07:55:34 $ ls
keyboard-1-stdout.log
master.log
roslaunch-amax-X10DRi-10770.log
roslaunch-amax-X10DRi-11634.log
rosout-1-stdout.log
rosout.log
vehicle_spawn_amax_X10DRi_10770_1154193950404211463-5.log

In previous tests, without MAVROS, such as running make posix_sitl_default gazebo instead of roslaunch px4 mavros_posix_sitl.launch, the .px4log and .ulg saved correctly in the build_posix_sitl_default/rootfs/fs/microsd/log/ folder whith is independent of $ROS_HOME folder.

mhkabir commented 7 years ago

Please reopen if this is still an issue. It works fine for me locally.

NRottmann commented 7 years ago

@weiweikong or @mhkabir I am facing the same Issue. I am running my simulation with mavros and .ulg is not saved correctly. If I instead make posix_sitl_default gazebo then it stores the log files correctly. How did you solve the problem? Best Nils