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@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@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@python.org
https://mail.python.org/mailman/listinfo/async-sig
Code of Conduct: https://www.python.org/psf/codeofconduct/

--

Thanks,

Andrew Svetlov