wait_for and run_in_reactor swallow exceptions

[hynek]

Consider the following code:

from __future__ import absolute_import, division, print_function

from crochet import no_setup, wait_for, run_in_reactor

no_setup()

from twisted.trial import unittest as unittest_twisted
import unittest as unittest_stdlib


class C(object):
    @wait_for(1)
    def wait_for(self):
        raise Exception

    @run_in_reactor
    def run_in_reactor(self):
        raise Exception

    def vanilla(self):
        raise Exception


class TestStdLib(unittest_stdlib.TestCase):
    def test_wait_for(self):
        C().wait_for()

    def test_run_in_reactor(self):
        C().run_in_reactor()

    def test_vanilla(self):
        C().vanilla()


class TestTwistedDefault(unittest_twisted.TestCase):
    def test_wait_for(self):
        C().wait_for()

    def test_run_in_reactor(self):
        C().run_in_reactor()

    def test_vanilla(self):
        C().vanilla()


class TestTwistedSync(unittest_twisted.SynchronousTestCase):
    def test_wait_for(self):
        C().wait_for()

    def test_run_in_reactor(self):
        C().run_in_reactor()

    def test_vanilla(self):
        C().vanilla()

The output of running it with trial on Python 2.7.8 (OS X) is as following:

test_t
  TestStdLib
    test_run_in_reactor ...                                                [OK]
    test_vanilla ...                                                    [ERROR]
    test_wait_for ...                                                   [ERROR]
  TestTwistedDefault
    test_run_in_reactor ...                                             [ERROR]
                                            [ERROR]
    test_vanilla ...                                                    [ERROR]
    test_wait_for ...                                                   [ERROR]
                                                  [ERROR]
  TestTwistedSync
    test_run_in_reactor ...                                                [OK]
    test_vanilla ...                                                    [ERROR]
    test_wait_for ...                                                   [ERROR]

===============================================================================
[ERROR]
Traceback (most recent call last):
  File "/Users/hynek/.pyenv/versions/2.7.8/lib/python2.7/unittest/case.py", line 329, in run
    testMethod()
  File "/Users/hynek/Projects/ssce/test_t.py", line 32, in test_vanilla
    C().vanilla()
  File "/Users/hynek/Projects/ssce/test_t.py", line 21, in vanilla
    raise Exception
exceptions.Exception: 

test_t.TestStdLib.test_vanilla
===============================================================================
[ERROR]
Traceback (most recent call last):
  File "/Users/hynek/.pyenv/versions/2.7.8/lib/python2.7/unittest/case.py", line 329, in run
    testMethod()
  File "/Users/hynek/Projects/ssce/test_t.py", line 26, in test_wait_for
    C().wait_for()
  File "/Users/hynek/.virtualenvs/sscce/lib/python2.7/site-packages/crochet/_eventloop.py", line 461, in wrapper
    return eventual_result.wait(timeout)
  File "/Users/hynek/.virtualenvs/sscce/lib/python2.7/site-packages/crochet/_eventloop.py", line 229, in wait
    result = self._result(timeout)
  File "/Users/hynek/.virtualenvs/sscce/lib/python2.7/site-packages/crochet/_eventloop.py", line 193, in _result
    raise TimeoutError()
crochet._eventloop.TimeoutError: 

test_t.TestStdLib.test_wait_for
===============================================================================
[ERROR]
Traceback (most recent call last):
  File "/Users/hynek/.virtualenvs/sscce/lib/python2.7/site-packages/twisted/internet/defer.py", line 140, in maybeDeferred
    result = f(*args, **kw)
  File "/Users/hynek/Projects/ssce/test_t.py", line 18, in run_in_reactor
    raise Exception
exceptions.Exception: 

test_t.TestTwistedDefault.test_run_in_reactor
test_t.TestTwistedDefault.test_run_in_reactor
===============================================================================
[ERROR]
Traceback (most recent call last):
  File "/Users/hynek/Projects/ssce/test_t.py", line 43, in test_vanilla
    C().vanilla()
  File "/Users/hynek/Projects/ssce/test_t.py", line 21, in vanilla
    raise Exception
exceptions.Exception: 

