[Zope3-dev] buildbot failure in Zope3 trunk 2.4 Linux zc-buildbot

[Tim Peters]

[buildbot at zope.com]
>> The Buildbot has detected a failed build of Zope3 trunk 2.4 Linux
zc-buildbot.

[Benji York]
> This was the ever-popular...
>
>> Error in test testRunIgnoresParentSignals
(zdaemon.tests.testzdrun.ZDaemonTests)
>> Traceback (most recent call last):
>>   File "/usr/lib/python2.4/unittest.py", line 270, in run
>>     self.tearDown()
>>   File "/home/buildbot/slave-zope.org/zc-buildbot--Linux--Zope3---trunk--2.4/build/src/zdaemon/tests/testzdrun.py",
line 76, in tearDown
>>     self.assertEqual(self.expect, output)
>> [...]
>> AssertionError: '' != '\n\nError in test testRunIgnoresParentSignals
>> [...]
>> File "/usr/lib/python2.4/shutil.py", line 162, in rmtree
>>     os.remove(fullname)\nOSError: [Errno 2] No such file or
directory: '/tmp/tmp-7nmMV/testsock'

Failure in testRunIgnoresParentSignals has been depressingly popular,
but I don't think I've ever seen that _specific_ failure mode before. 
The one that was reportedly endlessly over recent months, and which
Jim fixed, ended with this instead:

    AssertionError: spawned process failed to start in a minute

> I've restarted a test run on that machine to see if it fails consistently.

And it doesn't.  I think the new version of this test may be hiding
the real problem, though:  the shutil.rmtree() call is in a top-level
`finally` clause, so if any exception is raised in the body of the
test, then _before_ that exception is reported we get into the
`finally` clause. Then if shutil.rmtree() raises an exception (as it
did in the failing buildbot run), the original exception is lost.

Hmm.  Looks like that includes the case where the new test is trying
to report the old symptom:

            self.assert_(is_started,
                             "spawned process failed to start in a minute")

But I don't think that's what happened in this specific failure: 
os.rmtree(tmp) died with

     No such file or directory: '/tmp/tmp-7nmMV/testsock'

but os.rmtree() wouldn't have _tried_ to delete 'testsock' to begin
with unless os.listdir(tmp)  said 'testsock' was in the temp
directory.  The sanest conclusion I can draw is that some other
process (zdrun?) unlinked 'testsock' between the time os.rmtree() did
its os.listdir() and the time os.rmtree()  tried to unlink 'testsock'
itself.

If so, that's a new race condition in the new version of the test (the
old version of the test didn't try to unlink 'testsock' -- I guess it
left that to zdrun), and can trigger even if the body of the test
passes.