layer setup failures don't output a failure message (they spew straight to console)

[Robert Collins]

I offer as evidence (straight from the failure log from ec2). This is likely a zope.testing bug, but maybe not, so starting here.

test: canonical.testing.layers.LibrarianLayer:setUp
tags: zope:layer
Traceback (most recent call last):
  File "/var/launchpad/tmp/eggs/zope.testing-3.9.4_p1-py2.5.egg/zope/testing/testrunner/runner.py", line 367, in run_layer
    setup_layer(options, layer, setup_layers)
  File "/var/launchpad/tmp/eggs/zope.testing-3.9.4_p1-py2.5.egg/zope/testing/testrunner/runner.py", line 632, in setup_layer
    layer.setUp()
  File "/var/launchpad/test/lib/canonical/testing/profiled.py", line 25, in profiled_func
    return func(cls, *args, **kw)
  File "/var/launchpad/test/lib/canonical/testing/layers.py", line 565, in setUp
    the_librarian.setUp()
  File "/var/launchpad/test/lib/canonical/librarian/ftests/harness.py", line 100, in setUp
    TacLibrarianTestSetup().setUp()
  File "/var/launchpad/test/lib/canonical/launchpad/daemons/tachandler.py", line 153, in setUp
    % (args, stdout))
TacException: Error running ['/usr/bin/python', '-Wignore::DeprecationWarning', '/var/launchpad/test/bin/twistd', '-o', '-y', '/var/launchpad/test/daemons/librarian.tac', '--pidfile', '/var/tmp/fatsam.test/librarian.pid', '--logfile', '/var/tmp/librarian.log']: unclean stdout/err: Traceback (most recent call last):
  File "/var/launchpad/tmp/eggs/Twisted-10.1.0-py2.5-linux-x86_64.egg/twisted/application/app.py", line 626, in run
    runApp(config)
  File "/var/launchpad/tmp/eggs/Twisted-10.1.0-py2.5-linux-x86_64.egg/twisted/scripts/twistd.py", line 23, in runApp
    _SomeApplicationRunner(config).run()
  File "/var/launchpad/tmp/eggs/Twisted-10.1.0-py2.5-linux-x86_64.egg/twisted/application/app.py", line 374, in run
    self.application = self.createOrGetApplication()
  File "/var/launchpad/tmp/eggs/Twisted-10.1.0-py2.5-linux-x86_64.egg/twisted/application/app.py", line 439, in createOrGetApplication
    application = getApplication(self.config, passphrase)
--- <exception caught here> ---
  File "/var/launchpad/tmp/eggs/Twisted-10.1.0-py2.5-linux-x86_64.egg/twisted/application/app.py", line 450, in getApplication
    application = service.loadApplication(filename, style, passphrase)
  File "/var/launchpad/tmp/eggs/Twisted-10.1.0-py2.5-linux-x86_64.egg/twisted/application/service.py", line 390, in loadApplication
    application = sob.loadValueFromFile(filename, 'application', passphrase)
  File "/var/launchpad/tmp/eggs/Twisted-10.1.0-py2.5-linux-x86_64.egg/twisted/persisted/sob.py", line 210, in loadValueFromFile
    exec fileObj in d, d
  File "/var/launchpad/test/daemons/librarian.tac", line 75, in <module>
    set_up_oops_reporting('librarian', 'librarian')
  File "/var/launchpad/test/lib/lp/services/twistedsupport/loggingsupport.py", line 82, in set_up_oops_reporting
    errorlog.globalErrorUtility.configure(configuration)
  File "/var/launchpad/test/lib/canonical/launchpad/webapp/errorlog.py", line 263, in configure
    self.copy_to_zlog = config[section_name].copy_to_zlog
  File "/var/launchpad/tmp/eggs/lazr.config-1.1.3-py2.5.egg/lazr/config/_config.py", line 222, in __getattr__
    value = super(ImplicitTypeSection, self).__getattr__(name)
  File "/var/launchpad/tmp/eggs/lazr.config-1.1.3-py2.5.egg/lazr/config/_config.py", line 143, in __getattr__
    "No section key named %s." % name)
exceptions.AttributeError: No section key named copy_to_zlog.

Failed to load application: No section key named copy_to_zlog.

time: 2010-07-25 23:49:40.096153Z
test: canonical.testing.layers.DatabaseLayer:setUp

[Gary Poster (gary)]

Robert, I don't understand. That traceback looks like a failure message to me, and suggests what needs to be done to fix it. What's wrong?

[Robert Collins (lifeless)]

It should be captured as a 'test failure' not as a raw traceback: I'd
expect it to look something like:

test: canonical.testing.layers.LibrarianLayer:setUp
tags: zope:layer
failure: canonical.testing.layers.LibrarianLayer:setUp [
 Traceback (most recent call last):
  File "/var/launchpad/tmp/eggs/zope.testing-3.9.4_p1-py2.5.egg/zope/testing/testrunner/runner.py",
line 367, in run_layer
    setup_layer(options, layer, setup_layers)
 ..
]

Note the 'failure: ..' line and the brackets around the traceback.

-Rob

[Robert Collins (lifeless)]

I've tagged this paralleltest because it will impact the ability to get clean results back from the LXC test workers.

[Gary Poster (gary)]

Robert, does "tags: zope:layer" in the excerpt you included indicate that in fact this is doing the right thing, per the discussions we had at the sprint?

[Robert Collins (lifeless)]

No: there are two events emitted for each layer that is setup: a before and an after. these lines:
test: canonical.testing.layers.LibrarianLayer:setUp
tags: zope:layer
are emitted from the before event. The after is never reached (because an exception is thrown).

What needs to happen is that the exception is captured and used to report a 'test failure' of the test 'canonical.testing.layers.LibrarianLayer:setUp' (which is the layer setup). We still to stop the test runner running all the tests that depended on that layer setup working, but a shallow version of fix (just reraise the exception and tweak the runner to depend on the Reporter rather than printing the backtrace itself) is probably ok.

[sidebar: unittest compatible runners would keep running other tests - because tests are isolated etc etc, but that is orthogonal and rather bigger].

[Gary Poster (gary)]

@Robert right, sorry, your previous comment made that clear as well.

[Launchpad QA Bot (lpqabot)]

Fixed in stable r15044 (http://bazaar.launchpad.net/~launchpad-pqm/launchpad/stable/revision/15044) by a commit, but not testable.