python - 如何衡量 Python 的 asyncio 代码性能？

Question

我不能使用普通的工具和技术来衡量协程的性能，因为它在 await 上花费的时间不应该被考虑在内(或者它应该只考虑从可等待但不是 IO 延迟)。

那么如何衡量协程所花费的时间呢？我如何比较 2 个实现并找到更有效的？我使用什么工具？

Answer 1

这个答案最初包含两个不同的解决方案:第一个基于猴子补丁，第二个不适用于 python 3.7 及更高版本。这个新版本有望提供一种更好、更强大的方法。

首先，标准计时工具，例如 time可用于确定程序的 CPU 时间，这通常是我们在测试异步应用程序的性能时感兴趣的内容。这些测量也可以在 python 中使用 time.process_time() 执行。功能:

import time

real_time = time.time()
cpu_time = time.process_time()

time.sleep(1.)
sum(range(10**6))

real_time = time.time() - real_time
cpu_time = time.process_time() - cpu_time

print(f"CPU time: {cpu_time:.2f} s, Real time: {real_time:.2f} s")

请参阅下面两种方法产生的类似输出:

$ /usr/bin/time -f "CPU time: %U s, Real time: %e s" python demo.py
CPU time: 0.02 s, Real time: 1.02 s  # python output
CPU time: 0.03 s, Real time: 1.04 s  # `time` output

在 asyncio 应用程序中，可能会发生程序的某些同步部分最终执行阻塞调用，从而有效地阻止事件循环运行其他任务。因此，我们可能希望分别记录事件循环等待的时间与其他 IO 任务所花费的时间。

这可以通过子类化 default selector 来实现执行一些计时操作并使用 custom event loop policy设置一切。 This code snippet提供这样的策略以及用于打印不同时间指标的上下文管理器。

async def main():
    print("~ Correct IO management ~")
    with print_timing():
        await asyncio.sleep(1)
        sum(range(10**6))
    print()

    print("~ Incorrect IO management ~")
    with print_timing():
        time.sleep(0.2)
        await asyncio.sleep(0.8)
        sum(range(10**6))
    print()

asyncio.set_event_loop_policy(TimedEventLoopPolicy())
asyncio.run(main(), debug=True)

注意这两个运行之间的区别:

~ Correct IO management ~
CPU time:      0.016 s
Select time:   1.001 s
Other IO time: 0.000 s
Real time:     1.017 s

~ Incorrect IO management ~
CPU time:      0.016 s
Select time:   0.800 s
Other IO time: 0.200 s
Real time:     1.017 s

另请注意 asyncio debug mode可以检测到那些阻塞操作:

Executing <Handle <TaskWakeupMethWrapper object at 0x7fd4835864f8>(<Future finis...events.py:396>) created at ~/miniconda/lib/python3.7/asyncio/futures.py:288> took 0.243 seconds