under some circumstances getLastOopsReport returns the wrong report

Bug #640007 reported by Robert Collins
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Launchpad itself
Fix Released
High
Robert Collins

Bug Description

E.g. at the moment we're seeing:

======================================================================
FAILURE: lp.services.job.tests.test_runner.TestJobRunner.test_oops_messages_used_when_handling (subunit.RemotedTestCase)
----------------------------------------------------------------------
_StringException: Text attachment: traceback
------------
Traceback (most recent call last):
_StringException: Text attachment: oops-0
------------
Oops-Id: OOPS-1719T4
Exception-Type: ValueError
Exception-Value: Fake exception. Foobar, I say!
Date: 2010-09-15T11:08:20.557672+00:00
Page-Id:
Branch: test
Revision: 11551
User: None
URL: None
Duration: -1
Informational: True

%3Coops-message-12%3E=%7B%27foo%27: %27bar%27%7D

56926-56933@librarian-connection http://localhost:58000/94/2572BxOvgNERmSshwjMvUm9YIVz.msg
56933-56933@librarian-read http://localhost:58000/94/2572BxOvgNERmSshwjMvUm9YIVz.msg
196815-196822@librarian-connection http://localhost:58005/93/81ceeb46-c0b8-11df-b266-12313b0a9967.txt
196823-196823@librarian-read http://localhost:58005/93/81ceeb46-c0b8-11df-b266-12313b0a9967.txt
198285-198292@librarian-connection http://localhost:58005/93/82af873c-c0b8-11df-b266-12313b0a9967.txt
198293-198293@librarian-read http://localhost:58005/93/82af873c-c0b8-11df-b266-12313b0a9967.txt
200020-200027@librarian-connection http://localhost:58005/93/83b820ee-c0b8-11df-b266-12313b0a9967.txt
200027-200027@librarian-read http://localhost:58005/93/83b820ee-c0b8-11df-b266-12313b0a9967.txt
214274-214281@librarian-connection http://localhost:58005/93/8c371f54-c0b8-11df-b266-12313b0a9967.txt
214281-214281@librarian-read http://localhost:58005/93/8c371f54-c0b8-11df-b266-12313b0a9967.txt
262782-262789@librarian-connection http://localhost:58000/93/foo.pot
262790-262790@librarian-read http://localhost:58000/93/foo.pot
272154-272161@librarian-connection http://localhost:58000/93/%2A
272162-272162@librarian-read http://localhost:58000/93/%2A
272165-272169@librarian-connection http://localhost:58000/93/%2A
272169-272169@librarian-read http://localhost:58000/93/%2A
274229-274236@librarian-connection http://localhost:58000/93/%2A
274237-274237@librarian-read http://localhost:58000/93/%2A
291253-291260@librarian-connection http://localhost:58005/93/ba178b20-c0b8-11df-b266-12313b0a9967.txt
291260-291260@librarian-read http://localhost:58005/93/ba178b20-c0b8-11df-b266-12313b0a9967.txt
299006-299013@librarian-connection http://localhost:58005/93/beb8e228-c0b8-11df-b266-12313b0a9967.txt
299013-299013@librarian-read http://localhost:58005/93/beb8e228-c0b8-11df-b266-12313b0a9967.txt
301813-301820@librarian-connection http://localhost:58005/93/c0646eee-c0b8-11df-b266-12313b0a9967.txt
301821-301821@librarian-read http://localhost:58005/93/c0646eee-c0b8-11df-b266-12313b0a9967.txt
301821-301825@librarian-connection http://localhost:58005/93/c0646eee-c0b8-11df-b266-12313b0a9967.txt
301825-301825@librarian-read http://localhost:58005/93/c0646eee-c0b8-11df-b266-12313b0a9967.txt
301826-301829@librarian-connection http://localhost:58005/93/c0646eee-c0b8-11df-b266-12313b0a9967.txt
301829-301829@librarian-read http://localhost:58005/93/c0646eee-c0b8-11df-b266-12313b0a9967.txt
305236-305243@librarian-connection http://localhost:58005/93/c26eb514-c0b8-11df-b266-12313b0a9967.txt
305243-305243@librarian-read http://localhost:58005/93/c26eb514-c0b8-11df-b266-12313b0a9967.txt
305243-305246@librarian-connection http://localhost:58005/93/c26eb514-c0b8-11df-b266-12313b0a9967.txt
305247-305247@librarian-read http://localhost:58005/93/c26eb514-c0b8-11df-b266-12313b0a9967.txt
306098-306105@librarian-connection http://localhost:58005/93/c2f3dd8e-c0b8-11df-b266-12313b0a9967.txt
306106-306106@librarian-read http://localhost:58005/93/c2f3dd8e-c0b8-11df-b266-12313b0a9967.txt
552570-552577@librarian-connection http://localhost:58005/93/55db1bee-c0b9-11df-b266-12313b0a9967.txt
552577-552577@librarian-read http://localhost:58005/93/55db1bee-c0b9-11df-b266-12313b0a9967.txt

