How to separately measure time spent suspended and blocking for a given coroutine in python?

Viewed 25

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())
0 Answers
Related