15

使用 python 内置分析器和在一个处理器中运行的脚本（并且没有多线程）

time python -m cProfile myscript.py

分析器报告的 CPU 时间是 345.710 CPU 秒

24184348 function calls (24183732 primitive calls) in 345.710 CPU seconds

真实时间、用户时间和系统时间是：

real    5m45.926s
user    1m59.340s
sys     0m39.452s

如您所见，CPU 时间几乎是实时的（345.710 = 5m45.710s）。

那么，鉴于该结果，是否可以假设分析器报告的 CPU 时间包括其他进程使用的时间片和进程阻塞的时间？即探查器 CPU 时间不是进程时间（用户 + sys），而是挂钟时间，正如 “真实”、“用户”和“系统”在时间输出中的含义是什么（1）中解释的那样？

非常感谢提前

4

3 回答 3

17

这很好地回答了真实、用户和系统时间的含义。去引用：

  • “真实”是挂钟时间 - 从通话开始到结束的时间。这是所有经过的时间，包括其他进程使用的时间片和进程阻塞的时间（例如，如果它正在等待 I/O 完成）。

  • “用户”是进程内用于用户模式代码（内核外部）的 CPU 时间量。这只是执行进程中使用的实际 CPU 时间。其他进程和进程阻塞的时间不计入此数字。

  • 'Sys' 是进程内在内核中花费的 CPU 时间量。这意味着在内核中执行系统调用所花费的 CPU 时间，而不是仍在用户空间中运行的库代码。像“用户”一样，这只是进程使用的 CPU 时间。

从上面的解释看来，用户+系统时间应该等于 CPU 秒数。相反，它更接近“真实”时间。奇怪的！

对此有一个合理的解释。“用户”时间不包括进程内用于 I/O 操作的 CPU 秒数。它只是测量内存中用户模式代码所花费的 CPU 时间。经验法则是：

实时 = 用户 + 系统 + I/O 时间 + 解释器启动时间 + 字节码编译时间

为了验证这一点，我进行了urllib2.urlopen(urllib2.Request(url))密集 I/O 调用。结果如下：

         100792 function calls (98867 primitive calls) in 2.076 CPU seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
      512    0.719    0.001    0.719    0.001 {method 'recv' of '_socket.socket' objects}
        1    0.464    0.464    0.473    0.473 {_socket.getaddrinfo}
        1    0.352    0.352    0.352    0.352 <string>:1(connect)
        1    0.248    0.248    0.348    0.348 common_functions.py:1(<module>)
        1    0.022    0.022    0.075    0.075 __init__.py:2(<module>)
        1    0.017    0.017    0.030    0.030 urllib.py:1442(getproxies_macosx_sysconf)
   330/67    0.012    0.000    0.031    0.000 sre_parse.py:385(_parse)


real    0m2.255s
user    0m0.352s
sys 0m0.093s

这里，2.076-(0.352+0.093)，即 1.631 CPU 秒消耗在 I/O 操作中（主要是_socket.socket和_socket.getaddrinfo）。其余时间 2.255-2.076 用于代码的冷启动。

希望这很有用。

更新：在多核系统中，多个 CPU 并行工作，情况略有不同。cProfile 报告的总 CPU 秒数是所有 CPU 单独花费的时间总和。例如：在 2 核系统中，如果一个 CPU 工作 10 秒。同时，另一个 CPU 工作 15 秒。报告的总 CPU 秒数将为 25 秒。虽然实际经过的时间可能只有 15 秒。因此，在多核系统中，CPU 时间可能超过实时。由于 CPU并行工作

于 2012-03-02T13:54:00.227 回答
7

我一直对同样的问题感到困惑。

答案是 cProfile 使用挂钟时间。它的输出在历史上一直是错误的，但现在已修复（“CPU seconds”中的“CPU”已被删除）。我不知道确切的时间，但是 Debian 6.0 中的 Python 2.6.6 有这个错误，而 Debian 7.0 中的 Python 2.7.3 很好。

这很令人费解，因为大多数分析器会计算 CPU 上花费的时间，而不是挂钟时间。但这是一个“便宜”的分析器。

文档http://docs.python.org/2/library/profile.html#limitations解释 - 不清楚 - 时间是基于滴答作响的挂钟，而不是 getrusage() 或 ptrace 技术。

如果您检查代码（http://hg.python.org/cpython/file/44f455e6163d/Modules/_lsprof.c），您可以验证它是否基于 QueryPerformanceFrequency/gettimeofday。

Jerrymouse 关于“时间”和 cProfile 计时不能重合的事实是正确的，因为 cProfile 仅在编译代码后才开始运行。但除此之外，它的“实​​时”方程是虚假的。

wallclock 和 user+sys 之间的区别可能在于许多不同的因素，例如代表您的进程的 I/O 或代表包括内核本身（交换、日志等）在内的任何其他进程的 I/O，或花费在其他进程上的 CPU 时间进程，或代表您的进程等待任何无法计算的东西，因为它是远程资源（网络，或通过 NFS 或 iSCSI 间接）等。您可以命名它。

于 2013-06-27T22:10:53.550 回答
7

Python 分析器默认测量墙时间，但可以使用自定义计时器函数测量 CPU 时间。以下适用于 Linux，但不适用于 Windows（因为time.clock在 Windows 上测量挂墙时间）：

import cProfile
import time


def idleWait():
    time.sleep(10)

def busyWait():
    t = time.time() + 10
    while time.time() < t: pass

def target():
    idleWait()
    busyWait()


print "Wall time:"
p = cProfile.Profile()
p.runcall(target)
p.print_stats()

print "CPU time:"
p = cProfile.Profile(time.clock)
p.runcall(target)
p.print_stats()

第一次配置文件运行将显示 20 秒已过去，其中大约一半花费在time.sleep. 第二个显示已过去 10 秒，其中没有一个花费在time.sleep.

于 2013-08-02T09:03:45.993 回答