blob: 8eea766b4c344b3db306a5026c9f9e29534a8075 [file] [log] [blame]
Benjamin Peterson90f5ba52010-03-11 22:53:45 +00001#! /usr/bin/env python3
Skip Montanarocfd55502003-04-08 19:49:40 +00002
Guido van Rossum6e31aad2003-03-07 01:33:18 +00003"""Tool for measuring execution time of small code snippets.
Guido van Rossumb3f09d42003-03-05 23:31:58 +00004
Guido van Rossumb7ab6002003-03-06 02:32:19 +00005This module avoids a number of common traps for measuring execution
6times. See also Tim Peters' introduction to the Algorithms chapter in
7the Python Cookbook, published by O'Reilly.
Guido van Rossumb3f09d42003-03-05 23:31:58 +00008
Guido van Rossumb7ab6002003-03-06 02:32:19 +00009Library usage: see the Timer class.
Guido van Rossumb3f09d42003-03-05 23:31:58 +000010
11Command line usage:
Georg Brandlc9d77b22012-05-01 11:56:22 +020012 python timeit.py [-n N] [-r N] [-s S] [-t] [-c] [-p] [-h] [--] [statement]
Guido van Rossumb3f09d42003-03-05 23:31:58 +000013
14Options:
Guido van Rossumb7ab6002003-03-06 02:32:19 +000015 -n/--number N: how many times to execute 'statement' (default: see below)
Guido van Rossum0070f002003-03-15 12:25:00 +000016 -r/--repeat N: how many times to repeat the timer (default 3)
Andrew Kuchling333518e2015-04-21 19:43:33 -040017 -s/--setup S: statement to be executed once initially (default 'pass').
18 Execution time of this setup statement is NOT timed.
Georg Brandlc9d77b22012-05-01 11:56:22 +020019 -p/--process: use time.process_time() (default is time.perf_counter())
20 -t/--time: use time.time() (deprecated)
21 -c/--clock: use time.clock() (deprecated)
Guido van Rossum0070f002003-03-15 12:25:00 +000022 -v/--verbose: print raw timing results; repeat for more digits precision
Robert Collins302dbc62015-03-18 09:54:50 +130023 -u/--unit: set the output time unit (usec, msec, or sec)
Guido van Rossume8577b72003-03-06 03:02:10 +000024 -h/--help: print this usage message and exit
Georg Brandl794f5b32010-08-01 08:52:32 +000025 --: separate options from statement, use when statement starts with -
Guido van Rossumb3f09d42003-03-05 23:31:58 +000026 statement: statement to be timed (default 'pass')
Guido van Rossumb7ab6002003-03-06 02:32:19 +000027
28A multi-line statement may be given by specifying each line as a
29separate argument; indented lines are possible by enclosing an
Guido van Rossum6e31aad2003-03-07 01:33:18 +000030argument in quotes and using leading spaces. Multiple -s options are
31treated similarly.
Guido van Rossumb7ab6002003-03-06 02:32:19 +000032
33If -n is not given, a suitable number of loops is calculated by trying
34successive powers of 10 until the total time is at least 0.2 seconds.
35
Guido van Rossume8577b72003-03-06 03:02:10 +000036Note: there is a certain baseline overhead associated with executing a
Terry Jan Reedyd49af5d2013-03-15 03:04:25 -040037pass statement. It differs between versions. The code here doesn't try
38to hide it, but you should be aware of it. The baseline overhead can be
39measured by invoking the program without arguments.
Guido van Rossum6e31aad2003-03-07 01:33:18 +000040
Terry Jan Reedyd49af5d2013-03-15 03:04:25 -040041Classes:
42
43 Timer
44
45Functions:
46
47 timeit(string, string) -> float
48 repeat(string, string) -> list
49 default_timer() -> float
50
Guido van Rossumb3f09d42003-03-05 23:31:58 +000051"""
52
Raymond Hettinger816ed1b2004-01-04 03:47:51 +000053import gc
Guido van Rossumb3f09d42003-03-05 23:31:58 +000054import sys
Guido van Rossumb3f09d42003-03-05 23:31:58 +000055import time
Terry Jan Reedyd49af5d2013-03-15 03:04:25 -040056import itertools
Guido van Rossumb3f09d42003-03-05 23:31:58 +000057
Terry Jan Reedyd49af5d2013-03-15 03:04:25 -040058__all__ = ["Timer", "timeit", "repeat", "default_timer"]
Guido van Rossumb3f09d42003-03-05 23:31:58 +000059
Guido van Rossum538f1d82003-03-14 17:21:00 +000060dummy_src_name = "<timeit-src>"
Guido van Rossumb3f09d42003-03-05 23:31:58 +000061default_number = 1000000
Guido van Rossum0070f002003-03-15 12:25:00 +000062default_repeat = 3
Victor Stinnerfe98e2f2012-04-29 03:01:20 +020063default_timer = time.perf_counter
Guido van Rossumb3f09d42003-03-05 23:31:58 +000064
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -040065_globals = globals
66
Guido van Rossumb7ab6002003-03-06 02:32:19 +000067# Don't change the indentation of the template; the reindent() calls
68# in Timer.__init__() depend on setup being indented 4 spaces and stmt
69# being indented 8 spaces.
Guido van Rossumb3f09d42003-03-05 23:31:58 +000070template = """
Serhiy Storchakaf28fa662015-05-30 19:38:26 +030071def inner(_it, _timer{init}):
Raymond Hettingerc800af42011-04-04 09:28:25 -070072 {setup}
Guido van Rossum538f1d82003-03-14 17:21:00 +000073 _t0 = _timer()
Guido van Rossumdd42edc2003-03-21 14:54:19 +000074 for _i in _it:
Raymond Hettingerc800af42011-04-04 09:28:25 -070075 {stmt}
Guido van Rossum538f1d82003-03-14 17:21:00 +000076 _t1 = _timer()
77 return _t1 - _t0
Guido van Rossumb3f09d42003-03-05 23:31:58 +000078"""
79
80def reindent(src, indent):
Guido van Rossumb7ab6002003-03-06 02:32:19 +000081 """Helper to reindent a multi-line statement."""
Guido van Rossume05dcce2003-03-06 13:09:09 +000082 return src.replace("\n", "\n" + " "*indent)
Guido van Rossumb3f09d42003-03-05 23:31:58 +000083
84class Timer:
Guido van Rossumb7ab6002003-03-06 02:32:19 +000085 """Class for timing execution speed of small code snippets.
86
87 The constructor takes a statement to be timed, an additional
88 statement used for setup, and a timer function. Both statements
89 default to 'pass'; the timer function is platform-dependent (see
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -040090 module doc string). If 'globals' is specified, the code will be
91 executed within that namespace (as opposed to inside timeit's
92 namespace).
Guido van Rossumb7ab6002003-03-06 02:32:19 +000093
94 To measure the execution time of the first statement, use the
95 timeit() method. The repeat() method is a convenience to call
96 timeit() multiple times and return a list of results.
97
98 The statements may contain newlines, as long as they don't contain
99 multi-line string literals.
100 """
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000101
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400102 def __init__(self, stmt="pass", setup="pass", timer=default_timer,
103 globals=None):
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000104 """Constructor. See class doc string."""
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000105 self.timer = timer
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400106 local_ns = {}
107 global_ns = _globals() if globals is None else globals
Serhiy Storchaka1b560cb2015-05-30 19:44:55 +0300108 init = ''
109 if isinstance(setup, str):
110 # Check that the code can be compiled outside a function
111 compile(setup, dummy_src_name, "exec")
Serhiy Storchakaced770d2015-07-15 22:11:36 +0300112 stmtprefix = setup + '\n'
Serhiy Storchaka1b560cb2015-05-30 19:44:55 +0300113 setup = reindent(setup, 4)
114 elif callable(setup):
115 local_ns['_setup'] = setup
116 init += ', _setup=_setup'
Serhiy Storchakaced770d2015-07-15 22:11:36 +0300117 stmtprefix = ''
Serhiy Storchaka1b560cb2015-05-30 19:44:55 +0300118 setup = '_setup()'
119 else:
120 raise ValueError("setup is neither a string nor callable")
Guido van Rossum3172c5d2007-10-16 18:12:55 +0000121 if isinstance(stmt, str):
Serhiy Storchaka2bef5852015-01-26 12:09:17 +0200122 # Check that the code can be compiled outside a function
Serhiy Storchakaced770d2015-07-15 22:11:36 +0300123 compile(stmtprefix + stmt, dummy_src_name, "exec")
Guido van Rossumd8faa362007-04-27 19:54:29 +0000124 stmt = reindent(stmt, 8)
Florent Xicluna5d1155c2011-10-28 14:45:05 +0200125 elif callable(stmt):
Serhiy Storchaka1b560cb2015-05-30 19:44:55 +0300126 local_ns['_stmt'] = stmt
127 init += ', _stmt=_stmt'
128 stmt = '_stmt()'
Guido van Rossumd8faa362007-04-27 19:54:29 +0000129 else:
130 raise ValueError("stmt is neither a string nor callable")
Serhiy Storchaka1b560cb2015-05-30 19:44:55 +0300131 src = template.format(stmt=stmt, setup=setup, init=init)
132 self.src = src # Save for traceback display
133 code = compile(src, dummy_src_name, "exec")
134 exec(code, global_ns, local_ns)
135 self.inner = local_ns["inner"]
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000136
Guido van Rossum538f1d82003-03-14 17:21:00 +0000137 def print_exc(self, file=None):
138 """Helper to print a traceback from the timed code.
139
140 Typical use:
141
142 t = Timer(...) # outside the try/except
143 try:
144 t.timeit(...) # or t.repeat(...)
145 except:
146 t.print_exc()
147
148 The advantage over the standard traceback is that source lines
149 in the compiled template will be displayed.
150
151 The optional file argument directs where the traceback is
152 sent; it defaults to sys.stderr.
153 """
154 import linecache, traceback
Guido van Rossumd8faa362007-04-27 19:54:29 +0000155 if self.src is not None:
156 linecache.cache[dummy_src_name] = (len(self.src),
157 None,
158 self.src.split("\n"),
159 dummy_src_name)
160 # else the source is already stored somewhere else
161
Guido van Rossum538f1d82003-03-14 17:21:00 +0000162 traceback.print_exc(file=file)
163
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000164 def timeit(self, number=default_number):
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000165 """Time 'number' executions of the main statement.
166
167 To be precise, this executes the setup statement once, and
168 then returns the time it takes to execute the main statement
169 a number of times, as a float measured in seconds. The
170 argument is the number of times through the loop, defaulting
171 to one million. The main statement, the setup statement and
172 the timer function to be used are passed to the constructor.
173 """
Terry Jan Reedyd49af5d2013-03-15 03:04:25 -0400174 it = itertools.repeat(None, number)
Raymond Hettinger816ed1b2004-01-04 03:47:51 +0000175 gcold = gc.isenabled()
176 gc.disable()
Raymond Hettinger3a081f52011-07-29 00:02:04 -0700177 try:
178 timing = self.inner(it, self.timer)
179 finally:
180 if gcold:
181 gc.enable()
Raymond Hettinger816ed1b2004-01-04 03:47:51 +0000182 return timing
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000183
184 def repeat(self, repeat=default_repeat, number=default_number):
Skip Montanarofb2a6cc2003-04-08 19:40:19 +0000185 """Call timeit() a few times.
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000186
Skip Montanarofb2a6cc2003-04-08 19:40:19 +0000187 This is a convenience function that calls the timeit()
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000188 repeatedly, returning a list of results. The first argument
Skip Montanarofb2a6cc2003-04-08 19:40:19 +0000189 specifies how many times to call timeit(), defaulting to 3;
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000190 the second argument specifies the timer argument, defaulting
191 to one million.
Guido van Rossum55735412003-03-06 16:11:17 +0000192
193 Note: it's tempting to calculate mean and standard deviation
194 from the result vector and report these. However, this is not
195 very useful. In a typical case, the lowest value gives a
196 lower bound for how fast your machine can run the given code
197 snippet; higher values in the result vector are typically not
198 caused by variability in Python's speed, but by other
199 processes interfering with your timing accuracy. So the min()
200 of the result is probably the only number you should be
201 interested in. After that, you should look at the entire
202 vector and apply common sense rather than statistics.
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000203 """
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000204 r = []
205 for i in range(repeat):
206 t = self.timeit(number)
207 r.append(t)
208 return r
209
Steven D'Aprano09f4f712016-08-15 01:27:03 +1000210 def autorange(self, callback=None):
Xiang Zhangc4a786b2017-02-28 11:28:44 +0800211 """Return the number of loops and time taken so that total time >= 0.2.
Steven D'Aprano09f4f712016-08-15 01:27:03 +1000212
213 Calls the timeit method with *number* set to successive powers of
214 ten (10, 100, 1000, ...) up to a maximum of one billion, until
215 the time taken is at least 0.2 second, or the maximum is reached.
216 Returns ``(number, time_taken)``.
217
218 If *callback* is given and is not None, it will be called after
219 each trial with two arguments: ``callback(number, time_taken)``.
220 """
221 for i in range(1, 10):
222 number = 10**i
223 time_taken = self.timeit(number)
224 if callback:
225 callback(number, time_taken)
226 if time_taken >= 0.2:
227 break
228 return (number, time_taken)
229
Guido van Rossumd8faa362007-04-27 19:54:29 +0000230def timeit(stmt="pass", setup="pass", timer=default_timer,
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400231 number=default_number, globals=None):
Guido van Rossumd8faa362007-04-27 19:54:29 +0000232 """Convenience function to create Timer object and call timeit method."""
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400233 return Timer(stmt, setup, timer, globals).timeit(number)
Guido van Rossumd8faa362007-04-27 19:54:29 +0000234
235def repeat(stmt="pass", setup="pass", timer=default_timer,
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400236 repeat=default_repeat, number=default_number, globals=None):
Guido van Rossumd8faa362007-04-27 19:54:29 +0000237 """Convenience function to create Timer object and call repeat method."""
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400238 return Timer(stmt, setup, timer, globals).repeat(repeat, number)
Guido van Rossumd8faa362007-04-27 19:54:29 +0000239
R David Murraya88da672011-03-16 17:32:27 -0400240def main(args=None, *, _wrap_timer=None):
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000241 """Main program, used when run as a script.
242
R David Murraya88da672011-03-16 17:32:27 -0400243 The optional 'args' argument specifies the command line to be parsed,
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000244 defaulting to sys.argv[1:].
245
246 The return value is an exit code to be passed to sys.exit(); it
247 may be None to indicate success.
Guido van Rossum538f1d82003-03-14 17:21:00 +0000248
249 When an exception happens during timing, a traceback is printed to
250 stderr and the return value is 1. Exceptions at other times
251 (including the template compilation) are not caught.
R David Murraya88da672011-03-16 17:32:27 -0400252
253 '_wrap_timer' is an internal interface used for unit testing. If it
254 is not None, it must be a callable that accepts a timer function
255 and returns another timer function (used for unit testing).
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000256 """
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000257 if args is None:
258 args = sys.argv[1:]
259 import getopt
260 try:
Robert Collins302dbc62015-03-18 09:54:50 +1300261 opts, args = getopt.getopt(args, "n:u:s:r:tcpvh",
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000262 ["number=", "setup=", "repeat=",
Georg Brandlc9d77b22012-05-01 11:56:22 +0200263 "time", "clock", "process",
Robert Collins302dbc62015-03-18 09:54:50 +1300264 "verbose", "unit=", "help"])
Guido van Rossumb940e112007-01-10 16:19:56 +0000265 except getopt.error as err:
Guido van Rossumbe19ed72007-02-09 05:37:30 +0000266 print(err)
267 print("use -h/--help for command line help")
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000268 return 2
269 timer = default_timer
270 stmt = "\n".join(args) or "pass"
271 number = 0 # auto-determine
Guido van Rossum6e31aad2003-03-07 01:33:18 +0000272 setup = []
Guido van Rossum0070f002003-03-15 12:25:00 +0000273 repeat = default_repeat
274 verbose = 0
Robert Collins302dbc62015-03-18 09:54:50 +1300275 time_unit = None
276 units = {"usec": 1, "msec": 1e3, "sec": 1e6}
Guido van Rossum0070f002003-03-15 12:25:00 +0000277 precision = 3
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000278 for o, a in opts:
279 if o in ("-n", "--number"):
280 number = int(a)
281 if o in ("-s", "--setup"):
Guido van Rossum6e31aad2003-03-07 01:33:18 +0000282 setup.append(a)
Robert Collins302dbc62015-03-18 09:54:50 +1300283 if o in ("-u", "--unit"):
284 if a in units:
285 time_unit = a
286 else:
287 print("Unrecognized unit. Please select usec, msec, or sec.",
288 file=sys.stderr)
289 return 2
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000290 if o in ("-r", "--repeat"):
291 repeat = int(a)
292 if repeat <= 0:
293 repeat = 1
Guido van Rossume8577b72003-03-06 03:02:10 +0000294 if o in ("-t", "--time"):
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000295 timer = time.time
Guido van Rossume8577b72003-03-06 03:02:10 +0000296 if o in ("-c", "--clock"):
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000297 timer = time.clock
Georg Brandlc9d77b22012-05-01 11:56:22 +0200298 if o in ("-p", "--process"):
299 timer = time.process_time
Guido van Rossum0070f002003-03-15 12:25:00 +0000300 if o in ("-v", "--verbose"):
301 if verbose:
302 precision += 1
303 verbose += 1
Guido van Rossume8577b72003-03-06 03:02:10 +0000304 if o in ("-h", "--help"):
Guido van Rossumbe19ed72007-02-09 05:37:30 +0000305 print(__doc__, end=' ')
Guido van Rossume8577b72003-03-06 03:02:10 +0000306 return 0
Guido van Rossum6e31aad2003-03-07 01:33:18 +0000307 setup = "\n".join(setup) or "pass"
Raymond Hettinger22952a32003-05-20 04:59:56 +0000308 # Include the current directory, so that local imports work (sys.path
309 # contains the directory of this script, rather than the current
310 # directory)
311 import os
312 sys.path.insert(0, os.curdir)
R David Murraya88da672011-03-16 17:32:27 -0400313 if _wrap_timer is not None:
314 timer = _wrap_timer(timer)
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000315 t = Timer(stmt, setup, timer)
316 if number == 0:
317 # determine number so that 0.2 <= total time < 2.0
Steven D'Aprano09f4f712016-08-15 01:27:03 +1000318 callback = None
319 if verbose:
320 def callback(number, time_taken):
321 msg = "{num} loops -> {secs:.{prec}g} secs"
322 print(msg.format(num=number, secs=time_taken, prec=precision))
323 try:
324 number, _ = t.autorange(callback)
325 except:
326 t.print_exc()
327 return 1
Guido van Rossum538f1d82003-03-14 17:21:00 +0000328 try:
329 r = t.repeat(repeat, number)
330 except:
331 t.print_exc()
332 return 1
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000333 best = min(r)
Guido van Rossum0070f002003-03-15 12:25:00 +0000334 if verbose:
Guido van Rossumbe19ed72007-02-09 05:37:30 +0000335 print("raw times:", " ".join(["%.*g" % (precision, x) for x in r]))
336 print("%d loops," % number, end=' ')
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000337 usec = best * 1e6 / number
Robert Collins302dbc62015-03-18 09:54:50 +1300338 if time_unit is not None:
Robert Collins69de2a52015-08-26 12:40:28 +1200339 scale = units[time_unit]
Guido van Rossum57172082003-10-20 23:38:28 +0000340 else:
Robert Collins69de2a52015-08-26 12:40:28 +1200341 scales = [(scale, unit) for unit, scale in units.items()]
342 scales.sort(reverse=True)
343 for scale, time_unit in scales:
344 if usec >= scale:
345 break
346 print("best of %d: %.*g %s per loop" % (repeat, precision,
347 usec/scale, time_unit))
348 best = min(r)
349 usec = best * 1e6 / number
350 worst = max(r)
351 if worst >= best * 4:
352 usec = worst * 1e6 / number
353 import warnings
354 warnings.warn_explicit(
355 "The test results are likely unreliable. The worst\n"
356 "time (%.*g %s) was more than four times slower than the best time." %
357 (precision, usec/scale, time_unit),
358 UserWarning, '', 0)
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000359 return None
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000360
361if __name__ == "__main__":
362 sys.exit(main())