test_t.TestTwistedDefault.test_vanilla
===============================================================================
[ERROR]
Traceback (most recent call last):
  File "/Users/hynek/Projects/ssce/test_t.py", line 37, in test_wait_for
    C().wait_for()
  File "/Users/hynek/.virtualenvs/sscce/lib/python2.7/site-packages/crochet/_eventloop.py", line 461, in wrapper
    return eventual_result.wait(timeout)
  File "/Users/hynek/.virtualenvs/sscce/lib/python2.7/site-packages/crochet/_eventloop.py", line 229, in wait
    result = self._result(timeout)
  File "/Users/hynek/.virtualenvs/sscce/lib/python2.7/site-packages/crochet/_eventloop.py", line 193, in _result
    raise TimeoutError()
crochet._eventloop.TimeoutError: 

test_t.TestTwistedDefault.test_wait_for
===============================================================================
[ERROR]
Traceback (most recent call last):
  File "/Users/hynek/.virtualenvs/sscce/lib/python2.7/site-packages/twisted/internet/defer.py", line 140, in maybeDeferred
    result = f(*args, **kw)
  File "/Users/hynek/.virtualenvs/sscce/lib/python2.7/site-packages/crochet/_eventloop.py", line 458, in run
    return function(*args, **kwargs)
  File "/Users/hynek/Projects/ssce/test_t.py", line 14, in wait_for
    raise Exception
exceptions.Exception: 

test_t.TestTwistedDefault.test_wait_for
===============================================================================
[ERROR]
Traceback (most recent call last):
  File "/Users/hynek/Projects/ssce/test_t.py", line 54, in test_vanilla
    C().vanilla()
  File "/Users/hynek/Projects/ssce/test_t.py", line 21, in vanilla
    raise Exception
exceptions.Exception: 

test_t.TestTwistedSync.test_vanilla
===============================================================================
[ERROR]
Traceback (most recent call last):
  File "/Users/hynek/Projects/ssce/test_t.py", line 48, in test_wait_for
    C().wait_for()
  File "/Users/hynek/.virtualenvs/sscce/lib/python2.7/site-packages/crochet/_eventloop.py", line 461, in wrapper
    return eventual_result.wait(timeout)
  File "/Users/hynek/.virtualenvs/sscce/lib/python2.7/site-packages/crochet/_eventloop.py", line 229, in wait
    result = self._result(timeout)
  File "/Users/hynek/.virtualenvs/sscce/lib/python2.7/site-packages/crochet/_eventloop.py", line 193, in _result
    raise TimeoutError()
crochet._eventloop.TimeoutError: 

test_t.TestTwistedSync.test_wait_for
-------------------------------------------------------------------------------
Ran 9 tests in 3.020s

FAILED (errors=9, successes=2)

The output is the same on pypy.

I hope this is helpful.

[itamarst]

I've never tested crochet on OS X... what does running the test suite tell you?

[hynek]

Tests pass skipping test_non_posix ... [SKIPPED] with a rather non-sensical skip message of SIGCHLD is a POSIX-specific issue.

[itamarst]

That message could be better, I guess, but that's expected output.

[itamarst]

OK, first problem with this example code is that you're calling no_setup(): that's wrong. Trial doesn't really run the reactor in a useful way, so you need crochet to run it for you.

[itamarst]

Once I switch no_setup() to setup() I get pretty much what is expected: no timeout errors, just Exceptions.

Also note that methods decorated with run_in_reactor are async, so if you want to extract the exception you have to do something like C().run_in_reactor().wait(timeout=1).

[itamarst]

If you change no_setup() to setup() does that fix your issue?

[hynek]

Yes and no: if I do that, I’ll get a fat traceback that reactor is already running.

If I do neither, I get:

Traceback (most recent call last):
  File "/Users/hynek/Work/txepp/tests/test_sync_wrapper.py", line 35, in test_domain_check
    ssp.domain_check(["test.com"])
  File "/Users/hynek/Work/txepp/.tox/py27/lib/python2.7/site-packages/crochet/_eventloop.py", line 459, in wrapper
    eventual_result = run()
  File "/Users/hynek/Work/txepp/.tox/py27/lib/python2.7/site-packages/crochet/_eventloop.py", line 421, in wrapper
    result = EventualResult(None, self._reactor)
