[Twisted-Python] Weird PyPY twisted.internet.defer.TimeoutError ERROR*12 during full test run

[Tristan Seligmann]

On Sat, 5 Aug 2017 at 00:44 Daniel Sutcliffe <dansut at gmail.com> wrote:

> For the buildbot:
> https://buildbot.twistedmatrix.com/builders/ubuntu16.04-pypy5/
> they seem to pretty much consistently happen during:
>   twisted.protocols.test.test_tls.TLSMemoryBIOTests.test_hugeWrite_TLSv1_1
> but running in my own environment(s) I also always see the 12
> TimoutError but they can occur in a variety of different tests, I've
> seen them in these as well as the above:
>    twisted.news.test.test_news.NewsTests.testArticleRequest
>    twisted.names.test.test_server.DNSServerFactoryTests.test_verboseDefault
>
>  twisted.positioning.test.test_nmea.BrokenSentenceCallbackTests.test_dontSwallowCallbackException
> and a bunch of others.
>

This kind of timeout usually means that the test is waiting for some event,
and due to an event ordering that wasn't expected, the event never happens;
for example, it might have already happened before you start waiting for
it, or it might not happen at all due to an error.

Sometimes this means that the test is really stuck, but often it means that
an error has occurred but was not handled by the test, so you get an error
(maybe logged, maybe not) but also the test never ends.

Always exactly 12 and always during same test for a single test run.
> I've not been able to reproduce running anything but the full
> testsuite - but they have always occured for me during full run.
>
> Just wondered if anybody with more experience had a clue/idea as to
> why this could happen (why 12), and how I could go about tracking down
> the root cause.
>

Look for missing error handling in the test to see if an error is occurring
that the test does not notice; if you're lucky, these errors may have been
logged (check test.log). If not, you may need to improve the error handling
and / or play around in a debugger.

If the test really is stuck, a common cause of PyPy vs CPython issues is
garbage collection or weakref callbacks happening in an unpredictable
ordering of events. I haven't looked at the tests in question but I would
check for things like __del__ methods (eg. files not being closed
explicitly) or weakref use in the vicinity.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: </pipermail/twisted-python/attachments/20170805/ae2040ad/attachment-0002.html>