blob: de7d5505e46242e757cec88a0cc7a85fc4e540fb [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 = """
Guido van Rossumdd42edc2003-03-21 14:54:19 +000071def inner(_it, _timer):
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
Guido van Rossumd8faa362007-04-27 19:54:29 +000084def _template_func(setup, func):
85 """Create a timer function. Used if the "statement" is a callable."""
Raymond Hettingerb646aa12009-04-03 02:45:36 +000086 def inner(_it, _timer, _func=func):
Guido van Rossumd8faa362007-04-27 19:54:29 +000087 setup()
88 _t0 = _timer()
89 for _i in _it:
Raymond Hettingerb646aa12009-04-03 02:45:36 +000090 _func()
Guido van Rossumd8faa362007-04-27 19:54:29 +000091 _t1 = _timer()
92 return _t1 - _t0
93 return inner
94
Guido van Rossumb3f09d42003-03-05 23:31:58 +000095class Timer:
Guido van Rossumb7ab6002003-03-06 02:32:19 +000096 """Class for timing execution speed of small code snippets.
97
98 The constructor takes a statement to be timed, an additional
99 statement used for setup, and a timer function. Both statements
100 default to 'pass'; the timer function is platform-dependent (see
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400101 module doc string). If 'globals' is specified, the code will be
102 executed within that namespace (as opposed to inside timeit's
103 namespace).
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000104
105 To measure the execution time of the first statement, use the
106 timeit() method. The repeat() method is a convenience to call
107 timeit() multiple times and return a list of results.
108
109 The statements may contain newlines, as long as they don't contain
110 multi-line string literals.
111 """
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000112
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400113 def __init__(self, stmt="pass", setup="pass", timer=default_timer,
114 globals=None):
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000115 """Constructor. See class doc string."""
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000116 self.timer = timer
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400117 local_ns = {}
118 global_ns = _globals() if globals is None else globals
Guido van Rossum3172c5d2007-10-16 18:12:55 +0000119 if isinstance(stmt, str):
Serhiy Storchaka2bef5852015-01-26 12:09:17 +0200120 # Check that the code can be compiled outside a function
121 if isinstance(setup, str):
122 compile(setup, dummy_src_name, "exec")
123 compile(setup + '\n' + stmt, dummy_src_name, "exec")
124 else:
125 compile(stmt, dummy_src_name, "exec")
Guido van Rossumd8faa362007-04-27 19:54:29 +0000126 stmt = reindent(stmt, 8)
Guido van Rossum3172c5d2007-10-16 18:12:55 +0000127 if isinstance(setup, str):
Guido van Rossumd8faa362007-04-27 19:54:29 +0000128 setup = reindent(setup, 4)
Raymond Hettingerc800af42011-04-04 09:28:25 -0700129 src = template.format(stmt=stmt, setup=setup)
Florent Xicluna5d1155c2011-10-28 14:45:05 +0200130 elif callable(setup):
Raymond Hettingerc800af42011-04-04 09:28:25 -0700131 src = template.format(stmt=stmt, setup='_setup()')
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400132 local_ns['_setup'] = setup
Guido van Rossumd8faa362007-04-27 19:54:29 +0000133 else:
134 raise ValueError("setup is neither a string nor callable")
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400135 self.src = src # Save for traceback display
Guido van Rossumd8faa362007-04-27 19:54:29 +0000136 code = compile(src, dummy_src_name, "exec")
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400137 exec(code, global_ns, local_ns)
138 self.inner = local_ns["inner"]
Florent Xicluna5d1155c2011-10-28 14:45:05 +0200139 elif callable(stmt):
Guido van Rossumd8faa362007-04-27 19:54:29 +0000140 self.src = None
Guido van Rossum3172c5d2007-10-16 18:12:55 +0000141 if isinstance(setup, str):
Guido van Rossumd8faa362007-04-27 19:54:29 +0000142 _setup = setup
143 def setup():
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400144 exec(_setup, global_ns, local_ns)
Florent Xicluna5d1155c2011-10-28 14:45:05 +0200145 elif not callable(setup):
Guido van Rossumd8faa362007-04-27 19:54:29 +0000146 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")
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000150
Guido van Rossum538f1d82003-03-14 17:21:00 +0000151 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
Guido van Rossumd8faa362007-04-27 19:54:29 +0000169 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
Guido van Rossum538f1d82003-03-14 17:21:00 +0000176 traceback.print_exc(file=file)
177
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000178 def timeit(self, number=default_number):
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000179 """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 """
Terry Jan Reedyd49af5d2013-03-15 03:04:25 -0400188 it = itertools.repeat(None, number)
Raymond Hettinger816ed1b2004-01-04 03:47:51 +0000189 gcold = gc.isenabled()
190 gc.disable()
Raymond Hettinger3a081f52011-07-29 00:02:04 -0700191 try:
192 timing = self.inner(it, self.timer)
193 finally:
194 if gcold:
195 gc.enable()
Raymond Hettinger816ed1b2004-01-04 03:47:51 +0000196 return timing
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000197
198 def repeat(self, repeat=default_repeat, number=default_number):
Skip Montanarofb2a6cc2003-04-08 19:40:19 +0000199 """Call timeit() a few times.
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000200
Skip Montanarofb2a6cc2003-04-08 19:40:19 +0000201 This is a convenience function that calls the timeit()
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000202 repeatedly, returning a list of results. The first argument
Skip Montanarofb2a6cc2003-04-08 19:40:19 +0000203 specifies how many times to call timeit(), defaulting to 3;
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000204 the second argument specifies the timer argument, defaulting
205 to one million.
Guido van Rossum55735412003-03-06 16:11:17 +0000206
207 Note: it's tempting to calculate mean and standard deviation
208 from the result vector and report these. However, this is not
209 very useful. In a typical case, the lowest value gives a
210 lower bound for how fast your machine can run the given code
211 snippet; higher values in the result vector are typically not
212 caused by variability in Python's speed, but by other
213 processes interfering with your timing accuracy. So the min()
214 of the result is probably the only number you should be
215 interested in. After that, you should look at the entire
216 vector and apply common sense rather than statistics.
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000217 """
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000218 r = []
219 for i in range(repeat):
220 t = self.timeit(number)
221 r.append(t)
222 return r
223
Guido van Rossumd8faa362007-04-27 19:54:29 +0000224def timeit(stmt="pass", setup="pass", timer=default_timer,
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400225 number=default_number, globals=None):
Guido van Rossumd8faa362007-04-27 19:54:29 +0000226 """Convenience function to create Timer object and call timeit method."""
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400227 return Timer(stmt, setup, timer, globals).timeit(number)
Guido van Rossumd8faa362007-04-27 19:54:29 +0000228
229def repeat(stmt="pass", setup="pass", timer=default_timer,
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400230 repeat=default_repeat, number=default_number, globals=None):
Guido van Rossumd8faa362007-04-27 19:54:29 +0000231 """Convenience function to create Timer object and call repeat method."""
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400232 return Timer(stmt, setup, timer, globals).repeat(repeat, number)
Guido van Rossumd8faa362007-04-27 19:54:29 +0000233
R David Murraya88da672011-03-16 17:32:27 -0400234def main(args=None, *, _wrap_timer=None):
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000235 """Main program, used when run as a script.
236
R David Murraya88da672011-03-16 17:32:27 -0400237 The optional 'args' argument specifies the command line to be parsed,
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000238 defaulting to sys.argv[1:].
239
240 The return value is an exit code to be passed to sys.exit(); it
241 may be None to indicate success.
Guido van Rossum538f1d82003-03-14 17:21:00 +0000242
243 When an exception happens during timing, a traceback is printed to
244 stderr and the return value is 1. Exceptions at other times
245 (including the template compilation) are not caught.
R David Murraya88da672011-03-16 17:32:27 -0400246
247 '_wrap_timer' is an internal interface used for unit testing. If it
248 is not None, it must be a callable that accepts a timer function
249 and returns another timer function (used for unit testing).
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000250 """
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000251 if args is None:
252 args = sys.argv[1:]
253 import getopt
254 try:
Robert Collins302dbc62015-03-18 09:54:50 +1300255 opts, args = getopt.getopt(args, "n:u:s:r:tcpvh",
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000256 ["number=", "setup=", "repeat=",
Georg Brandlc9d77b22012-05-01 11:56:22 +0200257 "time", "clock", "process",
Robert Collins302dbc62015-03-18 09:54:50 +1300258 "verbose", "unit=", "help"])
Guido van Rossumb940e112007-01-10 16:19:56 +0000259 except getopt.error as err:
Guido van Rossumbe19ed72007-02-09 05:37:30 +0000260 print(err)
261 print("use -h/--help for command line help")
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000262 return 2
263 timer = default_timer
264 stmt = "\n".join(args) or "pass"
265 number = 0 # auto-determine
Guido van Rossum6e31aad2003-03-07 01:33:18 +0000266 setup = []
Guido van Rossum0070f002003-03-15 12:25:00 +0000267 repeat = default_repeat
268 verbose = 0
Robert Collins302dbc62015-03-18 09:54:50 +1300269 time_unit = None
270 units = {"usec": 1, "msec": 1e3, "sec": 1e6}
Guido van Rossum0070f002003-03-15 12:25:00 +0000271 precision = 3
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000272 for o, a in opts:
273 if o in ("-n", "--number"):
274 number = int(a)
275 if o in ("-s", "--setup"):
Guido van Rossum6e31aad2003-03-07 01:33:18 +0000276 setup.append(a)
Robert Collins302dbc62015-03-18 09:54:50 +1300277 if o in ("-u", "--unit"):
278 if a in units:
279 time_unit = a
280 else:
281 print("Unrecognized unit. Please select usec, msec, or sec.",
282 file=sys.stderr)
283 return 2
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000284 if o in ("-r", "--repeat"):
285 repeat = int(a)
286 if repeat <= 0:
287 repeat = 1
Guido van Rossume8577b72003-03-06 03:02:10 +0000288 if o in ("-t", "--time"):
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000289 timer = time.time
Guido van Rossume8577b72003-03-06 03:02:10 +0000290 if o in ("-c", "--clock"):
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000291 timer = time.clock
Georg Brandlc9d77b22012-05-01 11:56:22 +0200292 if o in ("-p", "--process"):
293 timer = time.process_time
Guido van Rossum0070f002003-03-15 12:25:00 +0000294 if o in ("-v", "--verbose"):
295 if verbose:
296 precision += 1
297 verbose += 1
Guido van Rossume8577b72003-03-06 03:02:10 +0000298 if o in ("-h", "--help"):
Guido van Rossumbe19ed72007-02-09 05:37:30 +0000299 print(__doc__, end=' ')
Guido van Rossume8577b72003-03-06 03:02:10 +0000300 return 0
Guido van Rossum6e31aad2003-03-07 01:33:18 +0000301 setup = "\n".join(setup) or "pass"
Raymond Hettinger22952a32003-05-20 04:59:56 +0000302 # Include the current directory, so that local imports work (sys.path
303 # contains the directory of this script, rather than the current
304 # directory)
305 import os
306 sys.path.insert(0, os.curdir)
R David Murraya88da672011-03-16 17:32:27 -0400307 if _wrap_timer is not None:
308 timer = _wrap_timer(timer)
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000309 t = Timer(stmt, setup, timer)
310 if number == 0:
311 # determine number so that 0.2 <= total time < 2.0
312 for i in range(1, 10):
313 number = 10**i
Guido van Rossum538f1d82003-03-14 17:21:00 +0000314 try:
315 x = t.timeit(number)
316 except:
317 t.print_exc()
318 return 1
Guido van Rossum0070f002003-03-15 12:25:00 +0000319 if verbose:
Guido van Rossumbe19ed72007-02-09 05:37:30 +0000320 print("%d loops -> %.*g secs" % (number, precision, x))
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000321 if x >= 0.2:
322 break
Guido van Rossum538f1d82003-03-14 17:21:00 +0000323 try:
324 r = t.repeat(repeat, number)
325 except:
326 t.print_exc()
327 return 1
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000328 best = min(r)
Guido van Rossum0070f002003-03-15 12:25:00 +0000329 if verbose:
Guido van Rossumbe19ed72007-02-09 05:37:30 +0000330 print("raw times:", " ".join(["%.*g" % (precision, x) for x in r]))
331 print("%d loops," % number, end=' ')
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000332 usec = best * 1e6 / number
Robert Collins302dbc62015-03-18 09:54:50 +1300333 if time_unit is not None:
334 print("best of %d: %.*g %s per loop" % (repeat, precision,
335 usec/units[time_unit], time_unit))
Guido van Rossum57172082003-10-20 23:38:28 +0000336 else:
Robert Collins302dbc62015-03-18 09:54:50 +1300337 if usec < 1000:
338 print("best of %d: %.*g usec per loop" % (repeat, precision, usec))
Guido van Rossum57172082003-10-20 23:38:28 +0000339 else:
Robert Collins302dbc62015-03-18 09:54:50 +1300340 msec = usec / 1000
341 if msec < 1000:
342 print("best of %d: %.*g msec per loop" % (repeat,
343 precision, msec))
344 else:
345 sec = msec / 1000
346 print("best of %d: %.*g sec per loop" % (repeat,
347 precision, sec))
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000348 return None
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000349
350if __name__ == "__main__":
351 sys.exit(main())