[Async-sig] Simplifying stack traces for tasks?
Andrew Svetlov
andrew.svetlov at gmail.com
Tue Nov 14 11:40:02 EST 2017
Got you.
PyPI library makes sense.
On Tue, Nov 14, 2017 at 5:27 PM Mark E. Haase <mehaase at gmail.com> wrote:
> I'm not asking to change Python's default behavior. I'm asking if anybody
> else likes this idea, has ideas to make it better, and would use it if I
> published some form of it on PyPI.
>
> On Tue, Nov 14, 2017 at 10:08 AM, Andrew Svetlov <andrew.svetlov at gmail.com
> > wrote:
>
>> AFAIK Python never hides stdlib codelines in tracebacks.
>> Why we should start to do it in asyncio?
>>
>> On Tue, Nov 14, 2017 at 4:54 PM Mark E. Haase <mehaase at gmail.com> wrote:
>>
>>> If an exception is thrown while the `asyncio` event loop is running, the
>>> stack trace is pretty complicated. Here's an example:
>>>
>>> Traceback (most recent call last):
>>> File "sample_client.py", line 616, in <module>
>>> loop.run_until_complete(main_task)
>>> File "/usr/lib/python3.6/asyncio/base_events.py", line 437, in
>>> run_until_complete
>>> self.run_forever()
>>> File "/usr/lib/python3.6/asyncio/base_events.py", line 405, in
>>> run_forever
>>> self._run_once()
>>> File "/usr/lib/python3.6/asyncio/base_events.py", line 1382, in
>>> _run_once
>>> handle._run()
>>> File "/usr/lib/python3.6/asyncio/events.py", line 126, in _run
>>> self._callback(*self._args)
>>> File "/usr/lib/python3.6/asyncio/tasks.py", line 315, in _wakeup
>>> self._step()
>>> File "/usr/lib/python3.6/asyncio/tasks.py", line 239, in _step
>>> result = coro.send(None)
>>> File "sample_client.py", line 319, in main
>>> await actions[args.action](args, socket)
>>> File "/usr/lib/python3.6/asyncio/coroutines.py", line 105, in
>>> __next__
>>> return self.gen.send(None)
>>> File "sample_client.py", line 558, in sync_job
>>> await asyncio.sleep(args.delay)
>>> File "/usr/lib/python3.6/asyncio/coroutines.py", line 105, in
>>> __next__
>>> return self.gen.send(None)
>>> File "/usr/lib/python3.6/asyncio/tasks.py", line 522, in sleep
>>> future, result)
>>> File "/usr/lib/python3.6/asyncio/base_events.py", line 525, in
>>> call_later
>>> timer = self.call_at(self.time() + delay, callback, *args)
>>> File "/usr/lib/python3.6/asyncio/base_events.py", line 541, in
>>> call_at
>>> timer = events.TimerHandle(when, callback, args, self)
>>> File "/usr/lib/python3.6/asyncio/events.py", line 148, in __init__
>>> super().__init__(callback, args, loop)
>>> File "/usr/lib/python3.6/asyncio/events.py", line 92, in __init__
>>> self._source_traceback =
>>> traceback.extract_stack(sys._getframe(1))
>>> File "/usr/lib/python3.6/traceback.py", line 207, in extract_stack
>>> stack = StackSummary.extract(walk_stack(f), limit=limit)
>>> File "/usr/lib/python3.6/traceback.py", line 352, in extract
>>> filename, lineno, name, lookup_line=False, locals=f_locals))
>>> KeyboardInterrupt
>>>
>>> Most of the stack frames are inside asyncio (_run, _wakeup, _step) and
>>> reveal the mechanics of the event loop. The stack trace would be a lot
>>> easier to read (and more similar to a stack trace of an equivalent
>>> synchronous program) if it looked like this:
>>>
>>> Traceback (most recent call last):
>>> File "sample_client.py", line 616, in <module>
>>> loop.run_until_complete(main_task)
>>> ...
>>> File "sample_client.py", line 319, in main
>>> await actions[args.action](args, socket)
>>> ...
>>> File "sample_client.py", line 558, in sync_job
>>> await asyncio.sleep(args.delay)
>>> KeyboardInterrupt
>>>
>>> I recognize that the event loop mechanics are probably useful in some
>>> circumstances, but in my experience working with asyncio for the last year,
>>> I've found the stack traces are generally too noisy. For a while, I was
>>> pasting stack traces into a text editor and cleaning them up by hand, but a
>>> few months ago I wrote a custom excepthook that generates stack traces
>>> similar to the one above.
>>>
>>> def async_excepthook(type_, exc, tb):
>>> cause_exc = None
>>> cause_str = None
>>>
>>> if exc.__cause__ is not None:
>>> cause_exc = exc.__cause__
>>> cause_str = 'The above exception was the direct cause ' \
>>> 'of the following exception:'
>>> elif exc.__context__ is not None and not
>>> exc.__suppress_context__:
>>> cause_exc = exc.__context__
>>> cause_str = 'During handling of the above exception, ' \
>>> 'another exception occurred:'
>>>
>>> if cause_exc:
>>> async_excepthook(type(cause_exc), cause_exc,
>>> cause_exc.__traceback__)
>>>
>>> if cause_str:
>>> print('\n{}\n'.format(cause_str))
>>>
>>> print('Async Traceback (most recent call last):')
>>> for frame in traceback.extract_tb(tb):
>>> head, tail = os.path.split(frame.filename)
>>> if (head.endswith('asyncio') or tail == 'traceback.py') and \
>>> frame.name.startswith('_'):
>>> print(' ...')
>>> continue
>>> print(' File "{}", line {}, in {}'
>>> .format(frame.filename, frame.lineno, frame.name))
>>> print(' {}'.format(frame.line))
>>> print('{}: {}'.format(type_.__name__, exc))
>>>
>>> The meat of it is towards the bottom, "if
>>> head.endswith('asyncio')..."There are a lot of debatable details and this
>>> implementation is pretty hacky and clumsy, but I have found it valuable in
>>> my own usage, and I haven't yet missed the omitted stack frames.
>>>
>>> I'm posting here to get constructive criticism on the concept and would
>>> also like to hear if Curio or Trio have done anything like this. (Based on
>>> a quick skim of the docs, I don't think they are.) I might publish a PyPI
>>> package if anybody is interested.
>>>
>>> Cheers,
>>> Mark
>>> _______________________________________________
>>> 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/
>>>
>> --
>> Thanks,
>> Andrew Svetlov
>>
>
> --
Thanks,
Andrew Svetlov
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.python.org/pipermail/async-sig/attachments/20171114/c8e8b0f3/attachment-0001.html>
More information about the Async-sig
mailing list