Traceback (most recent call last):
 Module lp.services.job.tests.test_runner, line 191, in handleError
   raise ValueError('Fake exception. Foobar, I say!')
ValueError: Fake exception. Foobar, I say!
------------
Text attachment: traceback
------------
Traceback (most recent call last):
 File "/var/launchpad/tmp/eggs/testtools-0.9.6-py2.6.egg/testtools/runtest.py", line 144, in _run_user
   return fn(*args)
 File "/var/launchpad/tmp/eggs/testtools-0.9.6-py2.6.egg/testtools/testcase.py", line 465, in _run_test_method
   testMethod()
 File "/var/launchpad/test/lib/lp/services/job/tests/test_runner.py", line 200, in test_oops_messages_used_when_handling
   self.assertEqual("{'foo': 'bar'}", oops.req_vars[0][1])
 File "/var/launchpad/tmp/eggs/testtools-0.9.6-py2.6.egg/testtools/testcase.py", line 244, in assertEqual
   self.fail('\n'.join(lines))
AssertionError: not equal:
a = "{'foo': 'bar'}"
b = 'Exception while processing upload /tmp/tmpxh1U7k/incoming/foocomm_1.0-1_proposed'

You can see here that the self.oopses captured oops is the right one, but getLastOopsReport is returning something different (possibly older, possibly newer, who knows). Running just those two tests together doesn't reproduce this.

Revision history for this message
Robert Collins (lifeless) wrote :

Working around by removing these uses of getLastOopsReport for a better use, but its likely to pop up again the next time test order is permuted by test ordering.

Revision history for this message
Robert Collins (lifeless) wrote :

It could also be that generation is broken; but both ways are bad.

Gary Poster (gary)
Changed in launchpad-foundations:
status: New → Triaged
importance: Undecided → Medium
Revision history for this message
Robert Collins (lifeless) wrote :

More info: getLastOopsReport returns oopses from a previous test. This leads to insidious test false-positives:
consider testA and testB that both want to raise an OOPS, a similar looking OOPS.

This OOPS will make both testA and testB pass, and if testA is always run before testB, testB does not *need* to actually raise an OOPS to pass, as it will get the one from testA.

Changed in launchpad:
importance: Medium → High
Revision history for this message
Robert Collins (lifeless) wrote :

(Filling in a missed step for clarity:)
If testB stops actually OOPSing, then it will keep passing until we:
 - run it own its own
 - e.g. when parallel testing

tags: added: paralleltest spurious-test-failure test-system
removed: lp-foundations
Revision history for this message
Robert Collins (lifeless) wrote :

(I know the original report seems slightly contradictory - I believe this to be me getting the analysis slightly wrong at the time. Or something like that).

Simple test isolation is a plausible explanation and one demonstrated correct in bug 825486.

Revision history for this message
Robert Collins (lifeless) wrote :

I deleted the code.
\o/

Changed in launchpad:
assignee: nobody → Robert Collins (lifeless)
status: Triaged → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.