[Async-sig] task.result() and exception traceback display

[Chris Jerdonek]

On Mon, Dec 25, 2017 at 12:48 AM, Nathaniel Smith <njs at pobox.com> wrote:
> I haven't thought about this enough to have an opinion about whether
> this is correct or how it could be improved, but I can explain why
> you're seeing what you're seeing :-).
>
> The traceback is really a trace of where the exception went after it
> was raised, with new lines added to the top as it bubbles out. So the
> bottom line is the 'raise' statement, because that's where it was
> created, and then it bubbled onto the 'call 1' line and was caught.
> Then it was raised again and bubbled onto the 'call 2' line. Etc. So
> you should think of it not as a snapshot of your stack when it was
> created, but as a travelogue.

Thanks, Nathaniel.  That's a really good explanation.

Also, here's a way to see the same behavior without async:

    def main():
        exc = ValueError()

        try:
            raise exc  # call 1
        except Exception:
            pass

        try:
            raise exc  # call 2
        except Exception:
            pass

        raise exc  # call 3

    main()

With this, the traceback looks like--

    Traceback (most recent call last):
      File "test.py", line 16, in <module>
        main()
      File "test.py", line 14, in main
        raise exc  # call 3
      File "test.py", line 10, in main
        raise exc  # call 2
      File "test.py", line 5, in main
        raise exc  # call 1
    ValueError

Since you can see that the later calls are getting added on the top,
it's almost as if it should read: most recent calls **first**. :)

(I wonder if there's a 4-word phrase that does accurately describe
what's happening.)

--Chris



>
> -n
>
> On Sun, Dec 24, 2017 at 9:55 PM, Chris Jerdonek
> <chris.jerdonek at gmail.com> wrote:
>> Hi,
>>
>> I noticed that if a task in asyncio raises an exception, then the
>> displayed traceback can be "polluted" by intermediate calls to
>> task.result().  Also, the calls to task.result() can appear out of
>> order relative to each other and to other lines.
>>
>> Here is an example:
>>
>>     import asyncio
>>
>>     async def raise_error():
>>         raise ValueError()
>>
>>     async def main():
>>         task = asyncio.ensure_future(raise_error())
>>
>>         try:
>>             await task  # call 1
>>         except Exception:
>>             pass
>>
>>         try:
>>             task.result()  # call 2
>>         except Exception:
>>             pass
>>
>>         task.result()  # call 3
>>
>>     asyncio.get_event_loop().run_until_complete(main())
>>
>> The above outputs--
>>
>>     Traceback (most recent call last):
>>       File "test.py", line 24, in <module>
>>         asyncio.get_event_loop().run_until_complete(main())
>>       File "/Users/.../3.6.4rc1/lib/python3.6/asyncio/base_events.py",
>>           line 467, in run_until_complete
>>         return future.result()
>>       File "test.py", line 21, in main
>>         task.result()  # call 3
>>       File "test.py", line 17, in main
>>         task.result()  # call 2
>>       File "test.py", line 12, in main
>>         await task  # call 1
>>       File "test.py", line 5, in raise_error
>>         raise ValueError()
>>     ValueError
>>
>> Notice that the "call 2" line appears in the traceback, even though it
>> doesn't come into play in the exception.  Also, the lines don't obey
>> the "most recent call last" rule.  If this rule were followed, it
>> should be something more like--
>>
>>     Traceback (most recent call last):
>>       File "test.py", line 24, in <module>
>>         asyncio.get_event_loop().run_until_complete(main())
>>       File "/Users/.../3.6.4rc1/lib/python3.6/asyncio/base_events.py",
>>           line 467, in run_until_complete
>>         return future.result()
>>       File "test.py", line 12, in main
>>         await task  # call 1
>>       File "test.py", line 5, in raise_error
>>         raise ValueError()
>>       File "test.py", line 17, in main
>>         task.result()  # call 2
>>       File "test.py", line 21, in main
>>         task.result()  # call 3
>>     ValueError
>>
>> If people agree there's an issue along these lines, I can file an
>> issue in the tracker. I didn't seem to find one when searching for
>> open issues with search terms like "asyncio traceback".
>>
>> Thanks,
>> --Chris
>> _______________________________________________
>> Async-sig mailing list
>> Async-sig at python.org
>> https://mail.python.org/mailman/listinfo/async-sig
>> Code of Conduct: https://www.python.org/psf/codeofconduct/
>
>
>
> --
> Nathaniel J. Smith -- https://vorpus.org