1 | #! /usr/bin/env python
|
---|
2 |
|
---|
3 | """Tool for measuring execution time of small code snippets.
|
---|
4 |
|
---|
5 | This module avoids a number of common traps for measuring execution
|
---|
6 | times. See also Tim Peters' introduction to the Algorithms chapter in
|
---|
7 | the Python Cookbook, published by O'Reilly.
|
---|
8 |
|
---|
9 | Library usage: see the Timer class.
|
---|
10 |
|
---|
11 | Command line usage:
|
---|
12 | python timeit.py [-n N] [-r N] [-s S] [-t] [-c] [-h] [--] [statement]
|
---|
13 |
|
---|
14 | Options:
|
---|
15 | -n/--number N: how many times to execute 'statement' (default: see below)
|
---|
16 | -r/--repeat N: how many times to repeat the timer (default 3)
|
---|
17 | -s/--setup S: statement to be executed once initially (default 'pass')
|
---|
18 | -t/--time: use time.time() (default on Unix)
|
---|
19 | -c/--clock: use time.clock() (default on Windows)
|
---|
20 | -v/--verbose: print raw timing results; repeat for more digits precision
|
---|
21 | -h/--help: print this usage message and exit
|
---|
22 | --: separate options from statement, use when statement starts with -
|
---|
23 | statement: statement to be timed (default 'pass')
|
---|
24 |
|
---|
25 | A multi-line statement may be given by specifying each line as a
|
---|
26 | separate argument; indented lines are possible by enclosing an
|
---|
27 | argument in quotes and using leading spaces. Multiple -s options are
|
---|
28 | treated similarly.
|
---|
29 |
|
---|
30 | If -n is not given, a suitable number of loops is calculated by trying
|
---|
31 | successive powers of 10 until the total time is at least 0.2 seconds.
|
---|
32 |
|
---|
33 | The difference in default timer function is because on Windows,
|
---|
34 | clock() has microsecond granularity but time()'s granularity is 1/60th
|
---|
35 | of a second; on Unix, clock() has 1/100th of a second granularity and
|
---|
36 | time() is much more precise. On either platform, the default timer
|
---|
37 | functions measure wall clock time, not the CPU time. This means that
|
---|
38 | other processes running on the same computer may interfere with the
|
---|
39 | timing. The best thing to do when accurate timing is necessary is to
|
---|
40 | repeat the timing a few times and use the best time. The -r option is
|
---|
41 | good for this; the default of 3 repetitions is probably enough in most
|
---|
42 | cases. On Unix, you can use clock() to measure CPU time.
|
---|
43 |
|
---|
44 | Note: there is a certain baseline overhead associated with executing a
|
---|
45 | pass statement. The code here doesn't try to hide it, but you should
|
---|
46 | be aware of it. The baseline overhead can be measured by invoking the
|
---|
47 | program without arguments.
|
---|
48 |
|
---|
49 | The baseline overhead differs between Python versions! Also, to
|
---|
50 | fairly compare older Python versions to Python 2.3, you may want to
|
---|
51 | use python -O for the older versions to avoid timing SET_LINENO
|
---|
52 | instructions.
|
---|
53 | """
|
---|
54 |
|
---|
55 | import gc
|
---|
56 | import sys
|
---|
57 | import time
|
---|
58 | try:
|
---|
59 | import itertools
|
---|
60 | except ImportError:
|
---|
61 | # Must be an older Python version (see timeit() below)
|
---|
62 | itertools = None
|
---|
63 |
|
---|
64 | __all__ = ["Timer"]
|
---|
65 |
|
---|
66 | dummy_src_name = "<timeit-src>"
|
---|
67 | default_number = 1000000
|
---|
68 | default_repeat = 3
|
---|
69 |
|
---|
70 | if sys.platform == "win32":
|
---|
71 | # On Windows, the best timer is time.clock()
|
---|
72 | default_timer = time.clock
|
---|
73 | else:
|
---|
74 | # On most other platforms the best timer is time.time()
|
---|
75 | default_timer = time.time
|
---|
76 |
|
---|
77 | # Don't change the indentation of the template; the reindent() calls
|
---|
78 | # in Timer.__init__() depend on setup being indented 4 spaces and stmt
|
---|
79 | # being indented 8 spaces.
|
---|
80 | template = """
|
---|
81 | def inner(_it, _timer):
|
---|
82 | %(setup)s
|
---|
83 | _t0 = _timer()
|
---|
84 | for _i in _it:
|
---|
85 | %(stmt)s
|
---|
86 | _t1 = _timer()
|
---|
87 | return _t1 - _t0
|
---|
88 | """
|
---|
89 |
|
---|
90 | def reindent(src, indent):
|
---|
91 | """Helper to reindent a multi-line statement."""
|
---|
92 | return src.replace("\n", "\n" + " "*indent)
|
---|
93 |
|
---|
94 | def _template_func(setup, func):
|
---|
95 | """Create a timer function. Used if the "statement" is a callable."""
|
---|
96 | def inner(_it, _timer, _func=func):
|
---|
97 | setup()
|
---|
98 | _t0 = _timer()
|
---|
99 | for _i in _it:
|
---|
100 | _func()
|
---|
101 | _t1 = _timer()
|
---|
102 | return _t1 - _t0
|
---|
103 | return inner
|
---|
104 |
|
---|
105 | class Timer:
|
---|
106 | """Class for timing execution speed of small code snippets.
|
---|
107 |
|
---|
108 | The constructor takes a statement to be timed, an additional
|
---|
109 | statement used for setup, and a timer function. Both statements
|
---|
110 | default to 'pass'; the timer function is platform-dependent (see
|
---|
111 | module doc string).
|
---|
112 |
|
---|
113 | To measure the execution time of the first statement, use the
|
---|
114 | timeit() method. The repeat() method is a convenience to call
|
---|
115 | timeit() multiple times and return a list of results.
|
---|
116 |
|
---|
117 | The statements may contain newlines, as long as they don't contain
|
---|
118 | multi-line string literals.
|
---|
119 | """
|
---|
120 |
|
---|
121 | def __init__(self, stmt="pass", setup="pass", timer=default_timer):
|
---|
122 | """Constructor. See class doc string."""
|
---|
123 | self.timer = timer
|
---|
124 | ns = {}
|
---|
125 | if isinstance(stmt, basestring):
|
---|
126 | stmt = reindent(stmt, 8)
|
---|
127 | if isinstance(setup, basestring):
|
---|
128 | setup = reindent(setup, 4)
|
---|
129 | src = template % {'stmt': stmt, 'setup': setup}
|
---|
130 | elif hasattr(setup, '__call__'):
|
---|
131 | src = template % {'stmt': stmt, 'setup': '_setup()'}
|
---|
132 | ns['_setup'] = setup
|
---|
133 | else:
|
---|
134 | raise ValueError("setup is neither a string nor callable")
|
---|
135 | self.src = src # Save for traceback display
|
---|
136 | code = compile(src, dummy_src_name, "exec")
|
---|
137 | exec code in globals(), ns
|
---|
138 | self.inner = ns["inner"]
|
---|
139 | elif hasattr(stmt, '__call__'):
|
---|
140 | self.src = None
|
---|
141 | if isinstance(setup, basestring):
|
---|
142 | _setup = setup
|
---|
143 | def setup():
|
---|
144 | exec _setup in globals(), ns
|
---|
145 | elif not hasattr(setup, '__call__'):
|
---|
146 | raise ValueError("setup is neither a string nor callable")
|
---|
147 | self.inner = _template_func(setup, stmt)
|
---|
148 | else:
|
---|
149 | raise ValueError("stmt is neither a string nor callable")
|
---|
150 |
|
---|
151 | def print_exc(self, file=None):
|
---|
152 | """Helper to print a traceback from the timed code.
|
---|
153 |
|
---|
154 | Typical use:
|
---|
155 |
|
---|
156 | t = Timer(...) # outside the try/except
|
---|
157 | try:
|
---|
158 | t.timeit(...) # or t.repeat(...)
|
---|
159 | except:
|
---|
160 | t.print_exc()
|
---|
161 |
|
---|
162 | The advantage over the standard traceback is that source lines
|
---|
163 | in the compiled template will be displayed.
|
---|
164 |
|
---|
165 | The optional file argument directs where the traceback is
|
---|
166 | sent; it defaults to sys.stderr.
|
---|
167 | """
|
---|
168 | import linecache, traceback
|
---|
169 | if self.src is not None:
|
---|
170 | linecache.cache[dummy_src_name] = (len(self.src),
|
---|
171 | None,
|
---|
172 | self.src.split("\n"),
|
---|
173 | dummy_src_name)
|
---|
174 | # else the source is already stored somewhere else
|
---|
175 |
|
---|
176 | traceback.print_exc(file=file)
|
---|
177 |
|
---|
178 | def timeit(self, number=default_number):
|
---|
179 | """Time 'number' executions of the main statement.
|
---|
180 |
|
---|
181 | To be precise, this executes the setup statement once, and
|
---|
182 | then returns the time it takes to execute the main statement
|
---|
183 | a number of times, as a float measured in seconds. The
|
---|
184 | argument is the number of times through the loop, defaulting
|
---|
185 | to one million. The main statement, the setup statement and
|
---|
186 | the timer function to be used are passed to the constructor.
|
---|
187 | """
|
---|
188 | if itertools:
|
---|
189 | it = itertools.repeat(None, number)
|
---|
190 | else:
|
---|
191 | it = [None] * number
|
---|
192 | gcold = gc.isenabled()
|
---|
193 | gc.disable()
|
---|
194 | try:
|
---|
195 | timing = self.inner(it, self.timer)
|
---|
196 | finally:
|
---|
197 | if gcold:
|
---|
198 | gc.enable()
|
---|
199 | return timing
|
---|
200 |
|
---|
201 | def repeat(self, repeat=default_repeat, number=default_number):
|
---|
202 | """Call timeit() a few times.
|
---|
203 |
|
---|
204 | This is a convenience function that calls the timeit()
|
---|
205 | repeatedly, returning a list of results. The first argument
|
---|
206 | specifies how many times to call timeit(), defaulting to 3;
|
---|
207 | the second argument specifies the timer argument, defaulting
|
---|
208 | to one million.
|
---|
209 |
|
---|
210 | Note: it's tempting to calculate mean and standard deviation
|
---|
211 | from the result vector and report these. However, this is not
|
---|
212 | very useful. In a typical case, the lowest value gives a
|
---|
213 | lower bound for how fast your machine can run the given code
|
---|
214 | snippet; higher values in the result vector are typically not
|
---|
215 | caused by variability in Python's speed, but by other
|
---|
216 | processes interfering with your timing accuracy. So the min()
|
---|
217 | of the result is probably the only number you should be
|
---|
218 | interested in. After that, you should look at the entire
|
---|
219 | vector and apply common sense rather than statistics.
|
---|
220 | """
|
---|
221 | r = []
|
---|
222 | for i in range(repeat):
|
---|
223 | t = self.timeit(number)
|
---|
224 | r.append(t)
|
---|
225 | return r
|
---|
226 |
|
---|
227 | def timeit(stmt="pass", setup="pass", timer=default_timer,
|
---|
228 | number=default_number):
|
---|
229 | """Convenience function to create Timer object and call timeit method."""
|
---|
230 | return Timer(stmt, setup, timer).timeit(number)
|
---|
231 |
|
---|
232 | def repeat(stmt="pass", setup="pass", timer=default_timer,
|
---|
233 | repeat=default_repeat, number=default_number):
|
---|
234 | """Convenience function to create Timer object and call repeat method."""
|
---|
235 | return Timer(stmt, setup, timer).repeat(repeat, number)
|
---|
236 |
|
---|
237 | def main(args=None):
|
---|
238 | """Main program, used when run as a script.
|
---|
239 |
|
---|
240 | The optional argument specifies the command line to be parsed,
|
---|
241 | defaulting to sys.argv[1:].
|
---|
242 |
|
---|
243 | The return value is an exit code to be passed to sys.exit(); it
|
---|
244 | may be None to indicate success.
|
---|
245 |
|
---|
246 | When an exception happens during timing, a traceback is printed to
|
---|
247 | stderr and the return value is 1. Exceptions at other times
|
---|
248 | (including the template compilation) are not caught.
|
---|
249 | """
|
---|
250 | if args is None:
|
---|
251 | args = sys.argv[1:]
|
---|
252 | import getopt
|
---|
253 | try:
|
---|
254 | opts, args = getopt.getopt(args, "n:s:r:tcvh",
|
---|
255 | ["number=", "setup=", "repeat=",
|
---|
256 | "time", "clock", "verbose", "help"])
|
---|
257 | except getopt.error, err:
|
---|
258 | print err
|
---|
259 | print "use -h/--help for command line help"
|
---|
260 | return 2
|
---|
261 | timer = default_timer
|
---|
262 | stmt = "\n".join(args) or "pass"
|
---|
263 | number = 0 # auto-determine
|
---|
264 | setup = []
|
---|
265 | repeat = default_repeat
|
---|
266 | verbose = 0
|
---|
267 | precision = 3
|
---|
268 | for o, a in opts:
|
---|
269 | if o in ("-n", "--number"):
|
---|
270 | number = int(a)
|
---|
271 | if o in ("-s", "--setup"):
|
---|
272 | setup.append(a)
|
---|
273 | if o in ("-r", "--repeat"):
|
---|
274 | repeat = int(a)
|
---|
275 | if repeat <= 0:
|
---|
276 | repeat = 1
|
---|
277 | if o in ("-t", "--time"):
|
---|
278 | timer = time.time
|
---|
279 | if o in ("-c", "--clock"):
|
---|
280 | timer = time.clock
|
---|
281 | if o in ("-v", "--verbose"):
|
---|
282 | if verbose:
|
---|
283 | precision += 1
|
---|
284 | verbose += 1
|
---|
285 | if o in ("-h", "--help"):
|
---|
286 | print __doc__,
|
---|
287 | return 0
|
---|
288 | setup = "\n".join(setup) or "pass"
|
---|
289 | # Include the current directory, so that local imports work (sys.path
|
---|
290 | # contains the directory of this script, rather than the current
|
---|
291 | # directory)
|
---|
292 | import os
|
---|
293 | sys.path.insert(0, os.curdir)
|
---|
294 | t = Timer(stmt, setup, timer)
|
---|
295 | if number == 0:
|
---|
296 | # determine number so that 0.2 <= total time < 2.0
|
---|
297 | for i in range(1, 10):
|
---|
298 | number = 10**i
|
---|
299 | try:
|
---|
300 | x = t.timeit(number)
|
---|
301 | except:
|
---|
302 | t.print_exc()
|
---|
303 | return 1
|
---|
304 | if verbose:
|
---|
305 | print "%d loops -> %.*g secs" % (number, precision, x)
|
---|
306 | if x >= 0.2:
|
---|
307 | break
|
---|
308 | try:
|
---|
309 | r = t.repeat(repeat, number)
|
---|
310 | except:
|
---|
311 | t.print_exc()
|
---|
312 | return 1
|
---|
313 | best = min(r)
|
---|
314 | if verbose:
|
---|
315 | print "raw times:", " ".join(["%.*g" % (precision, x) for x in r])
|
---|
316 | print "%d loops," % number,
|
---|
317 | usec = best * 1e6 / number
|
---|
318 | if usec < 1000:
|
---|
319 | print "best of %d: %.*g usec per loop" % (repeat, precision, usec)
|
---|
320 | else:
|
---|
321 | msec = usec / 1000
|
---|
322 | if msec < 1000:
|
---|
323 | print "best of %d: %.*g msec per loop" % (repeat, precision, msec)
|
---|
324 | else:
|
---|
325 | sec = msec / 1000
|
---|
326 | print "best of %d: %.*g sec per loop" % (repeat, precision, sec)
|
---|
327 | return None
|
---|
328 |
|
---|
329 | if __name__ == "__main__":
|
---|
330 | sys.exit(main())
|
---|