badmintonbaseba on Stack Traces Are Underrated

Comment on Stack Traces Are Underrated parent

Python asyncio supports meaningful stack traces through async functions just fine.

  import asyncio
  
  async def baz():
      await asyncio.sleep(.1)
      raise RuntimeError()
  
  async def bar():
      await asyncio.sleep(.1)
      await baz()
  
  async def foo():
      await asyncio.sleep(.1)
      await bar()
  
  async def main():
      await asyncio.sleep(.1)
      await foo()
  
  if __name__ == "__main__":
      loop = asyncio.new_event_loop()
      asyncio.set_event_loop(loop)
      main_task = loop.create_task(main())
      try:
          loop.run_until_complete(main_task)
      except KeyboardInterrupt:
          main_task.cancel()
          loop.run_until_complete(asyncio.wait([main_task]))
          pass

And then run: $ python3 test_stacktrace.py Traceback (most recent call last): File "/home/user/tmp/test_stacktrace.py", line 24, in <module> loop.run_until_complete(main_task) File "/usr/lib/python3.10/asyncio/base_events.py", line 649, in run_until_complete return future.result() File "/home/user/tmp/test_stacktrace.py", line 17, in main await foo() File "/home/user/tmp/test_stacktrace.py", line 13, in foo await bar() File "/home/user/tmp/test_stacktrace.py", line 9, in bar await baz() File "/home/user/tmp/test_stacktrace.py", line 5, in baz raise RuntimeError() RuntimeError

the_mitsuhiko 1y

Note how also in this stack trace you lose the information about where the main task was scheduled [1]. While you can stitch together the await points, it's much harder to find where tasks are originating. This is also true for `TaskGroup` where the actual call that schedules a task is lost. You will just find the eventual await, which might be the task group (which is good, since that would be structural concurrency), but often you just find nothing since it's not properly awaited or in a completely different place (eg: pending shutdown).

[1]: the important line is "main_task = loop.create_task(main())"

badmintonbaseba 1y

That's a good point. I would argue that both that line and the reported `loop.run_until_complete(main_task)` line are important, but then it becomes impossible to have a single linear trace when there are manually scheduled and waited on tasks mixed in.

At that point you have something like a "coroutine frame tree" instead of a "stack trace", where you potentially store multiple parent frames and source lines per coroutine frame. Could be presented something like:

  $ python3 test_stacktrace.py
  Traceback (most recent call last):
  * File "/home/user/tmp/test_stacktrace.py", line 22, in <module>
  |   main_task = loop.create_task(main())
  | * File "/home/user/tmp/test_stacktrace.py", line 24, in <module>
  |/    loop.run_until_complete(main_task)
  * File "/usr/lib/python3.10/asyncio/base_events.py", line 649, in run_until_complete
  |   return future.result()
  * File "/home/user/tmp/test_stacktrace.py", line 17, in main
  |   await foo()
  * File "/home/user/tmp/test_stacktrace.py", line 13, in foo
  |   await bar()
  * File "/home/user/tmp/test_stacktrace.py", line 9, in bar
  |   await baz()
  * File "/home/user/tmp/test_stacktrace.py", line 5, in baz
      raise RuntimeError()
  RuntimeError

Yoric 1y

Maybe in your example, but I long ago gave up on having stack traces with any meaningful async Python code. Is it the frameworks' fault? Presumably. But the end result is the same for me. Which is a shame, because Python stack traces are really good, when they work.

Comments