In parallel test runs I often see complaints like the below. For some reason, these sometimes are not consumed by testr as test errors. William Grant, in a launchpad-dev email titled "[Launchpad-dev] memcache errors in ec2 and buildbot -- newer python-memcached to blame?" pointed to a similar error in the non-parallel build: http://paste.ubuntu.com/896153/ . He writes:
> It's behind most of the recent buildbot failures, and is possibly
> related to system load or disk space (it went away for a couple of runs
> after buildbot was aggressively cleaned yesterday).
> python-memcached was upgraded a week ago, so it's tempting to revert it
> to see if it makes things more stable. What do people think?
Deryck and Aaron replied that the upgrade happened to fix bug 954232, and that they'd prefer not to revert it.
Here's the traceback I saw.
Traceback (most recent call last):
File "/var/lib/buildbot/slaves/slave/lucid-devel/build/bin/test", line 278, in <module>
testrunner.run([])
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/__init__.py", line 32, in run
failed = run_internal(defaults, args, script_parts=script_parts)
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/__init__.py", line 45, in run_internal
runner.run()
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/runner.py", line 139, in run
self.run_tests()
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/runner.py", line 220, in run_tests
setup_layers, self.failures, self.errors)
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/runner.py", line 401, in run_layer
return run_tests(options, tests, layer_name, failures, errors)
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/runner.py", line 326, in run_tests
test(result)
File "/usr/lib/python2.6/unittest.py", line 300, in __call__
return self.run(*args, **kwds)
File "/var/lib/buildbot/dependencies/eggs/testtools-0.9.14-py2.6.egg/testtools/testcase.py", line 517, in run
return self.__RunTest(self, self.exception_handlers).run(result)
File "/var/lib/buildbot/dependencies/eggs/testtools-0.9.14-py2.6.egg/testtools/runtest.py", line 74, in run
return self._run_one(actual_result)
File "/var/lib/buildbot/dependencies/eggs/testtools-0.9.14-py2.6.egg/testtools/runtest.py", line 88, in _run_one
return self._run_prepared_result(ExtendedToOriginalDecorator(result))
File "/var/lib/buildbot/dependencies/eggs/testtools-0.9.14-py2.6.egg/testtools/runtest.py", line 96, in _run_prepared_result
result.startTest(self.case)
File "/var/lib/buildbot/dependencies/eggs/testtools-0.9.14-py2.6.egg/testtools/testresult/real.py", line 591, in startTest
return self.decorated.startTest(test)
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/runner.py", line 731, in startTest
self.testSetUp()
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/runner.py", line 716, in testSetUp
layer.testSetUp()
File "/var/lib/buildbot/slaves/slave/lucid-devel/build/lib/lp/services/testing/profiled.py", line 30, in profiled_func
return func(cls, *args, **kw)
File "/var/lib/buildbot/slaves/slave/lucid-devel/build/lib/lp/testing/layers.py", line 650, in testSetUp
MemcachedLayer.client.flush_all()
File "/var/lib/buildbot/dependencies/eggs/python_memcached-1.48-py2.6.egg/memcache.py", line 304, in flush_all
s.expect("OK")
File "/var/lib/buildbot/dependencies/eggs/python_memcached-1.48-py2.6.egg/memcache.py", line 1136, in expect
line = self.readline()
File "/var/lib/buildbot/dependencies/eggs/python_memcached-1.48-py2.6.egg/memcache.py", line 1129, in readline
raise _ConnectionDeadError()
memcache._ConnectionDeadError
Traceback (most recent call last):
File "/var/lib/buildbot/slaves/slave/lucid-devel/build/bin/test", line 278, in <module>
testrunner.run([])
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/__init__.py", line 32, in run
failed = run_internal(defaults, args, script_parts=script_parts)
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/__init__.py", line 45, in run_internal
runner.run()
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/runner.py", line 139, in run
self.run_tests()
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/runner.py", line 220, in run_tests
setup_layers, self.failures, self.errors)
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/runner.py", line 401, in run_layer
return run_tests(options, tests, layer_name, failures, errors)
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/runner.py", line 326, in run_tests
test(result)
File "/usr/lib/python2.6/unittest.py", line 300, in __call__
return self.run(*args, **kwds)
File "/var/lib/buildbot/dependencies/eggs/testtools-0.9.14-py2.6.egg/testtools/testcase.py", line 517, in run
return self.__RunTest(self, self.exception_handlers).run(result)
File "/var/lib/buildbot/dependencies/eggs/testtools-0.9.14-py2.6.egg/testtools/runtest.py", line 74, in run
return self._run_one(actual_result)
File "/var/lib/buildbot/dependencies/eggs/testtools-0.9.14-py2.6.egg/testtools/runtest.py", line 88, in _run_one
return self._run_prepared_result(ExtendedToOriginalDecorator(result))
File "/var/lib/buildbot/dependencies/eggs/testtools-0.9.14-py2.6.egg/testtools/runtest.py", line 96, in _run_prepared_result
result.startTest(self.case)
File "/var/lib/buildbot/dependencies/eggs/testtools-0.9.14-py2.6.egg/testtools/testresult/real.py", line 591, in startTest
return self.decorated.startTest(test)
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/runner.py", line 731, in startTest
self.testSetUp()
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/runner.py", line 716, in testSetUp
layer.testSetUp()
File "/var/lib/buildbot/slaves/slave/lucid-devel/build/lib/lp/services/testing/profiled.py", line 30, in profiled_func
return func(cls, *args, **kw)
File "/var/lib/buildbot/slaves/slave/lucid-devel/build/lib/lp/testing/layers.py", line 650, in testSetUp
MemcachedLayer.client.flush_all()
File "/var/lib/buildbot/dependencies/eggs/python_memcached-1.48-py2.6.egg/memcache.py", line 304, in flush_all
s.expect("OK")
File "/var/lib/buildbot/dependencies/eggs/python_memcached-1.48-py2.6.egg/memcache.py", line 1136, in expect
line = self.readline()
File "/var/lib/buildbot/dependencies/eggs/python_memcached-1.48-py2.6.egg/memcache.py", line 1129, in readline
raise _ConnectionDeadError()
memcache._ConnectionDeadError
Traceback (most recent call last):
File "/var/lib/buildbot/slaves/slave/lucid-devel/build/bin/test", line 278, in <module>
testrunner.run([])
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/__init__.py", line 32, in run
failed = run_internal(defaults, args, script_parts=script_parts)
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/__init__.py", line 45, in run_internal
runner.run()
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/runner.py", line 139, in run
self.run_tests()
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/runner.py", line 220, in run_tests
setup_layers, self.failures, self.errors)
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/runner.py", line 401, in run_layer
return run_tests(options, tests, layer_name, failures, errors)
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/runner.py", line 326, in run_tests
test(result)
File "/usr/lib/python2.6/unittest.py", line 300, in __call__
return self.run(*args, **kwds)
File "/var/lib/buildbot/dependencies/eggs/testtools-0.9.14-py2.6.egg/testtools/testcase.py", line 517, in run
return self.__RunTest(self, self.exception_handlers).run(result)
File "/var/lib/buildbot/dependencies/eggs/testtools-0.9.14-py2.6.egg/testtools/runtest.py", line 74, in run
return self._run_one(actual_result)
File "/var/lib/buildbot/dependencies/eggs/testtools-0.9.14-py2.6.egg/testtools/runtest.py", line 88, in _run_one
return self._run_prepared_result(ExtendedToOriginalDecorator(result))
File "/var/lib/buildbot/dependencies/eggs/testtools-0.9.14-py2.6.egg/testtools/runtest.py", line 96, in _run_prepared_result
result.startTest(self.case)
File "/var/lib/buildbot/dependencies/eggs/testtools-0.9.14-py2.6.egg/testtools/testresult/real.py", line 591, in startTest
return self.decorated.startTest(test)
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/runner.py", line 731, in startTest
self.testSetUp()
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/runner.py", line 716, in testSetUp
layer.testSetUp()
File "/var/lib/buildbot/slaves/slave/lucid-devel/build/lib/lp/services/testing/profiled.py", line 30, in profiled_func
return func(cls, *args, **kw)
File "/var/lib/buildbot/slaves/slave/lucid-devel/build/lib/lp/testing/layers.py", line 650, in testSetUp
MemcachedLayer.client.flush_all()
File "/var/lib/buildbot/dependencies/eggs/python_memcached-1.48-py2.6.egg/memcache.py", line 304, in flush_all
s.expect("OK")
File "/var/lib/buildbot/dependencies/eggs/python_memcached-1.48-py2.6.egg/memcache.py", line 1136, in expect
line = self.readline()
File "/var/lib/buildbot/dependencies/eggs/python_memcached-1.48-py2.6.egg/memcache.py", line 1129, in readline
raise _ConnectionDeadError()
memcache._ConnectionDeadError
Traceback (most recent call last):
File "/var/lib/buildbot/slaves/slave/lucid-devel/build/bin/test", line 278, in <module>
testrunner.run([])
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/__init__.py", line 32, in run
failed = run_internal(defaults, args, script_parts=script_parts)
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/__init__.py", line 45, in run_internal
runner.run()
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/runner.py", line 139, in run
self.run_tests()
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/runner.py", line 220, in run_tests
setup_layers, self.failures, self.errors)
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/runner.py", line 401, in run_layer
return run_tests(options, tests, layer_name, failures, errors)
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/runner.py", line 326, in run_tests
test(result)
File "/usr/lib/python2.6/unittest.py", line 300, in __call__
return self.run(*args, **kwds)
File "/var/lib/buildbot/dependencies/eggs/testtools-0.9.14-py2.6.egg/testtools/testcase.py", line 517, in run
return self.__RunTest(self, self.exception_handlers).run(result)
File "/var/lib/buildbot/dependencies/eggs/testtools-0.9.14-py2.6.egg/testtools/runtest.py", line 74, in run
return self._run_one(actual_result)
File "/var/lib/buildbot/dependencies/eggs/testtools-0.9.14-py2.6.egg/testtools/runtest.py", line 88, in _run_one
return self._run_prepared_result(ExtendedToOriginalDecorator(result))
File "/var/lib/buildbot/dependencies/eggs/testtools-0.9.14-py2.6.egg/testtools/runtest.py", line 96, in _run_prepared_result
result.startTest(self.case)
File "/var/lib/buildbot/dependencies/eggs/testtools-0.9.14-py2.6.egg/testtools/testresult/real.py", line 591, in startTest
return self.decorated.startTest(test)
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/runner.py", line 731, in startTest
self.testSetUp()
File "/var/lib/buildbot/dependencies/eggs/zope.testing-3.9.4_p6-py2.6.egg/zope/testing/testrunner/runner.py", line 716, in testSetUp
layer.testSetUp()
File "/var/lib/buildbot/slaves/slave/lucid-devel/build/lib/lp/services/testing/profiled.py", line 30, in profiled_func
return func(cls, *args, **kw)
File "/var/lib/buildbot/slaves/slave/lucid-devel/build/lib/lp/testing/layers.py", line 650, in testSetUp
MemcachedLayer.client.flush_all()
File "/var/lib/buildbot/dependencies/eggs/python_memcached-1.48-py2.6.egg/memcache.py", line 304, in flush_all
s.expect("OK")
File "/var/lib/buildbot/dependencies/eggs/python_memcached-1.48-py2.6.egg/memcache.py", line 1136, in expect
line = self.readline()
File "/var/lib/buildbot/dependencies/eggs/python_memcached-1.48-py2.6.egg/memcache.py", line 1129, in readline
raise _ConnectionDeadError()
memcache._ConnectionDeadError
We recently upgraded python-memcached from 1.45 to 1.48 (it looks like 1.49 was available at the time but not used).
The fix for bug 728359 directly affected the readline method and introduced the _ConnectionDead
Previously, under those conditions readline() simply returned None. Now it raises an exception. In two places (_get() and _set()) that exception is caught and a retry is performed. Unfortunately, many other places in memcache.py call readline() but do not handle the exception.
The path that we're experiencing is the expect() method. In 1.45 if the socket were closed, readline() would return None, the expected values wouldn't match, and a message was written to the debug log but there were no other ill effects.
Now we get this exception propagated.
It appears to me the fix for bug 728359 was not implemented thoroughly and has left python-memcached in state where exceptions can escape that were not intended, as indicated by the name _ConnectionDead