lp.services.job.tests.test_runner.TestJobRunner.test_runJobHandleErrors_oops_generated_notify_fails fails intermittently/rarely on parallel tests

[Gary Poster]

======================================================================
FAILURE: lp.services.job.tests.test_runner.TestJobRunner.test_runJobHandleErrors_oops_generated_notify_fails
worker ID: worker-3
----------------------------------------------------------------------
Traceback (most recent call last):
_StringException: librarian-log: {{{
2012-05-01 05:48:45+0530 [-] Log opened.
2012-05-01 05:48:45+0530 [-] twistd 11.1.0 (/usr/bin/python2.6 2.6.5) starting up.
2012-05-01 05:48:45+0530 [-] reactor class: twisted.internet.pollreactor.PollReactor.
2012-05-01 05:48:45+0530 [-] FileUploadFactory starting on 59093
2012-05-01 05:48:45+0530 [-] Starting factory <lp.services.librarianserver.libraryprotocol.FileUploadFactory instance at 0xac5b06c>
2012-05-01 05:48:45+0530 [-] Site starting on 40850
2012-05-01 05:48:45+0530 [-] Starting factory <twisted.web.server.Site instance at 0xac5b1ac>
2012-05-01 05:48:45+0530 [-] FileUploadFactory starting on 58141
2012-05-01 05:48:45+0530 [-] Starting factory <lp.services.librarianserver.libraryprotocol.FileUploadFactory instance at 0xac5b34c>
2012-05-01 05:48:45+0530 [-] Site starting on 53817
2012-05-01 05:48:45+0530 [-] Starting factory <twisted.web.server.Site instance at 0xac5b4cc>
2012-05-01 05:48:45+0530 [-] Not using upstream librarian
2012-05-01 05:48:45+0530 [-] daemon ready!
}}}

oops-0: {{{
Oops-Id: OOPS-14580a505b0d2fa7f1bc1419c281ba45
Exception-Type: RaisingJobException
Exception-Value: boom
Date: 2012-05-01T00:20:17.283302+00:00
Branch: devel
Revision: 15181
Duration: -1
Oops-Reporter: T

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

00000-00003@memcache-set MemcachedLayer__live_test
00080-00083@memcache-set MemcachedLayer__live_test
00184-00186@memcache-set MemcachedLayer__live_test
17202-17215@librarian-connection http://localhost:40850/95/foo_666.dsc
17216-17216@librarian-read http://localhost:40850/95/foo_666.dsc
17217-17217@librarian-read http://localhost:40850/95/foo_666.dsc
24119-24132@librarian-connection http://localhost:40850/94/filename-100308
24132-24133@librarian-read http://localhost:40850/94/filename-100308
50762-50775@librarian-connection http://localhost:40850/97/firefox_1.1_source.changes
50776-50776@librarian-read http://localhost:40850/97/firefox_1.1_source.changes
53591-53610@librarian-connection http://localhost:40850/95/foo_666.dsc
53611-53612@librarian-read http://localhost:40850/95/foo_666.dsc
53612-53612@librarian-read http://localhost:40850/95/foo_666.dsc
53633-53639@librarian-connection http://localhost:40850/96/foo-bin_666_all.deb
53639-53640@librarian-read http://localhost:40850/96/foo-bin_666_all.deb
53640-53640@librarian-read http://localhost:40850/96/foo-bin_666_all.deb

Traceback (most recent call last):
  Module lazr.jobrunner.jobrunner, line 194, in runJobHandleError
    self.runJob(job, fallback)
  Module lp.services.job.runner, line 255, in runJob
    super(BaseJobRunner, self).runJob(IRunnableJob(job), fallback)
  Module lazr.jobrunner.jobrunner, line 162, in runJob
    job.run()
  Module lp.services.job.tests.test_runner, line 107, in run
    raise RaisingJobException(self.message)
RaisingJobException: boom
}}}

