如何衡量Python的异步代码性能? [英] How to measure Python's asyncio code performance?

问题描述

我不能使用普通的工具和技术来衡量协程的性能，因为不应该考虑在await花费的时间(或者，它应该只考虑从等待中读取的开销，而不是考虑IO延迟).

I can't use normal tools and technics to measure the performance of a coroutine because the time it takes at await should not be taken in consideration (or it should just consider the overhead of reading from the awaitable but not the IO latency).

那么，如何衡量协程花费的时间呢?如何比较2种实现并找到更有效的方法?我要使用什么工具?

So how do measure the time a coroutine takes ? How do I compare 2 implementations and find the more efficent ? What tools do I use ?

推荐答案

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

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

First off, standard timing tools such as time can be used to determine the CPU time of a program, which is usually what we're interested in when testing the performance of an asynchronous application. Those measurements can also be performed in python using the time.process_time() function:

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")

请参见下面两种方法产生的相似输出:

See below the similar output produced by both methods:

$ /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

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

In an asyncio application, it might happen that some synchronous part of the program ends up performing a blocking call, effectively preventing the event loop from running other tasks. So we might want to record separately the time the event loop spends waiting from the time taken by other IO tasks.

这可以通过对默认选择器进行子类化来实现.以执行一些计时操作并使用自定义事件循环策略设置所有内容. 此代码段提供了这样的策略以及用于打印不同时间指标的上下文管理器.

This can be achieved by subclassing the default selector to perform some timing operation and using a custom event loop policy to set everything up. This code snippet provides such a policy along with a context manager for printing different time metrics.

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)

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

Note the difference between those two runs:

~ 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调试模式可以检测到这些阻止操作:

Also notice that the asyncio debug mode can detect those blocking operations:

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

这篇关于如何衡量Python的异步代码性能?的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持IT屋！