目录:

1.timeit

  1.1 在命令后调用timeit

  1.2 在代码中使用

  1.3 创建计时器实例,通过autorange获得循环次数

  1.4 Wall时间和CPU时间

2.profile和cProfile

  2.1 使用cProfile

  2.2 将cProfile封装成装饰器 或 上下文  

  2.3 line_profiler 逐行分析代码耗时

  2.4 memory profiler 逐行分析代码占用内存


1.timeit  python标准库自带

其算法如下:

  1. 将代码循环之行多次(参数名number),以便有足够长的统计时间。
  2. 将步骤 1 循环执行多次(参数名repeat),获取足够多的有统计采样。
  3. 从步骤 2 的结果选取耗时最短的采样,计算单次平均值。

1.1命令行执行

(djProj_py3) appledeMacBook-Air-7:tests apple$ python -m timeit -r 3 -s "import time" "time.sleep(1)"
10 loops, best of 3: 1 sec per loop

1.2 在代码中调用

import timeit
# 执行 算法第一步
timeit.timeit("time.sleep(1)", setup="import time", number=10)
>>>
[10.027022889000364]
# 执行 算法第二步
timeit.repeat("time.sleep(1)", setup="import time", number=10, repeat=3)
>>>
[10.030386196999643, 10.036546275000546, 10.020536892000564]

1.3创建计时器实例,可以使用autorange方法探测合适的循环次数

In [4]: import timeit

In [5]: t = timeit.Timer("time.sleep(0.002)", "import time")

In [6]: t.autorange()
Out[6]: (100, 0.2527182700000594)

1.4 默认使用高精度计时器统计Wall时间,也可以改为统计CPU时间。

参数名 timer:   Wall -- time.perf_counter

        CPU -- time.process_time

timeit.timeit("time.sleep(1)", "import time", number=10, timer=time.process_time)  # 指定统计CPU时间

2.profile和cProfile

2.1 cProfile以C实现,额外开销小。profile以python实现,相关开销大会导致测量误差较大,适合用来编写扩展分析器。

测试代码:

import time

def a():
n = 0
for i in range(1000):
n += 1
time.sleep(1)
return n def b():
n = 0
for i in range(3):
n += a()
print(n)
return n if __name__ == "__main__":
b()

开始测试:

 ncalls:被调用总次数 
tottime: 总执行时间(不包括调用的子函数)
percall: tottime/ncalls
cumtime: 执行总时间(包括调用的子函数)
percall: cumtime / ncalls
(djProj_py3) appledeMacBook-Air-7:tests apple$ python -m cProfile -s cumtime test_a.py
3000
11 function calls in 3.010 seconds Ordered by: cumulative time
  # 次数 不包括子函数 平均 包括子函数 平均
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 3.010 3.010 {built-in method builtins.exec}
1 0.000 0.000 3.010 3.010 test_a.py:1(<module>)
1 0.000 0.000 3.010 3.010 test_a.py:12(b)
3 0.000 0.000 3.010 1.003 test_a.py:4(a)
3 3.009 1.003 3.009 1.003 {built-in method time.sleep}
1 0.000 0.000 0.000 0.000 {built-in method builtins.print}
1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}

2.2 一般将cProfile封装成装饰器 或 上下文

2.2.1装饰器

def profile(sortby="cumtime", limit=1, timer=time.perf_counter):
def decorator(func):
@functools.wraps(func)
def warp(*args, **kwargs):
p = cProfile.Profile(timer)
p.enable() # 类似启动的功能
try:
return func(*args, **kwargs)
finally:
p.disable() # 类似停止
s = pstats.Stats(p).sort_stats(sortby)
s.print_stats(limit) # 限制输出几行
return warp
return decorator def a():
n = 0
for i in range(1000):
n += 1
time.sleep(1)
return n @profile()
def b():
n = 0
for i in range(3):
n += a()
return n if __name__ == "__main__":
b() >>>
(djProj_py3) appledeMacBook-Air-7:tests apple$ python test_a.py
8 function calls in 3.013 seconds Ordered by: cumulative time
List reduced from 4 to 1 due to restriction <1> ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 3.013 3.013 test_a.py:28(b)

2.2.2 上下文

import cProfile, pstats, contextlib, time

@contextlib.contextmanager
def profile1(sortby='cumtime', limit=10, timer=time.perf_counter):
p = cProfile.Profile(timer)
p.enable()
try:
yield
finally:
p.disable()
s = pstats.Stats(p).sort_stats(sortby)
s.print_stats(limit) def a():
n = 0
for i in range(1000):
n += 1
time.sleep(1)
return n @profile1()
def b():
n = 0
for i in range(3):
n += a()
return n if __name__ == "__main__":
b() >>>
(djProj_py3) appledeMacBook-Air-7:tests apple$ python test_a.py
11 function calls in 3.013 seconds Ordered by: cumulative time ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 3.013 3.013 test_a.py:39(b)
3 0.001 0.000 3.013 1.004 test_a.py:31(a)
3 3.012 1.004 3.012 1.004 {built-in method time.sleep}
1 0.000 0.000 0.000 0.000 /Library/Frameworks/Python.framework/Versions/3.6/lib/python3.6/contextlib.py:85(__exit__)
1 0.000 0.000 0.000 0.000 {built-in method builtins.next}
1 0.000 0.000 0.000 0.000 test_a.py:20(profile1)
1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}

  2.3 line_profiler

 通过上面的cProfile可以分析得到引发性能的函数,line_profiler可以对该函数代码逐行分析

  首先 pip install line_profiler

  

@profile  # 此装饰器,安装了line_profiler,才只能通过命令 kernprof -l -v test_a.py 分析每行性能
def test():
for i in range(3):
a = [1] * (10 ** 6)
b = [2] * (2 * 10 ** 7)
del b
return a if __name__ == "__main__":
test() >>>

(djProj_py3) appledeMacBook-Air-7:tests apple$ kernprof -l -v test_a.py

Wrote profile results to test_a.py.lprof    # -l 储存进文件   -v 显示
Timer unit: 1e-06 s

Total time: 0.147605 s
File: test_a.py
Function: test at line 40

Line # Hits Time Per Hit % Time Line Contents
==============================================================
40 @profile
41 def test():
42 4 19.0 4.8 0.0 for i in range(3):
43 3 15401.0 5133.7 10.4 a = [1] * (10 ** 6)
44 1 73001.0 73001.0 49.5 b = [2] * (2 * 10 ** 7)
45 1 59182.0 59182.0 40.1 del b
46 1 2.0 2.0 0.0 return a

2.4 memory profiler

逐行分析代码内存占用

首先 pip install memory_profiler

@profile
def test():
for i in range(3):
a = [1] * (10 ** 6)
b = [2] * (2 * 10 ** 7)
del b
return a >>>
(djProj_py3) appledeMacBook-Air-7:tests apple$ python -m memory_profiler test_a.py
Filename: test_a.py Line # Mem usage Increment Line Contents
================================================
40 31.000 MiB 31.000 MiB @profile
41 def test():
42 46.266 MiB 0.000 MiB for i in range(3):
43 46.266 MiB 15.266 MiB a = [1] * (10 ** 6)
44 198.855 MiB 152.590 MiB b = [2] * (2 * 10 ** 7)
45 46.266 MiB -152.590 MiB del b
46 46.266 MiB 0.000 MiB return a
04-14 08:44