1 | n/a | #! /usr/bin/env python3 |
---|
2 | n/a | |
---|
3 | n/a | """Tool for measuring execution time of small code snippets. |
---|
4 | n/a | |
---|
5 | n/a | This module avoids a number of common traps for measuring execution |
---|
6 | n/a | times. See also Tim Peters' introduction to the Algorithms chapter in |
---|
7 | n/a | the Python Cookbook, published by O'Reilly. |
---|
8 | n/a | |
---|
9 | n/a | Library usage: see the Timer class. |
---|
10 | n/a | |
---|
11 | n/a | Command line usage: |
---|
12 | n/a | python timeit.py [-n N] [-r N] [-s S] [-p] [-h] [--] [statement] |
---|
13 | n/a | |
---|
14 | n/a | Options: |
---|
15 | n/a | -n/--number N: how many times to execute 'statement' (default: see below) |
---|
16 | n/a | -r/--repeat N: how many times to repeat the timer (default 3) |
---|
17 | n/a | -s/--setup S: statement to be executed once initially (default 'pass'). |
---|
18 | n/a | Execution time of this setup statement is NOT timed. |
---|
19 | n/a | -p/--process: use time.process_time() (default is time.perf_counter()) |
---|
20 | n/a | -v/--verbose: print raw timing results; repeat for more digits precision |
---|
21 | n/a | -u/--unit: set the output time unit (nsec, usec, msec, or sec) |
---|
22 | n/a | -h/--help: print this usage message and exit |
---|
23 | n/a | --: separate options from statement, use when statement starts with - |
---|
24 | n/a | statement: statement to be timed (default 'pass') |
---|
25 | n/a | |
---|
26 | n/a | A multi-line statement may be given by specifying each line as a |
---|
27 | n/a | separate argument; indented lines are possible by enclosing an |
---|
28 | n/a | argument in quotes and using leading spaces. Multiple -s options are |
---|
29 | n/a | treated similarly. |
---|
30 | n/a | |
---|
31 | n/a | If -n is not given, a suitable number of loops is calculated by trying |
---|
32 | n/a | successive powers of 10 until the total time is at least 0.2 seconds. |
---|
33 | n/a | |
---|
34 | n/a | Note: there is a certain baseline overhead associated with executing a |
---|
35 | n/a | pass statement. It differs between versions. The code here doesn't try |
---|
36 | n/a | to hide it, but you should be aware of it. The baseline overhead can be |
---|
37 | n/a | measured by invoking the program without arguments. |
---|
38 | n/a | |
---|
39 | n/a | Classes: |
---|
40 | n/a | |
---|
41 | n/a | Timer |
---|
42 | n/a | |
---|
43 | n/a | Functions: |
---|
44 | n/a | |
---|
45 | n/a | timeit(string, string) -> float |
---|
46 | n/a | repeat(string, string) -> list |
---|
47 | n/a | default_timer() -> float |
---|
48 | n/a | |
---|
49 | n/a | """ |
---|
50 | n/a | |
---|
51 | n/a | import gc |
---|
52 | n/a | import sys |
---|
53 | n/a | import time |
---|
54 | n/a | import itertools |
---|
55 | n/a | |
---|
56 | n/a | __all__ = ["Timer", "timeit", "repeat", "default_timer"] |
---|
57 | n/a | |
---|
58 | n/a | dummy_src_name = "<timeit-src>" |
---|
59 | n/a | default_number = 1000000 |
---|
60 | n/a | default_repeat = 5 |
---|
61 | n/a | default_timer = time.perf_counter |
---|
62 | n/a | |
---|
63 | n/a | _globals = globals |
---|
64 | n/a | |
---|
65 | n/a | # Don't change the indentation of the template; the reindent() calls |
---|
66 | n/a | # in Timer.__init__() depend on setup being indented 4 spaces and stmt |
---|
67 | n/a | # being indented 8 spaces. |
---|
68 | n/a | template = """ |
---|
69 | n/a | def inner(_it, _timer{init}): |
---|
70 | n/a | {setup} |
---|
71 | n/a | _t0 = _timer() |
---|
72 | n/a | for _i in _it: |
---|
73 | n/a | {stmt} |
---|
74 | n/a | _t1 = _timer() |
---|
75 | n/a | return _t1 - _t0 |
---|
76 | n/a | """ |
---|
77 | n/a | |
---|
78 | n/a | def reindent(src, indent): |
---|
79 | n/a | """Helper to reindent a multi-line statement.""" |
---|
80 | n/a | return src.replace("\n", "\n" + " "*indent) |
---|
81 | n/a | |
---|
82 | n/a | class Timer: |
---|
83 | n/a | """Class for timing execution speed of small code snippets. |
---|
84 | n/a | |
---|
85 | n/a | The constructor takes a statement to be timed, an additional |
---|
86 | n/a | statement used for setup, and a timer function. Both statements |
---|
87 | n/a | default to 'pass'; the timer function is platform-dependent (see |
---|
88 | n/a | module doc string). If 'globals' is specified, the code will be |
---|
89 | n/a | executed within that namespace (as opposed to inside timeit's |
---|
90 | n/a | namespace). |
---|
91 | n/a | |
---|
92 | n/a | To measure the execution time of the first statement, use the |
---|
93 | n/a | timeit() method. The repeat() method is a convenience to call |
---|
94 | n/a | timeit() multiple times and return a list of results. |
---|
95 | n/a | |
---|
96 | n/a | The statements may contain newlines, as long as they don't contain |
---|
97 | n/a | multi-line string literals. |
---|
98 | n/a | """ |
---|
99 | n/a | |
---|
100 | n/a | def __init__(self, stmt="pass", setup="pass", timer=default_timer, |
---|
101 | n/a | globals=None): |
---|
102 | n/a | """Constructor. See class doc string.""" |
---|
103 | n/a | self.timer = timer |
---|
104 | n/a | local_ns = {} |
---|
105 | n/a | global_ns = _globals() if globals is None else globals |
---|
106 | n/a | init = '' |
---|
107 | n/a | if isinstance(setup, str): |
---|
108 | n/a | # Check that the code can be compiled outside a function |
---|
109 | n/a | compile(setup, dummy_src_name, "exec") |
---|
110 | n/a | stmtprefix = setup + '\n' |
---|
111 | n/a | setup = reindent(setup, 4) |
---|
112 | n/a | elif callable(setup): |
---|
113 | n/a | local_ns['_setup'] = setup |
---|
114 | n/a | init += ', _setup=_setup' |
---|
115 | n/a | stmtprefix = '' |
---|
116 | n/a | setup = '_setup()' |
---|
117 | n/a | else: |
---|
118 | n/a | raise ValueError("setup is neither a string nor callable") |
---|
119 | n/a | if isinstance(stmt, str): |
---|
120 | n/a | # Check that the code can be compiled outside a function |
---|
121 | n/a | compile(stmtprefix + stmt, dummy_src_name, "exec") |
---|
122 | n/a | stmt = reindent(stmt, 8) |
---|
123 | n/a | elif callable(stmt): |
---|
124 | n/a | local_ns['_stmt'] = stmt |
---|
125 | n/a | init += ', _stmt=_stmt' |
---|
126 | n/a | stmt = '_stmt()' |
---|
127 | n/a | else: |
---|
128 | n/a | raise ValueError("stmt is neither a string nor callable") |
---|
129 | n/a | src = template.format(stmt=stmt, setup=setup, init=init) |
---|
130 | n/a | self.src = src # Save for traceback display |
---|
131 | n/a | code = compile(src, dummy_src_name, "exec") |
---|
132 | n/a | exec(code, global_ns, local_ns) |
---|
133 | n/a | self.inner = local_ns["inner"] |
---|
134 | n/a | |
---|
135 | n/a | def print_exc(self, file=None): |
---|
136 | n/a | """Helper to print a traceback from the timed code. |
---|
137 | n/a | |
---|
138 | n/a | Typical use: |
---|
139 | n/a | |
---|
140 | n/a | t = Timer(...) # outside the try/except |
---|
141 | n/a | try: |
---|
142 | n/a | t.timeit(...) # or t.repeat(...) |
---|
143 | n/a | except: |
---|
144 | n/a | t.print_exc() |
---|
145 | n/a | |
---|
146 | n/a | The advantage over the standard traceback is that source lines |
---|
147 | n/a | in the compiled template will be displayed. |
---|
148 | n/a | |
---|
149 | n/a | The optional file argument directs where the traceback is |
---|
150 | n/a | sent; it defaults to sys.stderr. |
---|
151 | n/a | """ |
---|
152 | n/a | import linecache, traceback |
---|
153 | n/a | if self.src is not None: |
---|
154 | n/a | linecache.cache[dummy_src_name] = (len(self.src), |
---|
155 | n/a | None, |
---|
156 | n/a | self.src.split("\n"), |
---|
157 | n/a | dummy_src_name) |
---|
158 | n/a | # else the source is already stored somewhere else |
---|
159 | n/a | |
---|
160 | n/a | traceback.print_exc(file=file) |
---|
161 | n/a | |
---|
162 | n/a | def timeit(self, number=default_number): |
---|
163 | n/a | """Time 'number' executions of the main statement. |
---|
164 | n/a | |
---|
165 | n/a | To be precise, this executes the setup statement once, and |
---|
166 | n/a | then returns the time it takes to execute the main statement |
---|
167 | n/a | a number of times, as a float measured in seconds. The |
---|
168 | n/a | argument is the number of times through the loop, defaulting |
---|
169 | n/a | to one million. The main statement, the setup statement and |
---|
170 | n/a | the timer function to be used are passed to the constructor. |
---|
171 | n/a | """ |
---|
172 | n/a | it = itertools.repeat(None, number) |
---|
173 | n/a | gcold = gc.isenabled() |
---|
174 | n/a | gc.disable() |
---|
175 | n/a | try: |
---|
176 | n/a | timing = self.inner(it, self.timer) |
---|
177 | n/a | finally: |
---|
178 | n/a | if gcold: |
---|
179 | n/a | gc.enable() |
---|
180 | n/a | return timing |
---|
181 | n/a | |
---|
182 | n/a | def repeat(self, repeat=default_repeat, number=default_number): |
---|
183 | n/a | """Call timeit() a few times. |
---|
184 | n/a | |
---|
185 | n/a | This is a convenience function that calls the timeit() |
---|
186 | n/a | repeatedly, returning a list of results. The first argument |
---|
187 | n/a | specifies how many times to call timeit(), defaulting to 3; |
---|
188 | n/a | the second argument specifies the timer argument, defaulting |
---|
189 | n/a | to one million. |
---|
190 | n/a | |
---|
191 | n/a | Note: it's tempting to calculate mean and standard deviation |
---|
192 | n/a | from the result vector and report these. However, this is not |
---|
193 | n/a | very useful. In a typical case, the lowest value gives a |
---|
194 | n/a | lower bound for how fast your machine can run the given code |
---|
195 | n/a | snippet; higher values in the result vector are typically not |
---|
196 | n/a | caused by variability in Python's speed, but by other |
---|
197 | n/a | processes interfering with your timing accuracy. So the min() |
---|
198 | n/a | of the result is probably the only number you should be |
---|
199 | n/a | interested in. After that, you should look at the entire |
---|
200 | n/a | vector and apply common sense rather than statistics. |
---|
201 | n/a | """ |
---|
202 | n/a | r = [] |
---|
203 | n/a | for i in range(repeat): |
---|
204 | n/a | t = self.timeit(number) |
---|
205 | n/a | r.append(t) |
---|
206 | n/a | return r |
---|
207 | n/a | |
---|
208 | n/a | def autorange(self, callback=None): |
---|
209 | n/a | """Return the number of loops so that total time >= 0.2. |
---|
210 | n/a | |
---|
211 | n/a | Calls the timeit method with increasing numbers from the sequence |
---|
212 | n/a | 1, 2, 5, 10, 20, 50, ... until the time taken is at least 0.2 |
---|
213 | n/a | second. Returns (number, time_taken). |
---|
214 | n/a | |
---|
215 | n/a | If *callback* is given and is not None, it will be called after |
---|
216 | n/a | each trial with two arguments: ``callback(number, time_taken)``. |
---|
217 | n/a | """ |
---|
218 | n/a | i = 1 |
---|
219 | n/a | while True: |
---|
220 | n/a | for j in 1, 2, 5: |
---|
221 | n/a | number = i * j |
---|
222 | n/a | time_taken = self.timeit(number) |
---|
223 | n/a | if callback: |
---|
224 | n/a | callback(number, time_taken) |
---|
225 | n/a | if time_taken >= 0.2: |
---|
226 | n/a | return (number, time_taken) |
---|
227 | n/a | i *= 10 |
---|
228 | n/a | |
---|
229 | n/a | def timeit(stmt="pass", setup="pass", timer=default_timer, |
---|
230 | n/a | number=default_number, globals=None): |
---|
231 | n/a | """Convenience function to create Timer object and call timeit method.""" |
---|
232 | n/a | return Timer(stmt, setup, timer, globals).timeit(number) |
---|
233 | n/a | |
---|
234 | n/a | def repeat(stmt="pass", setup="pass", timer=default_timer, |
---|
235 | n/a | repeat=default_repeat, number=default_number, globals=None): |
---|
236 | n/a | """Convenience function to create Timer object and call repeat method.""" |
---|
237 | n/a | return Timer(stmt, setup, timer, globals).repeat(repeat, number) |
---|
238 | n/a | |
---|
239 | n/a | def main(args=None, *, _wrap_timer=None): |
---|
240 | n/a | """Main program, used when run as a script. |
---|
241 | n/a | |
---|
242 | n/a | The optional 'args' argument specifies the command line to be parsed, |
---|
243 | n/a | defaulting to sys.argv[1:]. |
---|
244 | n/a | |
---|
245 | n/a | The return value is an exit code to be passed to sys.exit(); it |
---|
246 | n/a | may be None to indicate success. |
---|
247 | n/a | |
---|
248 | n/a | When an exception happens during timing, a traceback is printed to |
---|
249 | n/a | stderr and the return value is 1. Exceptions at other times |
---|
250 | n/a | (including the template compilation) are not caught. |
---|
251 | n/a | |
---|
252 | n/a | '_wrap_timer' is an internal interface used for unit testing. If it |
---|
253 | n/a | is not None, it must be a callable that accepts a timer function |
---|
254 | n/a | and returns another timer function (used for unit testing). |
---|
255 | n/a | """ |
---|
256 | n/a | if args is None: |
---|
257 | n/a | args = sys.argv[1:] |
---|
258 | n/a | import getopt |
---|
259 | n/a | try: |
---|
260 | n/a | opts, args = getopt.getopt(args, "n:u:s:r:tcpvh", |
---|
261 | n/a | ["number=", "setup=", "repeat=", |
---|
262 | n/a | "time", "clock", "process", |
---|
263 | n/a | "verbose", "unit=", "help"]) |
---|
264 | n/a | except getopt.error as err: |
---|
265 | n/a | print(err) |
---|
266 | n/a | print("use -h/--help for command line help") |
---|
267 | n/a | return 2 |
---|
268 | n/a | |
---|
269 | n/a | timer = default_timer |
---|
270 | n/a | stmt = "\n".join(args) or "pass" |
---|
271 | n/a | number = 0 # auto-determine |
---|
272 | n/a | setup = [] |
---|
273 | n/a | repeat = default_repeat |
---|
274 | n/a | verbose = 0 |
---|
275 | n/a | time_unit = None |
---|
276 | n/a | units = {"nsec": 1e-9, "usec": 1e-6, "msec": 1e-3, "sec": 1.0} |
---|
277 | n/a | precision = 3 |
---|
278 | n/a | for o, a in opts: |
---|
279 | n/a | if o in ("-n", "--number"): |
---|
280 | n/a | number = int(a) |
---|
281 | n/a | if o in ("-s", "--setup"): |
---|
282 | n/a | setup.append(a) |
---|
283 | n/a | if o in ("-u", "--unit"): |
---|
284 | n/a | if a in units: |
---|
285 | n/a | time_unit = a |
---|
286 | n/a | else: |
---|
287 | n/a | print("Unrecognized unit. Please select nsec, usec, msec, or sec.", |
---|
288 | n/a | file=sys.stderr) |
---|
289 | n/a | return 2 |
---|
290 | n/a | if o in ("-r", "--repeat"): |
---|
291 | n/a | repeat = int(a) |
---|
292 | n/a | if repeat <= 0: |
---|
293 | n/a | repeat = 1 |
---|
294 | n/a | if o in ("-p", "--process"): |
---|
295 | n/a | timer = time.process_time |
---|
296 | n/a | if o in ("-v", "--verbose"): |
---|
297 | n/a | if verbose: |
---|
298 | n/a | precision += 1 |
---|
299 | n/a | verbose += 1 |
---|
300 | n/a | if o in ("-h", "--help"): |
---|
301 | n/a | print(__doc__, end=' ') |
---|
302 | n/a | return 0 |
---|
303 | n/a | setup = "\n".join(setup) or "pass" |
---|
304 | n/a | |
---|
305 | n/a | # Include the current directory, so that local imports work (sys.path |
---|
306 | n/a | # contains the directory of this script, rather than the current |
---|
307 | n/a | # directory) |
---|
308 | n/a | import os |
---|
309 | n/a | sys.path.insert(0, os.curdir) |
---|
310 | n/a | if _wrap_timer is not None: |
---|
311 | n/a | timer = _wrap_timer(timer) |
---|
312 | n/a | |
---|
313 | n/a | t = Timer(stmt, setup, timer) |
---|
314 | n/a | if number == 0: |
---|
315 | n/a | # determine number so that 0.2 <= total time < 2.0 |
---|
316 | n/a | callback = None |
---|
317 | n/a | if verbose: |
---|
318 | n/a | def callback(number, time_taken): |
---|
319 | n/a | msg = "{num} loop{s} -> {secs:.{prec}g} secs" |
---|
320 | n/a | plural = (number != 1) |
---|
321 | n/a | print(msg.format(num=number, s='s' if plural else '', |
---|
322 | n/a | secs=time_taken, prec=precision)) |
---|
323 | n/a | try: |
---|
324 | n/a | number, _ = t.autorange(callback) |
---|
325 | n/a | except: |
---|
326 | n/a | t.print_exc() |
---|
327 | n/a | return 1 |
---|
328 | n/a | |
---|
329 | n/a | if verbose: |
---|
330 | n/a | print() |
---|
331 | n/a | |
---|
332 | n/a | try: |
---|
333 | n/a | raw_timings = t.repeat(repeat, number) |
---|
334 | n/a | except: |
---|
335 | n/a | t.print_exc() |
---|
336 | n/a | return 1 |
---|
337 | n/a | |
---|
338 | n/a | def format_time(dt): |
---|
339 | n/a | unit = time_unit |
---|
340 | n/a | |
---|
341 | n/a | if unit is not None: |
---|
342 | n/a | scale = units[unit] |
---|
343 | n/a | else: |
---|
344 | n/a | scales = [(scale, unit) for unit, scale in units.items()] |
---|
345 | n/a | scales.sort(reverse=True) |
---|
346 | n/a | for scale, unit in scales: |
---|
347 | n/a | if dt >= scale: |
---|
348 | n/a | break |
---|
349 | n/a | |
---|
350 | n/a | return "%.*g %s" % (precision, dt / scale, unit) |
---|
351 | n/a | |
---|
352 | n/a | if verbose: |
---|
353 | n/a | print("raw times: %s" % ", ".join(map(format_time, raw_timings))) |
---|
354 | n/a | print() |
---|
355 | n/a | timings = [dt / number for dt in raw_timings] |
---|
356 | n/a | |
---|
357 | n/a | best = min(timings) |
---|
358 | n/a | print("%d loop%s, best of %d: %s per loop" |
---|
359 | n/a | % (number, 's' if number != 1 else '', |
---|
360 | n/a | repeat, format_time(best))) |
---|
361 | n/a | |
---|
362 | n/a | best = min(timings) |
---|
363 | n/a | worst = max(timings) |
---|
364 | n/a | if worst >= best * 4: |
---|
365 | n/a | import warnings |
---|
366 | n/a | warnings.warn_explicit("The test results are likely unreliable. " |
---|
367 | n/a | "The worst time (%s) was more than four times " |
---|
368 | n/a | "slower than the best time (%s)." |
---|
369 | n/a | % (format_time(worst), format_time(best)), |
---|
370 | n/a | UserWarning, '', 0) |
---|
371 | n/a | return None |
---|
372 | n/a | |
---|
373 | n/a | if __name__ == "__main__": |
---|
374 | n/a | sys.exit(main()) |
---|