Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

How do I retrieve the original call stack when debugging async functions?

Given this sample code

#!/usr/bin/python3
import asyncio

async def f1():
    await f2()
async def f2():
    try:
        await asyncio.sleep(1)
    except BaseException as exc:
        import pdb;pdb.set_trace()
        pass
async def main():
    f = asyncio.ensure_future(f1())
    await asyncio.sleep(0.5)
    f.cancel()
    await f

loop = asyncio.get_event_loop()
loop.run_until_complete(main())

the stack trace at the breakpoint looks like this:

(Pdb) w
  /tmp/t.py(19)<module>()
-> loop.run_until_complete(main())
  /usr/lib/python3.5/asyncio/base_events.py(325)run_until_complete()
-> self.run_forever()
  /usr/lib/python3.5/asyncio/base_events.py(295)run_forever()
-> self._run_once()
  /usr/lib/python3.5/asyncio/base_events.py(1254)_run_once()
-> handle._run()
  /usr/lib/python3.5/asyncio/events.py(125)_run()
-> self._callback(*self._args)
  /usr/lib/python3.5/asyncio/tasks.py(293)_wakeup()
-> self._step(exc)
  /usr/lib/python3.5/asyncio/tasks.py(241)_step()
-> result = coro.throw(exc)
> /tmp/t.py(11)f2()
-> pass

This is bad because I do no longer see that f2() was originally called from f1().

How do I retrieve the original call stack, given that Python is able to do that by simple single-stepping?:

$ python3 t.py
> /tmp/t.py(11)f2()
-> pass
(Pdb) s
--Return--
> /tmp/t.py(11)f2()->None
-> pass
(Pdb) s
--Call--
> /tmp/t.py(5)f1()
-> await f2()
(Pdb) s
--Return--
> /tmp/t.py(4)f1()->None
like image 548
Matthias Urlichs Avatar asked Feb 13 '16 06:02

Matthias Urlichs


1 Answers

No way, sorry.

It's impossible, at least in Python 3.5

UPD

Inner python frame has a reference to outer frame (fr.f_back), it makes possible to display stack traces.

But it has no reference to outer coroutine that awaits inner one.

Your code demonstrates a really interesting case.

For simpler example:

#!/usr/bin/python3
import asyncio
import sys
import traceback

async def f1():
    await f2()
async def f2():
    import pdb;pdb.set_trace()

loop = asyncio.get_event_loop()
loop.run_until_complete(f1())

we will see your coroutines on trace:

(Pdb) w
  /tmp/3.py(12)<module>()
-> loop.run_until_complete(f1())
  /usr/lib/python3.5/asyncio/base_events.py(325)run_until_complete()
-> self.run_forever()
  /usr/lib/python3.5/asyncio/base_events.py(295)run_forever()
-> self._run_once()
  /usr/lib/python3.5/asyncio/base_events.py(1254)_run_once()
-> handle._run()
  /usr/lib/python3.5/asyncio/events.py(125)_run()
-> self._callback(*self._args)
  /usr/lib/python3.5/asyncio/tasks.py(239)_step()
-> result = coro.send(None)
  /tmp/3.py(7)f1()
-> await f2()
> /tmp/3.py(9)f2()->None
-> import pdb;pdb.set_trace()

But in your case situation is different: f2() waits for sleep().

It works internally in the following way: sleep() returns a future object, f2() yields (not returns) it back to f1() which yields future again. The topmost caller in this case a task f created in main by ensure_future() call.

When you cancel the task it cancels most inner waiter (future returned by sleep()) without going through f1 -> f2 -> sleep chain top-down but explicitly cancelling sleep and popping up over the chain in bottom-up order.

What's why you see only the last coroutine on the stack -- all other will appear on it on exception unwinding.

like image 131
Andrew Svetlov Avatar answered Nov 15 '22 09:11

Andrew Svetlov