Suppose I have a coroutine function in python that looks like this :
async def foo():
time.sleep(1)
await asyncio.sleep(1)
Which blocks for 1 second and suspends for another second without blocking the event loop. Suppose I want to measure the time spent by this function for time spent blocking and suspended
...
Initially, I made a decorator like this:
def time_this(coro_func):
async def wrapper(*a, **k):
start = time.perf_counter()
ret = await coro_func(*a, **k)
elapsed = time.perf_counter() - start
print(f"Time spent blocking IO: {elapsed}, suspended: ...")
return ret
return wrapper
and decorated foo
with it.
Which produced this result :
Time spent blocking IO: 2.021167900005821, suspended: ...
This isn't correct, because only 1 second is spent blocking, and 1 second is spent suspended.
Ideally, I wanted something like this :
Time spent blocking IO: 1.0, suspended: 1.0
How do I get such a result from measuring async context switching?
Full code used above to reproduce:
import asyncio, time
def time_this(coro_func):
async def wrapper(*a, **k):
start = time.perf_counter()
ret = await coro_func(*a, **k)
elapsed = time.perf_counter() - start
print(f"Time spent blocking IO: {elapsed}, suspended: ...")
return ret
return wrapper
@time_this
async def foo():
time.sleep(1)
await asyncio.sleep(1)
async def main():
await foo()
asyncio.run(main())