不只是分析CPU:为Python编写自定义分析器
假设你的程序很慢,并且你已经确定只有一部分是由于CPU的原因。你要如何确定代码的哪些部分正在等待CPU以外的东西?
在本文中,你将学习如何编写自定义分析器,特别是能帮助你追踪到你代码中等待CPU以外的东西的位置的分析器。我们将特别讨论:
- 你的程序可能正在等待什么。
- 分析非-CPU时间。
- 分析非主动上下文切换。
你的程序正在等待什么?
当你的程序没有消耗CPU的时候,它可能在等待其它的东西。这些东西可能是:
- 网络通信:这可能包括DNS查询、等待另一方响应、等待要下载的所有数据等等。
- 你的硬盘驱动器:从磁盘读取需要时间;写入磁盘也是如此。有时直接对RAM缓存进行读取和写入,这要快一些,但有时对磁盘进行读取和写入时,这就很慢了。
- 锁:你的程序可能正在等待一个线程或进程锁。
- 休眠:有时你的程序会故意休眠,例如在重试时退出。
那么如何找出这些操作发生的地方呢?
技巧#1:非-cpu时间
Python的内置cProfile分析器可以使用任何上升的计数器进行分析,因此你可以利用这个事实来构建一个非-cpu时间的分析器。
正如我在前一篇文章中讨论的,你的操作系统可以告诉你你的进程使用了多少秒CPU。
让我们假设一个单线程程序,因为多线程程序分析和推理起来要难得多。如果你的程序已经运行了9秒,并且使用了7.5秒的CPU,这意味着它花费了1.5秒的等待时间。
首先,你可以构造一个计时器来测量非-cpu时间:
然后你再创建一个分析器,使用这个新的时间度量来进行分析:
现在你可以分析各种函数:
大多数等待时间都花在从socket进行读取,但也有一些时间花在DNS查询(getaddrinfo)、进行TCP握手(connect)和进行TLS/SSL握手。
由于我们非常小心地去不包括CPU时间,所以我们知道这纯粹是等待时间,而不是计算时间。
注意:为什么要记录strt .find和list.append的时间?它们并不做任何等待,所以这很可能是整个进程都没有运行的情况,可能是因为其它进程按计划运行了,或者是因为必须从swap中加载一些内存。这意味着一些时间消耗了,但是没有CPU时间。
我还看到少量的负时间消耗,这表明消耗的时间和CPU时间之间存在一些不一致,但是对于不太重要的程序,我不认为这会有显著的影响。
技巧2:主动上下文切换
测量运行时间的问题是,它可能会根据不在程序控制之下的东西而变化。有时候DNS查询会慢一些,有时候下载会慢一些。因此,如果能有一个不受外部操作速度有多慢影响的更一致的测量方法是非常有用的。
其中一种方法是测量该进程执行了多少需要进行等待的操作:计算等待的数量,而不是等待的时间。
你可以这样做。当你的进程停止使用CPU时,可能有两个原因:
- 每当一个进程执行无法立即成功的操作(从socket读取数据、休眠等等)时,它基本上是在告诉操作系统“在我可以继续执行时唤醒我”。这是一个“主动上下文切换”:CPU可以切换去运行一个不同的进程,直到socket上的数据可用时,休眠就结束,等等。
- “非主动上下文切换”是指操作系统临时停止运行一个进程,以便另一个进程可以使用CPU。
因此,出于我们的目的而言,我们希望使用主动上下文切换进行分析。
你可以使用psutil库来编写一个测量主动上下文切换的分析器:
然后你可以重新分析网络代码:
现在,你看到的不是等待的时间,而是主动上下文切换发生的次数。
请注意,你偶尔会在未预期的地方看到主动上下文切换—我的猜测是由于页面错误或加载了已交换出去的内存。
分析所有的东西
使用这种分析技术会有一些成本:由于额外的开销,它会大大降低你的程序的运行速度。但是,在大多数情况下,这不会对结果造成太大的影响,因为你不是在分析CPU。
一般情况下,你可以分析任意一个上升的数字。例如:
- 读取操作(psutil.Process().write_count)和写入操作(psutil.Process().read_count) 的数量。
- Linux系统中读取和写入(psutil.Process().read_chars)的字节总数。
- 内存分析中的内存分配 (这需要做一些工作,但使用jemalloc来完成应该是可能的)。
有关前两种用例的更多信息,请参阅psutil文档。
如果你有其它东西可以进行分析,请给我发邮件,我会把它们添加到列表中。
英文原文:https://pythonspeed.com/articles/custom-python-profiler/
译者:一瞬