ec2 test mail reports SUCCESS when the suite fails

I have not been able to reproduce the failure on any of the reported branches.

For Graham's case the broken test clearly appears in the testrunner log file, but the entire suite still reported SUCCESS:

test: xx-temporary-blob-storage_txt
time: 2010-05-28 12:26:36.103693Z
failure: xx-temporary-blob-storage_txt [ multipart
Content-Type: text/x-traceback;charset=utf8,language=python
traceback
1AD
Failed doctest test for xx-temporary-blob-storage.txt
  File "lib/canonical/launchpad/pagetests/webservice/xx-temporary-blob-storage.txt", line 0

----------------------------------------------------------------------
File "lib/canonical/launchpad/pagetests/webservice/xx-temporary-blob-storage.txt", line 77, in xx-temporary-blob-storage.txt
Failed example:
    job.metadata
Differences (ndiff with -expected +actual):
    + {}
0
]

It appears that whatever ran the doctests failed to communicate that failure to its parent process using an exit code, or whatever ran the doctests may have not noticed the failure in that individual test. The ec2test.remote.SummaryResult object did correctly parse and report the error when it saw it in the output stream, but what the stream parser notices does not affect the test harness' overall outcome.

Here is the most likely culprit: a Traceback begin generated by the test framework itself. That error kills the child testrunner:

test: xx-copy-packages_txt
failure: xx-copy-packages_txt [ multipart
Content-Type: text/x-traceback;charset=utf8,language=python
traceback
Traceback (most recent call last):
  File "/var/launchpad/test/bin/test", line 258, in <module>
    result = testrunner.run([])
  File "/var/launchpad/tmp/eggs/zope.testing-3.9.4_p0-py2.5.egg/zope/testing/testrunner/__init__.py", line 32, in run
    failed = run_internal(defaults, args, script_parts=script_parts)
  File "/var/launchpad/tmp/eggs/zope.testing-3.9.4_p0-py2.5.egg/zope/testing/testrunner/__init__.py", line 45, in run_internal
    runner.run()
  File "/var/launchpad/tmp/eggs/zope.testing-3.9.4_p0-py2.5.egg/zope/testing/testrunner/runner.py", line 138, in run
    self.run_tests()
  File "/var/launchpad/tmp/eggs/zope.testing-3.9.4_p0-py2.5.egg/zope/testing/testrunner/runner.py", line 219, in run_tests
    setup_layers, self.failures, self.errors)
  File "/var/launchpad/tmp/eggs/zope.testing-3.9.4_p0-py2.5.egg/zope/testing/testrunner/runner.py", line 377, in run_layer
    return run_tests(options, tests, layer_name, failures, errors)
  File "/var/launchpad/tmp/eggs/zope.testing-3.9.4_p0-py2.5.egg/zope/testing/testrunner/runner.py", line 309, in run_tests
    test(result)
  File "/usr/lib/python2.5/unittest.py", line 281, in __call__
    return self.run(*args, **kwds)
  File "/usr/lib/python2.5/unittest.py", line 263, in run
    result.addFailure(self, self._exc_info())
  File "/var/launchpad/tmp/eggs/zope.testing-3.9.4_p0-py2.5.egg/zope/testing/testrunner/runner.py", line 719, in addFailure
    exc_info)
  File "/var/launchpad/tmp/eggs/zope.testing-3.9.4_p0-py2.5.egg/zope/testing/testrunner/formatter.py", line 943, in test_failure
    self._subunit.addFailure(test, details=details)
  File "/usr/lib/python2.5/site-packages/subunit/__init__.py", line 599, in addFailure
    self._addOutcome("failure", test, error=error, details=details)
  File "/usr/lib/python2.5/site-packages/subunit/__init__.py", line 624, in _addOutcome
    self._write_details(details)
  File "/usr/lib/python2.5/site-packages/subunit/__init__.py", line 700, in _write_details
    map(encoder.write, content.iter_bytes())
  File "/var/launchpad/tmp/eggs/testtools-0.9.2-py2.5.egg/testtools/content.py", line 38, in iter_bytes
    return self._get_bytes()
  File "/var/launchpad/tmp/eggs/zope.testing-3.9.4_p0-py2.5.egg/zope/testing/testrunner/formatter.py", line 919, in <lambda>
    self.TRACEBACK_CONTENT_TYPE, lambda: [traceback.encode('utf8')])}
UnicodeDecodeError: 'ascii' codec can't decode byte 0xe2 in position 10895: ordinal not in range(128)
test: Could not communicate with subprocess
tags: zope:error_with_banner
successful: Could not communicate with subprocess
test: Running in a subprocess.
tags: zope:info_suboptimal
successful: Running in a subprocess.

I can think of two important questions that still need to be answered:

  1) Why are these intermittent test failures taking place?

  2) Why is the parent testrunner process not failing the suite when it knows that the child process died due to a t...

This was fixed by deploying a patched version of zope.testing. Bug 591309 tracks the upstream fix.

Fixed in stable r10991 <http://bazaar.launchpad.net/~launchpad-pqm/launchpad/stable/revision/10991>

Flagging as untestable: this is a developer tools fix, and can not be tested except by daily use.