Numerous tests failing autotest for many many builds

[jaxxzer]

We have currently 10 failing autotests, and tests have been failing on every build for several months.

What is the point of doing these tests if we do not make use of the results? There are obviously problems here that are not being resolved.

I think we need to strive to police this better, increase the visibility of these results, and make some sort of rule about fixing failing tests within some amount of time. Preventing merge of code that fails tests (by adding autotest to ci) would be even better.

Related #9589 and #9592

[khancyr]

there is something wrong on autotest server as travis is able to pass the test ...
but yes we should add a baner to github that reflect the autotest server status

[jaxxzer]

travis and autotest are not running the same tests.

[khancyr]

yes they are ... we only have on set of autotest

[jaxxzer]

@khancyr FYI if I'm not mistaken:

autotest runs build_autotest.sh which takes several hours to complete.

Ci runs build_ci.sh. There is a small overlap of tests with autotest, but it is different.

The problem is not with the autotest server. The problem is our program fails the tests we wrote.

[jaxxzer]

There are some discrepancies in the tests that are common between travis ci and autotest. For example:
autotest.py dive.ArduSubis passing on travis, and failing on autotest.

[jaxxzer]

The problem is not with the autotest server. The problem is our program fails the tests we wrote.

autotest.py dive.ArduSub is passing locally also. Maybe I am wrong.

[khancyr]

Autotest.sh is calling autotest.py like build_ci.sh the test are the same.
But it should'nt take more than 1hour to run... Travis is already quite slow...
I got them running on my company server and that is fine.
They are some issue on some test, where we are relaying on timeout. Depending on the server, the test or the anwser expected can be too slow or to fast and break the test.
Now, we get the first stone of isolated test. So we will be able to parallelilize them more to finish sooner and see exactly which one are failling.

But I am pretty sure that the problem come from our build server... Something with cache management, like usual...
And I agree that we should have a banner or feedback on github to allow more people to check if they everything is OK

[jaxxzer]

Autotest.sh is calling autotest.py like build_ci.sh the test are the same.

My understanding is that ci is calling autotest.py with only a smaller subset of tests, and autotest is calling autotest.py with all tests.

[jaxxzer]

I've had a look at the full log from the most recent autotest. At the very end of the log we can see dive.ArduSub fails from some missing file DiveMission (Dive mission) ([Errno 2] No such file or directory: '/storage/autotest/APM/APM/test.ArduSub/logs/2019-02-04/flight15/way.txt') (see /storage/autotest/APM/buildlogs/ArduSub-DiveMission.txt)

Some other problems with missing dependencies are visible at the very end of the file also. Is there any information available about how autotest is set up and deployed?

$ curl http://autotest.ardupilot.org/autotest-output.txt | tail -n50
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100 16.8M  100 16.8M    0     0  12.2M      0  0:00:01  0:00:01 --:--:-- 12.2M
MANUAL> log download latest /storage/autotest/APM/buildlogs/APMrover2-log.bin
MANUAL> Downloading log 2 as /storage/autotest/APM/buildlogs/APMrover2-log.bin
Flight battery warning
Finished downloading /storage/autotest/APM/buildlogs/APMrover2-log.bin (9207808 bytes 35 seconds, 260.1 kbyte/sec 0 retries)
AUTOTEST: Drained 2051 messages from mav (110.192381/s)
AUTOTEST: Drained 0 messages from mav (0.000000/s)
Uploading 115 logs to http://firmware.ardupilot.org/CI-Logs/2019-02-04-12-42
@ERROR: Unknown module 'CI-Logs'
rsync error: error starting client-server protocol (code 5) at main.c(1653) [sender=3.1.1]
AUTOTEST: PASSED: "DownLoadLogs (Download logs)"
AUTOTEST: Failing tests:
  DiveMission (Dive mission) ([Errno 2] No such file or directory: '/storage/autotest/APM/APM/test.ArduSub/logs/2019-02-04/flight15/way.txt') (see /storage/autotest/APM/buildlogs/ArduSub-DiveMission.txt)
