position not reached | lat: 47.399269104, lon: 8.545572281, alt: 500.18, current pos_xy_d: 79.03, current pos_z_d: 0.25, best pos_xy_d: 12.14, best pos_z_d: 0.00, index: 2 | timeout(seconds): 60 File "/usr/lib/python2.7/unittest/case.py", line 329, in run testMethod() File "/tmp/jenkins/workspace/Firmware_PR-8879-TZVSC74FWKMSPBVCR36TYW7EI3BKRXFEVHOC22U6NPHOJJKPO6VQ/integrationtests/python_src/px4_it/mavros/mission_test.py", line 305, in test_mission index) File "/tmp/jenkins/workspace/Firmware_PR-8879-TZVSC74FWKMSPBVCR36TYW7EI3BKRXFEVHOC22U6NPHOJJKPO6VQ/integrationtests/python_src/px4_it/mavros/mission_test.py", line 262, in reach_position best_pos_z_d, index, timeout)) File "/usr/lib/python2.7/unittest/case.py", line 422, in assertTrue raise self.failureException(msg) <![CDATA[ [INFO] [1518534708.948427, 0.000000]: waiting for ROS services [INFO] [1518534708.956442, 0.000000]: ROS services are up [INFO] [1518534708.976851, 1.406000]: VTOL state changed from MAV_VTOL_STATE_UNDEFINED to MAV_VTOL_STATE_MC [INFO] [1518534708.977293, 1.406000]: landed state changed from MAV_LANDED_STATE_UNDEFINED to MAV_LANDED_STATE_IN_AIR [INFO] [1518534708.989575, 1.418000]: reading mission /tmp/jenkins/workspace/Firmware_PR-8879-TZVSC74FWKMSPBVCR36TYW7EI3BKRXFEVHOC22U6NPHOJJKPO6VQ/integrationtests/python_src/px4_it/mavros/vtol_old_3.txt [INFO] [1518534708.990862, 1.420000]: waiting for subscribed topics to be ready [INFO] [1518534709.364951, 1.796000]: landed state changed from MAV_LANDED_STATE_IN_AIR to MAV_LANDED_STATE_ON_GROUND [INFO] [1518534709.866362, 2.296000]: connected changed from False to True [INFO] [1518534709.866642, 2.296000]: mode changed from to MANUAL [INFO] [1518534709.866882, 2.296000]: system_status changed from MAV_STATE_UNINIT to MAV_STATE_STANDBY [INFO] [1518534720.893223, 13.302000]: mode changed from MANUAL to AUTO.LOITER [INFO] [1518534725.017920, 17.420000]: simulation topics ready | seconds: 16.0 of 60 [INFO] [1518534725.018290, 17.420000]: waiting for landed state | state: MAV_LANDED_STATE_ON_GROUND, index: -1 [INFO] [1518534725.018464, 17.420000]: landed state confirmed | seconds: 0.0 of 10 [INFO] [1518534725.018610, 17.420000]: waiting for MAV_TYPE [INFO] [1518534725.021564, 17.424000]: MAV_TYPE received | type: MAV_TYPE_VTOL_RESERVED2 | seconds: 0.0 of 10 [INFO] [1518534725.021893, 17.424000]: sending mission waypoints [INFO] [1518534725.033055, 17.436000]: waypoints successfully transferred [INFO] [1518534726.026688, 18.426000]: number of waypoints transferred: 3 [INFO] [1518534726.026970, 18.426000]: send waypoints success | seconds: 1.0 of 30 [INFO] [1518534726.027253, 18.426000]: ======================== [INFO] [1518534726.027462, 18.426000]: ===== topic values ===== [INFO] [1518534726.027646, 18.426000]: ======================== [INFO] [1518534726.028418, 18.426000]: altitude: header: seq: 170 stamp: secs: 18 nsecs: 403106283 frame_id: "map" monotonic: 491.09564209 amsl: 488.153625488 local: -0.0776000991464 relative: -0.111572265625 terrain: nan bottom_clearance: nan [INFO] [1518534726.028915, 18.428000]: ======================== [INFO] [1518534726.029473, 18.430000]: extended_state: header: seq: 341 stamp: secs: 18 nsecs: 402000000 frame_id: '' vtol_state: 3 landed_state: 1 [INFO] [1518534726.029706, 18.430000]: ======================== [INFO] [1518534726.030280, 18.430000]: global_position: header: seq: 855 stamp: secs: 18 nsecs: 423509283 frame_id: "base_link" status: status: 0 service: 1 latitude: 47.3977419 longitude: 8.5455939 altitude: 535.374915703 position_covariance: [0.0, 0.0, 0.0, 0.0, 0.0, 0.0, 0.0, 0.0, 0.0] position_covariance_type: 1 [INFO] [1518534726.030550, 18.430000]: ======================== [INFO] [1518534726.030822, 18.430000]: home_position: header: seq: 7 stamp: secs: 17 nsecs: 300000000 frame_id: '' geo: latitude: 47.3977418 longitude: 8.5455939 altitude: 535.485915657 position: x: 0.00697607640177 y: -0.0140532013029 z: 0.0339759550989 orientation: x: 0.999340553294 y: 0.0363111958661 z: 6.11919604925e-17 w: 2.22341948953e-18 approach: x: 0.0 y: 0.0 z: 0.0 [INFO] [1518534726.031124, 18.430000]: ======================== [INFO] [1518534726.031794, 18.432000]: local_position: header: seq: 512 stamp: secs: 18 nsecs: 401509283 frame_id: "map" pose: position: x: 0.000214634143049 y: -0.00423682434484 z: -0.0776000991464 orientation: x: 0.0101923605216 y: -0.0142150954537 z: -0.0230127693428 w: -0.99958213903 [INFO] [1518534726.031954, 18.432000]: ======================== [INFO] [1518534726.032427, 18.432000]: mission_wp: current_seq: 0 waypoints: - frame: 3 command: 16 is_current: True autocontinue: True param1: 15.0 param2: 0.0 param3: 0.0 param4: 0.0 x_lat: 47.3981576691 y_long: 8.54603363171 z_alt: 12.0 - frame: 2 command: 3000 is_current: False autocontinue: True param1: 4.0 param2: 0.0 param3: 0.0 param4: 0.0 x_lat: 47.3980331421 y_long: 8.54578971863 z_alt: 12.0 - frame: 3 command: 16 is_current: False autocontinue: True param1: 0.0 param2: 0.0 param3: 0.0 param4: 0.0 x_lat: 47.399269104 y_long: 8.54557228088 z_alt: 12.0 [INFO] [1518534726.032611, 18.432000]: ======================== [INFO] [1518534726.032972, 18.432000]: state: header: seq: 17 stamp: secs: 18 nsecs: 302000000 frame_id: '' connected: True armed: False guided: True mode: "AUTO.LOITER" system_status: 3 [INFO] [1518534726.033532, 18.434000]: ======================== [INFO] [1518534726.033781, 18.434000]: setting FCU mode: AUTO.MISSION [INFO] [1518534726.912746, 19.310000]: mode changed from AUTO.LOITER to AUTO.MISSION [INFO] [1518534727.037202, 19.434000]: set mode success | seconds: 1.0 of 5 [INFO] [1518534727.037450, 19.434000]: setting FCU arm: True [INFO] [1518534727.113365, 19.510000]: landed state changed from MAV_LANDED_STATE_ON_GROUND to MAV_LANDED_STATE_TAKEOFF [INFO] [1518534727.915148, 20.310000]: armed state changed from False to True [INFO] [1518534727.915627, 20.310000]: system_status changed from MAV_STATE_STANDBY to MAV_STATE_ACTIVE [INFO] [1518534728.038451, 20.434000]: set arm success | seconds: 1.0 of 5 [INFO] [1518534728.038726, 20.434000]: run mission vtol_old_3.txt [INFO] [1518534728.038992, 20.434000]: trying to reach waypoint | lat: 47.398157669, lon: 8.546033632, alt: 500.18, index: 0 [INFO] [1518534728.039827, 20.434000]: current distance to waypoint | pos_xy_d: 56.89, pos_z_d: 11.45, index: 0 [INFO] [1518534735.548833, 27.930000]: landed state changed from MAV_LANDED_STATE_TAKEOFF to MAV_LANDED_STATE_IN_AIR [INFO] [1518534738.064866, 30.434000]: current distance to waypoint | pos_xy_d: 54.32, pos_z_d: 0.06, index: 0 [INFO] [1518534748.078965, 40.434000]: current distance to waypoint | pos_xy_d: 5.38, pos_z_d: 0.05, index: 0 [INFO] [1518534758.112689, 50.434000]: current distance to waypoint | pos_xy_d: 0.26, pos_z_d: 0.10, index: 0 [INFO] [1518534763.285713, 55.596000]: mission item reached: 0 [INFO] [1518534763.286138, 55.596000]: current mission waypoint sequence updated: 1 [INFO] [1518534763.623873, 55.934000]: position reached | pos_xy_d: 0.29, pos_z_d: 0.05, index: 0 | seconds: 35.5 of 60 [INFO] [1518534763.624493, 55.936000]: waiting for VTOL transition | transition: MAV_VTOL_STATE_FW, index: 1 [INFO] [1518534764.701652, 57.010000]: mission item reached: 1 [INFO] [1518534764.751511, 57.060000]: VTOL state changed from MAV_VTOL_STATE_MC to MAV_VTOL_STATE_TRANSITION_TO_FW [INFO] [1518534769.257825, 61.550000]: current mission waypoint sequence updated: 2 [INFO] [1518534769.285072, 61.576000]: VTOL state changed from MAV_VTOL_STATE_TRANSITION_TO_FW to MAV_VTOL_STATE_FW [INFO] [1518534769.343246, 61.636000]: transitioned | seconds: 5.7 of 60 [INFO] [1518534769.343584, 61.636000]: trying to reach waypoint | lat: 47.399269104, lon: 8.545572281, alt: 500.18, index: 2 [INFO] [1518534769.343767, 61.636000]: current distance to waypoint | pos_xy_d: 111.57, pos_z_d: 0.05, index: 2 [INFO] [1518534770.008998, 62.300000]: mission item reached: 2 [INFO] [1518534779.365462, 71.636000]: current distance to waypoint | pos_xy_d: 88.19, pos_z_d: 10.13, index: 2 [INFO] [1518534789.385214, 81.636000]: current distance to waypoint | pos_xy_d: 85.11, pos_z_d: 2.06, index: 2 [INFO] [1518534799.407367, 91.636000]: current distance to waypoint | pos_xy_d: 78.16, pos_z_d: 1.15, index: 2 [INFO] [1518534809.426535, 101.636000]: current distance to waypoint | pos_xy_d: 79.26, pos_z_d: 0.13, index: 2 [INFO] [1518534819.442307, 111.636000]: current distance to waypoint | pos_xy_d: 78.88, pos_z_d: 0.27, index: 2 [INFO] [1518534829.464660, 121.636000]: ======================== [INFO] [1518534829.464931, 121.636000]: ===== topic values ===== [INFO] [1518534829.465109, 121.636000]: ======================== [INFO] [1518534829.465614, 121.636000]: altitude: header: seq: 1200 stamp: secs: 121 nsecs: 572075369 frame_id: "map" monotonic: 503.235748291 amsl: 500.382354736 local: 12.1511106491 relative: 12.205078125 terrain: nan bottom_clearance: nan [INFO] [1518534829.465777, 121.636000]: ======================== [INFO] [1518534829.465951, 121.636000]: extended_state: header: seq: 2402 stamp: secs: 121 nsecs: 622000000 frame_id: '' vtol_state: 4 landed_state: 2 [INFO] [1518534829.466091, 121.636000]: ======================== [INFO] [1518534829.466449, 121.636000]: global_position: header: seq: 6007 stamp: secs: 121 nsecs: 627903147 frame_id: "base_link" status: status: 0 service: 1 latitude: 47.399767 longitude: 8.5448203 altitude: 547.597978491 position_covariance: [0.0, 0.0, 0.0, 0.0, 0.0, 0.0, 0.0, 0.0, 0.0] position_covariance_type: 1 [INFO] [1518534829.466634, 121.636000]: ======================== [INFO] [1518534829.466909, 121.636000]: home_position: header: seq: 59 stamp: secs: 121 nsecs: 472000000 frame_id: '' geo: latitude: 47.3977419 longitude: 8.5455939 altitude: 535.397915703 position: x: 0.000787011231296 y: -0.00954933278263 z: -0.05396970734 orientation: x: 0.999751105745 y: 0.0223107292872 z: 6.12170995797e-17 w: 1.36613816041e-18 approach: x: 0.0 y: 0.0 z: 0.0 [INFO] [1518534829.467180, 121.636000]: ======================== [INFO] [1518534829.467530, 121.636000]: local_position: header: seq: 3603 stamp: secs: 121 nsecs: 603903147 frame_id: "map" pose: position: x: -58.5048751831 y: 224.8722229 z: 12.1474599838 orientation: x: -0.163120031098 y: -0.0615302789715 z: -0.376815563912 w: -0.90973401421 [INFO] [1518534829.467709, 121.636000]: ======================== [INFO] [1518534829.467990, 121.636000]: mission_wp: current_seq: 2 waypoints: - frame: 3 command: 16 is_current: False autocontinue: True param1: 15.0 param2: 0.0 param3: 0.0 param4: 0.0 x_lat: 47.3981576691 y_long: 8.54603363171 z_alt: 12.0 - frame: 2 command: 3000 is_current: False autocontinue: True param1: 4.0 param2: 0.0 param3: 0.0 param4: 0.0 x_lat: 47.3980331421 y_long: 8.54578971863 z_alt: 12.0 - frame: 3 command: 16 is_current: True autocontinue: True param1: 0.0 param2: 0.0 param3: 0.0 param4: 0.0 x_lat: 47.399269104 y_long: 8.54557228088 z_alt: 12.0 [INFO] [1518534829.468133, 121.636000]: ======================== [INFO] [1518534829.468511, 121.636000]: state: header: seq: 120 stamp: secs: 121 nsecs: 472000000 frame_id: '' connected: True armed: True guided: True mode: "AUTO.MISSION" system_status: 4 [INFO] [1518534829.468674, 121.636000]: ======================== ]]><![CDATA[ ]]>