|
1 | 1 | ============================== |
2 | | -14.13 给你的程序做基准测试 |
| 2 | +14.13 给你的程序做性能测试 |
3 | 3 | ============================== |
4 | 4 |
|
5 | 5 | ---------- |
6 | 6 | 问题 |
7 | 7 | ---------- |
8 | | -You would like to find out where your program spends its time and make timing |
9 | | -measurements. |
| 8 | + |
| 9 | +你想测试你的程序运行所花费的时间并做性能测试。 |
10 | 10 |
|
11 | 11 | | |
12 | 12 |
|
13 | 13 | ---------- |
14 | 14 | 解决方案 |
15 | 15 | ---------- |
16 | | -If you simply want to time your whole program, it’s usually easy enough to use something |
17 | | -like the Unix time command. For example: |
18 | | - |
19 | | -bash % time python3 someprogram.py |
20 | | -real 0m13.937s |
21 | | -user 0m12.162s |
22 | | -sys 0m0.098s |
23 | | -bash % |
24 | | - |
25 | | -On the other extreme, if you want a detailed report showing what your program is doing, |
26 | | -you can use the cProfile module: |
27 | | - |
28 | | -bash % python3 -m cProfile someprogram.py |
29 | | - 859647 function calls in 16.016 CPU seconds |
30 | | - |
31 | | - Ordered by: standard name |
32 | | - |
33 | | - ncalls tottime percall cumtime percall filename:lineno(function) |
34 | | - 263169 0.080 0.000 0.080 0.000 someprogram.py:16(frange) |
35 | | - 513 0.001 0.000 0.002 0.000 someprogram.py:30(generate_mandel) |
36 | | - 262656 0.194 0.000 15.295 0.000 someprogram.py:32(<genexpr>) |
37 | | - 1 0.036 0.036 16.077 16.077 someprogram.py:4(<module>) |
38 | | - 262144 15.021 0.000 15.021 0.000 someprogram.py:4(in_mandelbrot) |
39 | | - 1 0.000 0.000 0.000 0.000 os.py:746(urandom) |
40 | | - 1 0.000 0.000 0.000 0.000 png.py:1056(_readable) |
41 | | - 1 0.000 0.000 0.000 0.000 png.py:1073(Reader) |
42 | | - 1 0.227 0.227 0.438 0.438 png.py:163(<module>) |
43 | | - 512 0.010 0.000 0.010 0.000 png.py:200(group) |
| 16 | +如果你只是简单的想测试下你的程序整体花费的时间, |
| 17 | +通常使用Unix时间函数就行了,比如: |
| 18 | + |
| 19 | +:: |
| 20 | + |
| 21 | + bash % time python3 someprogram.py |
| 22 | + real 0m13.937s |
| 23 | + user 0m12.162s |
| 24 | + sys 0m0.098s |
| 25 | + bash % |
| 26 | + |
| 27 | +如果你还需要一个程序各个细节的详细报告,可以使用 ``cProfile`` 模块: |
| 28 | + |
| 29 | +:: |
| 30 | + |
| 31 | + bash % python3 -m cProfile someprogram.py |
| 32 | + 859647 function calls in 16.016 CPU seconds |
| 33 | + |
| 34 | + Ordered by: standard name |
| 35 | + |
| 36 | + ncalls tottime percall cumtime percall filename:lineno(function) |
| 37 | + 263169 0.080 0.000 0.080 0.000 someprogram.py:16(frange) |
| 38 | + 513 0.001 0.000 0.002 0.000 someprogram.py:30(generate_mandel) |
| 39 | + 262656 0.194 0.000 15.295 0.000 someprogram.py:32(<genexpr>) |
| 40 | + 1 0.036 0.036 16.077 16.077 someprogram.py:4(<module>) |
| 41 | + 262144 15.021 0.000 15.021 0.000 someprogram.py:4(in_mandelbrot) |
| 42 | + 1 0.000 0.000 0.000 0.000 os.py:746(urandom) |
| 43 | + 1 0.000 0.000 0.000 0.000 png.py:1056(_readable) |
| 44 | + 1 0.000 0.000 0.000 0.000 png.py:1073(Reader) |
| 45 | + 1 0.227 0.227 0.438 0.438 png.py:163(<module>) |
| 46 | + 512 0.010 0.000 0.010 0.000 png.py:200(group) |
| 47 | + ... |
| 48 | + bash % |
| 49 | + |
| 50 | +不过通常情况是介于这两个极端之间。比如你已经知道代码运行时在少数几个函数中花费了绝大部分时间。 |
| 51 | +对于这些函数的性能测试,可以使用一个简单的装饰器: |
| 52 | + |
| 53 | +.. code-block:: python |
| 54 | +
|
| 55 | + # timethis.py |
| 56 | +
|
| 57 | + import time |
| 58 | + from functools import wraps |
| 59 | +
|
| 60 | + def timethis(func): |
| 61 | + @wraps(func) |
| 62 | + def wrapper(*args, **kwargs): |
| 63 | + start = time.perf_counter() |
| 64 | + r = func(*args, **kwargs) |
| 65 | + end = time.perf_counter() |
| 66 | + print('{}.{} : {}'.format(func.__module__, func.__name__, end - start)) |
| 67 | + return r |
| 68 | + return wrapper |
| 69 | +
|
| 70 | +要使用这个装饰器,只需要将其放置在你要进行性能测试的函数定义前即可,比如: |
| 71 | + |
| 72 | +:: |
| 73 | + |
| 74 | + >>> @timethis |
| 75 | + ... def countdown(n): |
| 76 | + ... while n > 0: |
| 77 | + ... n -= 1 |
44 | 78 | ... |
45 | | -bash % |
| 79 | + >>> countdown(10000000) |
| 80 | + __main__.countdown : 0.803001880645752 |
| 81 | + >>> |
46 | 82 |
|
47 | | -More often than not, profiling your code lies somewhere in between these two extremes. |
48 | | -For example, you may already know that your code spends most of its time in a few |
49 | | -selected functions. For selected profiling of functions, a short decorator can be useful. |
50 | | -For example: |
| 83 | +要测试某个代码块运行时间,你可以定义一个上下文管理器,例如: |
51 | 84 |
|
52 | | -# timethis.py |
| 85 | +.. code-block:: python |
53 | 86 |
|
54 | | -import time |
55 | | -from functools import wraps |
| 87 | + from contextlib import contextmanager |
56 | 88 |
|
57 | | -def timethis(func): |
58 | | - @wraps(func) |
59 | | - def wrapper(*args, **kwargs): |
| 89 | + @contextmanager |
| 90 | + def timeblock(label): |
60 | 91 | start = time.perf_counter() |
61 | | - r = func(*args, **kwargs) |
62 | | - end = time.perf_counter() |
63 | | - print('{}.{} : {}'.format(func.__module__, func.__name__, end - start)) |
64 | | - return r |
65 | | - return wrapper |
66 | | -
|
67 | | -To use this decorator, you simply place it in front of a function definition to get timings |
68 | | -from it. For example: |
69 | | - |
70 | | ->>> @timethis |
71 | | -... def countdown(n): |
72 | | -... while n > 0: |
73 | | -... n -= 1 |
74 | | -... |
75 | | ->>> countdown(10000000) |
76 | | -__main__.countdown : 0.803001880645752 |
77 | | ->>> |
78 | | - |
79 | | -To time a block of statements, you can define a context manager. For example: |
80 | | - |
81 | | -from contextlib import contextmanager |
82 | | - |
83 | | -@contextmanager |
84 | | -def timeblock(label): |
85 | | - start = time.perf_counter() |
86 | | - try: |
87 | | - yield |
88 | | - finally: |
89 | | - end = time.perf_counter() |
90 | | - print('{} : {}'.format(label, end - start)) |
91 | | -Here is an example of how the context manager works: |
92 | | - |
93 | | ->>> with timeblock('counting'): |
94 | | -... n = 10000000 |
95 | | -... while n > 0: |
96 | | -... n -= 1 |
97 | | -... |
98 | | -counting : 1.5551159381866455 |
99 | | ->>> |
100 | | - |
101 | | -For studying the performance of small code fragments, the timeit module can be useful. |
102 | | -For example: |
103 | | - |
104 | | ->>> from timeit import timeit |
105 | | ->>> timeit('math.sqrt(2)', 'import math') |
106 | | -0.1432319980012835 |
107 | | ->>> timeit('sqrt(2)', 'from math import sqrt') |
108 | | -0.10836604500218527 |
109 | | ->>> |
110 | | - |
111 | | -timeit works by executing the statement specified in the first argument a million times |
112 | | -and measuring the time. The second argument is a setup string that is executed to set |
113 | | -up the environment prior to running the test. If you need to change the number of |
114 | | -iterations, supply a number argument like this: |
115 | | - |
116 | | ->>> timeit('math.sqrt(2)', 'import math', number=10000000) |
117 | | -1.434852126003534 |
118 | | ->>> timeit('sqrt(2)', 'from math import sqrt', number=10000000) |
119 | | -1.0270336690009572 |
120 | | ->>> |
| 92 | + try: |
| 93 | + yield |
| 94 | + finally: |
| 95 | + end = time.perf_counter() |
| 96 | + print('{} : {}'.format(label, end - start)) |
| 97 | +
|
| 98 | +下面是使用这个上下文管理器的例子: |
| 99 | + |
| 100 | +:: |
| 101 | + |
| 102 | + >>> with timeblock('counting'): |
| 103 | + ... n = 10000000 |
| 104 | + ... while n > 0: |
| 105 | + ... n -= 1 |
| 106 | + ... |
| 107 | + counting : 1.5551159381866455 |
| 108 | + >>> |
| 109 | + |
| 110 | +对于测试很小的代码片段运行性能,使用 ``timeit`` 模块会很方便,例如: |
| 111 | + |
| 112 | +:: |
| 113 | + |
| 114 | + >>> from timeit import timeit |
| 115 | + >>> timeit('math.sqrt(2)', 'import math') |
| 116 | + 0.1432319980012835 |
| 117 | + >>> timeit('sqrt(2)', 'from math import sqrt') |
| 118 | + 0.10836604500218527 |
| 119 | + >>> |
| 120 | + |
| 121 | +``timeit`` 会执行第一个参数中语句100万次并计算运行时间。 |
| 122 | +第二个参数是运行测试之前配置环境。如果你想改变循环执行次数, |
| 123 | +可以像下面这样设置 ``number`` 参数的值: |
| 124 | + |
| 125 | +:: |
| 126 | + |
| 127 | + >>> timeit('math.sqrt(2)', 'import math', number=10000000) |
| 128 | + 1.434852126003534 |
| 129 | + >>> timeit('sqrt(2)', 'from math import sqrt', number=10000000) |
| 130 | + 1.0270336690009572 |
| 131 | + >>> |
121 | 132 |
|
122 | 133 | | |
123 | 134 |
|
124 | 135 | ---------- |
125 | 136 | 讨论 |
126 | 137 | ---------- |
127 | | -When making performance measurements, be aware that any results you get are ap‐ |
128 | | -proximations. The time.perf_counter() function used in the solution provides the |
129 | | -highest-resolution timer possible on a given platform. However, it still measures wall- |
130 | | -clock time, and can be impacted by many different factors, such as machine load. |
131 | | -If you are interested in process time as opposed to wall-clock time, use time.pro |
132 | | -cess_time() instead. For example: |
133 | | - |
134 | | -from functools import wraps |
135 | | -def timethis(func): |
136 | | - @wraps(func) |
137 | | - def wrapper(*args, **kwargs): |
138 | | - start = time.process_time() |
139 | | - r = func(*args, **kwargs) |
140 | | - end = time.process_time() |
141 | | - print('{}.{} : {}'.format(func.__module__, func.__name__, end - start)) |
142 | | - return r |
143 | | - return wrapper |
144 | | -
|
145 | | -Last, but not least, if you’re going to perform detailed timing analysis, make sure to read |
146 | | -the documentation for the time, timeit, and other associated modules, so that you have |
147 | | -an understanding of important platform-related differences and other pitfalls. |
148 | | -See Recipe 13.13 for a related recipe on creating a stopwatch timer class. |
| 138 | +当执行性能测试的时候,需要注意的是你获取的结果都是近似值。 |
| 139 | +``time.perf_counter()`` 函数会在给定平台上获取最高精度的计时值。 |
| 140 | +不过,它仍然还是基于时钟时间,很多因素会影响到它的精确度,比如机器负载。 |
| 141 | +如果你对于执行时间更感兴趣,使用 ``time.process_time()`` 来代替它。例如: |
| 142 | + |
| 143 | +.. code-block:: python |
| 144 | +
|
| 145 | + from functools import wraps |
| 146 | + def timethis(func): |
| 147 | + @wraps(func) |
| 148 | + def wrapper(*args, **kwargs): |
| 149 | + start = time.process_time() |
| 150 | + r = func(*args, **kwargs) |
| 151 | + end = time.process_time() |
| 152 | + print('{}.{} : {}'.format(func.__module__, func.__name__, end - start)) |
| 153 | + return r |
| 154 | + return wrapper |
| 155 | +
|
| 156 | +最后,如果你想进行更深入的性能分析,那么你需要详细阅读 ``time`` 、``timeit`` 和其他相关模块的文档。 |
| 157 | +这样你可以理解和平台相关的差异以及一些其他陷阱。 |
| 158 | +还可以参考13.13小节中相关的一个创建计时器类的例子。 |
0 commit comments