exceptions.AttributeError: 'EventLoop' object has no attribute '_reactor'

[itamarst]

How are you running tests - what command line? What version of trial?

[dpnova]

Somewhat seems to be related to what I'm seeing.

I'm actually trying to run tests in trial that test code which is decorated by wait_for.

Without any setup I get the error pasted by @hynek on the 11th Feb.

With no_setup() the decorator blocks regardless as to whether the decorated function returns a deferred or not. When I ctrl-c I get this traceback:

[ERROR]
Traceback (most recent call last):
  File "/home/dpn/.virtualenvs/inbox-api/lib/python2.7/site-packages/mock.py", line 1201, in patched
    return func(*args, **keywargs)
  File "/home/dpn/workspace/inbox-api/inboxadmin/views/tests/test_home.py", line 28, in test_get_url_info
    return get_url_info("http://example.com")
  File "/home/dpn/.virtualenvs/inbox-api/lib/python2.7/site-packages/crochet/_eventloop.py", line 461, in wrapper
    return eventual_result.wait(timeout)
  File "/home/dpn/.virtualenvs/inbox-api/lib/python2.7/site-packages/crochet/_eventloop.py", line 229, in wait
    result = self._result(timeout)
  File "/home/dpn/.virtualenvs/inbox-api/lib/python2.7/site-packages/crochet/_eventloop.py", line 189, in _result
    self._result_set.wait(timeout)
  File "/usr/lib64/python2.7/threading.py", line 621, in wait
    self.__cond.wait(timeout)
  File "/usr/lib64/python2.7/threading.py", line 359, in wait
    _sleep(delay)
exceptions.KeyboardInterrupt: 

If I use setup() I get the following debug traceback:

[ERROR]
Traceback (most recent call last):
Failure: twisted.trial.util.DirtyReactorAggregateError: Reactor was unclean.
DelayedCalls: (set twisted.internet.base.DelayedCall.debug = True to debug)
<DelayedCall 0x7f86ff2c53f8 [0.0817131996155s] called=0 cancelled=0 LoopingCall<0.1>(reapAllProcesses, *(), **{})()

traceback at creation: 

  File "/usr/lib64/python2.7/threading.py", line 783, in __bootstrap
    self.__bootstrap_inner()
      File "/usr/lib64/python2.7/threading.py", line 810, in __bootstrap_inner
    self.run()
      File "/usr/lib64/python2.7/threading.py", line 763, in run
    self.__target(*self.__args, **self.__kwargs)
      File "/home/dpn/.virtualenvs/inbox-api/lib/python2.7/site-packages/crochet/_eventloop.py", line 382, in <lambda>
    target=lambda: self._reactor.run(installSignalHandlers=False),
      File "/home/dpn/.virtualenvs/inbox-api/lib/python2.7/site-packages/twisted/internet/base.py", line 1192, in run
    self.mainLoop()
      File "/home/dpn/.virtualenvs/inbox-api/lib/python2.7/site-packages/twisted/internet/base.py", line 1201, in mainLoop
    self.runUntilCurrent()
      File "/home/dpn/.virtualenvs/inbox-api/lib/python2.7/site-packages/twisted/internet/base.py", line 797, in runUntilCurrent
    f(*a, **kw)
      File "/home/dpn/.virtualenvs/inbox-api/lib/python2.7/site-packages/crochet/_eventloop.py", line 335, in _startReapingProcesses
    lc.start(0.1, False)
      File "/home/dpn/.virtualenvs/inbox-api/lib/python2.7/site-packages/twisted/internet/task.py", line 175, in start
    self._reschedule()
      File "/home/dpn/.virtualenvs/inbox-api/lib/python2.7/site-packages/twisted/internet/task.py", line 243, in _reschedule
    self.call = self.clock.callLater(nextTime - currentTime, self)
>

Going to continue playing..

[itamarst]

I suggest not using twisted.trial.unittest.TestCase as base class when when writing crochet related tests, and specifically when you're testing the blocking APIs. Use unittest.TestCase or twisted.trial.unittest.SynchronousTestCase.

[dpnova]

Actually @itamarst I totally misread the doc about wrapped_function - that's working as expected with no_setup() now!

But, duly noted about not using the async test case.. thanks :)