oops-1: {{{
Oops-Id: OOPS-6be8185274f05a0098b7df4de4fab21e
Exception-Type: RaisingJobException
Exception-Value: oops notifying oops
Date: 2012-05-01T00:20:17.292009+00:00
Branch: devel
Revision: 15181
URL: None
Duration: -1
Oops-Reporter: T

%3Coops-message-0%3E=%7B%27foo%27: %27bar%27%7D
%3Coops-message-1%3E=Failure in _doOops: oops notifying oops
path=/var/lib/buildbot/slaves/slave/lucid-devel/build/bin/test
script_name=publishftpmaster

00000-00003@memcache-set MemcachedLayer__live_test
00080-00083@memcache-set MemcachedLayer__live_test
00184-00186@memcache-set MemcachedLayer__live_test
17202-17215@librarian-connection http://localhost:40850/95/foo_666.dsc
17216-17216@librarian-read http://localhost:40850/95/foo_666.dsc
17217-17217@librarian-read http://localhost:40850/95/foo_666.dsc
24119-24132@librarian-connection http://localhost:40850/94/filename-100308
24132-24133@librarian-read http://localhost:40850/94/filename-100308
50762-50775@librarian-connection http://localhost:40850/97/firefox_1.1_source.changes
50776-50776@librarian-read http://localhost:40850/97/firefox_1.1_source.changes
53591-53610@librarian-connection http://localhost:40850/95/foo_666.dsc
53611-53612@librarian-read http://localhost:40850/95/foo_666.dsc
53612-53612@librarian-read http://localhost:40850/95/foo_666.dsc
53633-53639@librarian-connection http://localhost:40850/96/foo-bin_666_all.deb
53639-53640@librarian-read http://localhost:40850/96/foo-bin_666_all.deb
53640-53640@librarian-read http://localhost:40850/96/foo-bin_666_all.deb

Traceback (most recent call last):
  Module lazr.jobrunner.jobrunner, line 202, in runJobHandleError
    return self._doOops(job, info)
  Module lp.services.job.runner, line 268, in _doOops
    job.notifyOops(oops)
  Module lp.services.job.tests.test_runner, line 110, in notifyOops
    raise RaisingJobException('oops notifying oops')
RaisingJobException: oops notifying oops
}}}

oops-2: {{{
Oops-Id: OOPS-b65ae53fb09bf20bdf600717dde6549d
Exception-Type: RaisingJobException
Exception-Value: oops notifying oops
Date: 2012-05-01T00:20:17.295780+00:00
Branch: devel
Revision: 15181
Duration: -1
Oops-Reporter: T

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

Traceback (most recent call last):
  Module lazr.jobrunner.jobrunner, line 202, in runJobHandleError
    return self._doOops(job, info)
  Module lp.services.job.runner, line 268, in _doOops
    job.notifyOops(oops)
  Module lp.services.job.tests.test_runner, line 110, in notifyOops
    raise RaisingJobException('oops notifying oops')
RaisingJobException: oops notifying oops
}}}

Traceback (most recent call last):
  File "/var/lib/buildbot/slaves/slave/lucid-devel/build/lib/lp/services/job/tests/test_runner.py", line 355, in test_runJobHandleErrors_oops_generated_notify_fails
    self.assertEqual(2, len(self.oopses))
MismatchError: 2 != 3

Worker 3's list of tests: http://pastebin.ubuntu.com/958899/

[Gary Poster (gary)]

I can reliably reproduce this error in a Lucid LXC container with ./bin/test --load-list tests.txt if tests.txt contains these two tests:

lp.archivepublisher.tests.test_publish_ftpmaster.TestPublishFTPMasterScript.test_getDirtySuites_ignores_suites_without_pending_publications
lp.services.job.tests.test_runner.TestJobRunner.test_runJobHandleErrors_oops_generated_notify_fails

(The test passes by itself.)

[Benji York (benji)]

It turns out that this bug can be fixed in the same way as 992692, so I'm marking this bug as a duplicate of it.