eliot icon indicating copy to clipboard operation
eliot copied to clipboard

Tracebacks going through `eliot.twisted.inline_callbacks` lose some important frames at the end

Open exarkun opened this issue 4 years ago • 8 comments

Consider:

from eliot.twisted import inline_callbacks
from twisted.internet.defer import fail

@inline_callbacks
def foo():
    yield
    yield bar()

@inline_callbacks
def bar():
    yield
    raise Exception("Some problem")

foo()

This results in the following output:

$ python2 eliot-tb-example.py 
Unhandled error in Deferred:

Traceback (most recent call last):
  File "eliot-tb-example.py", line 15, in <module>
    foo()
  File ".../twisted/internet/defer.py", line 1613, in unwindGenerator
    return _cancellableInlineCallbacks(gen)
  File ".../twisted/internet/defer.py", line 1529, in _cancellableInlineCallbacks
    _inlineCallbacks(None, g, status)
--- <exception caught here> ---
  File ".../twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File ".../twisted/python/failure.py", line 512, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File ".../eliot/_generators.py", line 141, in wrapper
    value_out = gen.throw(*value_in)
  File "eliot-tb-example.py", line 8, in foo
    yield bar()
  File ".../eliot/_generators.py", line 160, in wrapper
    value_in = yield value_out
exceptions.Exception: Some problem

The 2nd to last frame looks correct to me - line 8 in foo - but the subsequent frame - line 160 in wrapp is wrong. It should be line line 13 in bar.

exarkun avatar Feb 19 '20 13:02 exarkun

Looks like an issue in Python 3 as well. Insofar as this get fixed (I will try to, or would be happy to accept PR), it's only going to be fixed in newer releases, though, so it won't work on Python 2.

itamarst avatar Feb 19 '20 14:02 itamarst

Yea, that's more or less what I expected. Depending on what the fix looks like, I might try to put in some time backporting it, though whether that's something that makes it into a new Eliot 1.7.x release or if I have to put it elsewhere, I dunno? Any thoughts on that?

exarkun avatar Feb 19 '20 14:02 exarkun

(Maybe too early to say, I have no idea what the fix is going to look like.)

exarkun avatar Feb 19 '20 14:02 exarkun

I'm... not really sure what's going on apriori. We catch the exception, yes, but then we throw it again through the generator with the same traceback. So oughtn't do the right thing?

itamarst avatar Feb 19 '20 14:02 itamarst

I can do a 1.7.1 release, given a backported PR.

itamarst avatar Feb 19 '20 14:02 itamarst

I'm really hoping, BTW, to eventually be able to rip out all the Twisted-specific code and rely on https://github.com/twisted/twisted/pull/1192

Haven't tested that, though, so not sure how well it works compared to current solution.

itamarst avatar Feb 19 '20 14:02 itamarst

I think this is at least partially an issue with twisted. If I remove this line, then the correct traceback is printed. Thus, it looks like it happens when an error happens synchronously, as the inner function returns an already failed deferred, which thus has its failure cleaned.

It looks like the reason it works without eliot's wrapper is that Failure digs around in the traceback to find the Failure object an exception corresponds to, and merges the tracebacks of the two.

tomprince avatar Jun 30 '21 20:06 tomprince

Haven't tested that, though, so not sure how well it works compared to current solution

Changing https://github.com/itamarst/eliot/blob/8609d380866491abe9e97eb814e4a04478b5893e/eliot/_generators.py#L111 to be

value_out = go()

makes the twisted tests still pass. (Though as mentioned in #472, it would be good to keep that code around for other reasons.

tomprince avatar Jul 14 '21 23:07 tomprince