4

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())
  • I think that the time is calculated correctly, since you will finish execution only after this 2nd second passed. However, I am facing similar problem with distinguishing time used by asynchronous function/generator, and if you managed to resolve this, please let me know. https://stackoverflow.com/q/76201333/5002658 – Artur Laskowski May 08 '23 at 14:07

0 Answers0