>>>> FAILED STEP: dive.ArduSub at Mon Feb  4 12:42:43 2019
>>>> RUNNING STEP: convertgpx at Mon Feb  4 12:42:43 2019
Running: ("/bin/rm -f logs/*.BIN logs/LASTLOG.TXT") in (.)
step=convertgpx
Running: ("/storage/autotest/APM/APM/modules/mavlink/pymavlink/tools/mavtogpx.py --nofixcheck /storage/autotest/APM/buildlogs/ArduSub-test.tlog") in (.)
Created /storage/autotest/APM/buildlogs/ArduSub-test.tlog.gpx with 2277 points
Running: ("gpsbabel -i gpx -f /storage/autotest/APM/buildlogs/ArduSub-test.tlog.gpx -o kml,units=m,floating=1,extrude=1 -F /storage/autotest/APM/buildlogs/ArduSub-test.tlog.kml") in (.)
Running: ("zip /storage/autotest/APM/buildlogs/ArduSub-test.tlog.kmz /storage/autotest/APM/buildlogs/ArduSub-test.tlog.kml") in (.)
updating: storage/autotest/APM/buildlogs/ArduSub-test.tlog.kml (deflated 98%)
Running: ("mavflightview.py --imagefile=/storage/autotest/APM/buildlogs/ArduSub-test.tlog.png /storage/autotest/APM/buildlogs/ArduSub-test.tlog") in (.)
Traceback (most recent call last):
  File "/home/autotest/.local/bin/mavflightview.py", line 4, in <module>
    __import__('pkg_resources').run_script('MAVProxy==1.8.5', 'mavflightview.py')
  File "/usr/local/lib/python2.7/dist-packages/pkg_resources/__init__.py", line 742, in run_script
    self.require(requires)[0].run_script(script_name, ns)
  File "/usr/local/lib/python2.7/dist-packages/pkg_resources/__init__.py", line 1510, in run_script
    exec(script_code, namespace, namespace)
  File "/home/autotest/.local/lib/python2.7/site-packages/MAVProxy-1.8.5-py2.7.egg/EGG-INFO/scripts/mavflightview.py", line 11, in <module>
    
  File "build/bdist.linux-x86_64/egg/MAVProxy/modules/mavproxy_map/mp_slipmap.py", line 19, in <module>
    
  File "build/bdist.linux-x86_64/egg/MAVProxy/modules/lib/win_layout.py", line 4, in <module>
ImportError: No module named wx
>>>> FAILED STEP: convertgpx at Mon Feb  4 12:42:45 2019 (Command '['mavflightview.py --imagefile=/storage/autotest/APM/buildlogs/ArduSub-test.tlog.png /storage/autotest/APM/buildlogs/ArduSub-test.tlog']' returned non-zero exit status 1)
Traceback (most recent call last):
  File "APM/Tools/autotest/autotest.py", line 589, in run_tests
    if run_step(step):
  File "APM/Tools/autotest/autotest.py", line 434, in run_step
    return convert_gpx()
  File "APM/Tools/autotest/autotest.py", line 210, in convert_gpx
    util.run_cmd("mavflightview.py --imagefile=%s.png %s" % (m, m))
  File "/storage/autotest/APM/APM/Tools/autotest/pysim/util.py", line 73, in run_cmd
    return check_call(cmd, shell=shell, cwd=directory)
  File "/usr/lib/python2.7/subprocess.py", line 541, in check_call
    raise CalledProcessError(retcode, cmd)
CalledProcessError: Command '['mavflightview.py --imagefile=/storage/autotest/APM/buildlogs/ArduSub-test.tlog.png /storage/autotest/APM/buildlogs/ArduSub-test.tlog']' returned non-zero exit status 1
check step:  convertgpx
FAILED 9 tests: ['run.examples', 'fly.ArduPlane', 'fly.QuadPlane', 'drive.APMrover2', 'drive.balancebot', 'fly.ArduCopter', 'fly.CopterAVC', 'dive.ArduSub', 'convertgpx']

[peterbarker]

I've installed python-wxgtk3.0 on the server - hopefully that fixes the deps problem.

[peterbarker]

I've merged a fix for not understanding where MAVProxy's files are being put into master.

[jaxxzer]

eyyy! @peterbarker it worked! http://autotest.ardupilot.org/
🎉

There remain only two failing tests now.

[peterbarker]

On Tue, 5 Feb 2019, Jacob Walser wrote: eyyy! @peterbarker it worked! http://autotest.ardupilot.org/ 🎉 There remain only two failing tests now.

I've created another PR to fix some remaining issues: https://github.com/ArduPilot/ardupilot/pull/10422/commits

[peterbarker]

All done. Looking forward to badges so we don't lose track of this again :-)