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
