5

您好 Python 专家，我开始使用 cProfile 以便在我的程序上获得更详细的时序信息。但是，让我感到非常不安的是，有很大的开销。知道为什么 cProfile 报告了 7 秒，而时间模块在下面的代码中只报告了 2 秒吗？

# a simple function

def f(a, b):
 c = a+b

# a simple loop
def loop():
 for i in xrange(10000000):
  f(1,2)

# timing using time module
# 2 seconds on my computer
from time import time
x = time()
loop()
y = time()
print 'Time taken %.3f s.' % (y-x)

# timing using cProfile
# 7 seconds on my computer
import cProfile
cProfile.runctx('loop()', globals(), locals())
4

2 回答 2

5

因为它做了更多的工作？ time只计算整个操作的时间，同时cProfile在仪器下运行它，以便获得详细的故障。显然，分析并不意味着在生产中使用，因此 2.5 倍的开销似乎是一个很小的代价。

于 2010-06-28T17:59:11.053 回答
1

该函数f返回非常快。当您使用 cProfile 时，归因于一次调用f的时间并不准确，因为时间太小以至于与测量时间的误差相当。用于测量时间差异的时钟可能只能精确到 0.001 秒。因此，每次测量的误差可能比您尝试测量的时间大几个数量级。这样做 1e7 次，你就会得到虚假的结果。（有关此问题的更多讨论，请参见http://docs.python.org/library/profile.html#limitations。）

请注意，如果您更改要使用的代码

def f(a, b):
 for i in xrange(int(1e4)):    
     c = a+b

# a simple loop
def loop():
 for i in xrange(int(1e3)):
  f(1,2)

你得到

Time taken 0.732 s.
         1003 function calls in 0.725 CPU seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.725    0.725 <string>:1(<module>)
     1000    0.723    0.001    0.723    0.001 test.py:4(f)
        1    0.001    0.001    0.725    0.725 test.py:9(loop)
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

您正在执行相同数量的循环，但每次调用都f需要更长的时间。这减少了每次测量的误差。（归因于每次调用的时间f包含一个错误，现在没有测量到的总时间那么大。）

于 2010-06-28T19:07:40.120 回答