blob: 6c3ec01067f2d415a87eda572b8727be383d0141 [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:
Victor Stinner3d7feb92016-10-18 17:18:21 +020012 python timeit.py [-n N] [-r N] [-s S] [-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)
Victor Stinner3ef769f2018-06-06 17:55:18 +020016 -r/--repeat N: how many times to repeat the timer (default 5)
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())
Guido van Rossum0070f002003-03-15 12:25:00 +000020 -v/--verbose: print raw timing results; repeat for more digits precision
Victor Stinnerc3e40f82016-10-18 17:42:48 +020021 -u/--unit: set the output time unit (nsec, usec, msec, or sec)
Guido van Rossume8577b72003-03-06 03:02:10 +000022 -h/--help: print this usage message and exit
Georg Brandl794f5b32010-08-01 08:52:32 +000023 --: separate options from statement, use when statement starts with -
Guido van Rossumb3f09d42003-03-05 23:31:58 +000024 statement: statement to be timed (default 'pass')
Guido van Rossumb7ab6002003-03-06 02:32:19 +000025
26A multi-line statement may be given by specifying each line as a
27separate argument; indented lines are possible by enclosing an
Guido van Rossum6e31aad2003-03-07 01:33:18 +000028argument in quotes and using leading spaces. Multiple -s options are
29treated similarly.
Guido van Rossumb7ab6002003-03-06 02:32:19 +000030
31If -n is not given, a suitable number of loops is calculated by trying
Sander76635232020-05-02 18:12:05 +020032increasing numbers from the sequence 1, 2, 5, 10, 20, 50, ... until the
33total time is at least 0.2 seconds.
Guido van Rossumb7ab6002003-03-06 02:32:19 +000034
Guido van Rossume8577b72003-03-06 03:02:10 +000035Note: there is a certain baseline overhead associated with executing a
Terry Jan Reedyd49af5d2013-03-15 03:04:25 -040036pass statement. It differs between versions. The code here doesn't try
37to hide it, but you should be aware of it. The baseline overhead can be
38measured by invoking the program without arguments.
Guido van Rossum6e31aad2003-03-07 01:33:18 +000039
Terry Jan Reedyd49af5d2013-03-15 03:04:25 -040040Classes:
41
42 Timer
43
44Functions:
45
46 timeit(string, string) -> float
47 repeat(string, string) -> list
48 default_timer() -> float
49
Guido van Rossumb3f09d42003-03-05 23:31:58 +000050"""
51
Raymond Hettinger816ed1b2004-01-04 03:47:51 +000052import gc
Guido van Rossumb3f09d42003-03-05 23:31:58 +000053import sys
Guido van Rossumb3f09d42003-03-05 23:31:58 +000054import time
Terry Jan Reedyd49af5d2013-03-15 03:04:25 -040055import itertools
Guido van Rossumb3f09d42003-03-05 23:31:58 +000056
Terry Jan Reedyd49af5d2013-03-15 03:04:25 -040057__all__ = ["Timer", "timeit", "repeat", "default_timer"]
Guido van Rossumb3f09d42003-03-05 23:31:58 +000058
Guido van Rossum538f1d82003-03-14 17:21:00 +000059dummy_src_name = "<timeit-src>"
Guido van Rossumb3f09d42003-03-05 23:31:58 +000060default_number = 1000000
Victor Stinner1b901152016-10-18 17:13:22 +020061default_repeat = 5
Victor Stinnerfe98e2f2012-04-29 03:01:20 +020062default_timer = time.perf_counter
Guido van Rossumb3f09d42003-03-05 23:31:58 +000063
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -040064_globals = globals
65
Guido van Rossumb7ab6002003-03-06 02:32:19 +000066# Don't change the indentation of the template; the reindent() calls
67# in Timer.__init__() depend on setup being indented 4 spaces and stmt
68# being indented 8 spaces.
Guido van Rossumb3f09d42003-03-05 23:31:58 +000069template = """
Serhiy Storchakaf28fa662015-05-30 19:38:26 +030070def inner(_it, _timer{init}):
Raymond Hettingerc800af42011-04-04 09:28:25 -070071 {setup}
Guido van Rossum538f1d82003-03-14 17:21:00 +000072 _t0 = _timer()
Guido van Rossumdd42edc2003-03-21 14:54:19 +000073 for _i in _it:
Raymond Hettingerc800af42011-04-04 09:28:25 -070074 {stmt}
Guido van Rossum538f1d82003-03-14 17:21:00 +000075 _t1 = _timer()
76 return _t1 - _t0
Guido van Rossumb3f09d42003-03-05 23:31:58 +000077"""
78
79def reindent(src, indent):
Guido van Rossumb7ab6002003-03-06 02:32:19 +000080 """Helper to reindent a multi-line statement."""
Guido van Rossume05dcce2003-03-06 13:09:09 +000081 return src.replace("\n", "\n" + " "*indent)
Guido van Rossumb3f09d42003-03-05 23:31:58 +000082
83class Timer:
Guido van Rossumb7ab6002003-03-06 02:32:19 +000084 """Class for timing execution speed of small code snippets.
85
86 The constructor takes a statement to be timed, an additional
87 statement used for setup, and a timer function. Both statements
88 default to 'pass'; the timer function is platform-dependent (see
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -040089 module doc string). If 'globals' is specified, the code will be
90 executed within that namespace (as opposed to inside timeit's
91 namespace).
Guido van Rossumb7ab6002003-03-06 02:32:19 +000092
93 To measure the execution time of the first statement, use the
94 timeit() method. The repeat() method is a convenience to call
95 timeit() multiple times and return a list of results.
96
97 The statements may contain newlines, as long as they don't contain
98 multi-line string literals.
99 """
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000100
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400101 def __init__(self, stmt="pass", setup="pass", timer=default_timer,
102 globals=None):
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000103 """Constructor. See class doc string."""
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000104 self.timer = timer
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400105 local_ns = {}
106 global_ns = _globals() if globals is None else globals
Serhiy Storchaka1b560cb2015-05-30 19:44:55 +0300107 init = ''
108 if isinstance(setup, str):
109 # Check that the code can be compiled outside a function
110 compile(setup, dummy_src_name, "exec")
Serhiy Storchakaced770d2015-07-15 22:11:36 +0300111 stmtprefix = setup + '\n'
Serhiy Storchaka1b560cb2015-05-30 19:44:55 +0300112 setup = reindent(setup, 4)
113 elif callable(setup):
114 local_ns['_setup'] = setup
115 init += ', _setup=_setup'
Serhiy Storchakaced770d2015-07-15 22:11:36 +0300116 stmtprefix = ''
Serhiy Storchaka1b560cb2015-05-30 19:44:55 +0300117 setup = '_setup()'
118 else:
119 raise ValueError("setup is neither a string nor callable")
Guido van Rossum3172c5d2007-10-16 18:12:55 +0000120 if isinstance(stmt, str):
Serhiy Storchaka2bef5852015-01-26 12:09:17 +0200121 # Check that the code can be compiled outside a function
Serhiy Storchakaced770d2015-07-15 22:11:36 +0300122 compile(stmtprefix + stmt, dummy_src_name, "exec")
Guido van Rossumd8faa362007-04-27 19:54:29 +0000123 stmt = reindent(stmt, 8)
Florent Xicluna5d1155c2011-10-28 14:45:05 +0200124 elif callable(stmt):
Serhiy Storchaka1b560cb2015-05-30 19:44:55 +0300125 local_ns['_stmt'] = stmt
126 init += ', _stmt=_stmt'
127 stmt = '_stmt()'
Guido van Rossumd8faa362007-04-27 19:54:29 +0000128 else:
129 raise ValueError("stmt is neither a string nor callable")
Serhiy Storchaka1b560cb2015-05-30 19:44:55 +0300130 src = template.format(stmt=stmt, setup=setup, init=init)
131 self.src = src # Save for traceback display
132 code = compile(src, dummy_src_name, "exec")
133 exec(code, global_ns, local_ns)
134 self.inner = local_ns["inner"]
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000135
Guido van Rossum538f1d82003-03-14 17:21:00 +0000136 def print_exc(self, file=None):
137 """Helper to print a traceback from the timed code.
138
139 Typical use:
140
141 t = Timer(...) # outside the try/except
142 try:
143 t.timeit(...) # or t.repeat(...)
144 except:
145 t.print_exc()
146
147 The advantage over the standard traceback is that source lines
148 in the compiled template will be displayed.
149
150 The optional file argument directs where the traceback is
151 sent; it defaults to sys.stderr.
152 """
153 import linecache, traceback
Guido van Rossumd8faa362007-04-27 19:54:29 +0000154 if self.src is not None:
155 linecache.cache[dummy_src_name] = (len(self.src),
156 None,
157 self.src.split("\n"),
158 dummy_src_name)
159 # else the source is already stored somewhere else
160
Guido van Rossum538f1d82003-03-14 17:21:00 +0000161 traceback.print_exc(file=file)
162
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000163 def timeit(self, number=default_number):
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000164 """Time 'number' executions of the main statement.
165
166 To be precise, this executes the setup statement once, and
167 then returns the time it takes to execute the main statement
168 a number of times, as a float measured in seconds. The
169 argument is the number of times through the loop, defaulting
170 to one million. The main statement, the setup statement and
171 the timer function to be used are passed to the constructor.
172 """
Terry Jan Reedyd49af5d2013-03-15 03:04:25 -0400173 it = itertools.repeat(None, number)
Raymond Hettinger816ed1b2004-01-04 03:47:51 +0000174 gcold = gc.isenabled()
175 gc.disable()
Raymond Hettinger3a081f52011-07-29 00:02:04 -0700176 try:
177 timing = self.inner(it, self.timer)
178 finally:
179 if gcold:
180 gc.enable()
Raymond Hettinger816ed1b2004-01-04 03:47:51 +0000181 return timing
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000182
183 def repeat(self, repeat=default_repeat, number=default_number):
Skip Montanarofb2a6cc2003-04-08 19:40:19 +0000184 """Call timeit() a few times.
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000185
Skip Montanarofb2a6cc2003-04-08 19:40:19 +0000186 This is a convenience function that calls the timeit()
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000187 repeatedly, returning a list of results. The first argument
Victor Stinner3ef769f2018-06-06 17:55:18 +0200188 specifies how many times to call timeit(), defaulting to 5;
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000189 the second argument specifies the timer argument, defaulting
190 to one million.
Guido van Rossum55735412003-03-06 16:11:17 +0000191
192 Note: it's tempting to calculate mean and standard deviation
193 from the result vector and report these. However, this is not
194 very useful. In a typical case, the lowest value gives a
195 lower bound for how fast your machine can run the given code
196 snippet; higher values in the result vector are typically not
197 caused by variability in Python's speed, but by other
198 processes interfering with your timing accuracy. So the min()
199 of the result is probably the only number you should be
200 interested in. After that, you should look at the entire
201 vector and apply common sense rather than statistics.
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000202 """
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000203 r = []
204 for i in range(repeat):
205 t = self.timeit(number)
206 r.append(t)
207 return r
208
Steven D'Aprano09f4f712016-08-15 01:27:03 +1000209 def autorange(self, callback=None):
Xiang Zhangecf39bb2017-02-28 11:06:07 +0800210 """Return the number of loops and time taken so that total time >= 0.2.
Steven D'Aprano09f4f712016-08-15 01:27:03 +1000211
Serhiy Storchakad3ff7842016-10-23 15:17:05 +0300212 Calls the timeit method with increasing numbers from the sequence
213 1, 2, 5, 10, 20, 50, ... until the time taken is at least 0.2
214 second. Returns (number, time_taken).
Steven D'Aprano09f4f712016-08-15 01:27:03 +1000215
216 If *callback* is given and is not None, it will be called after
217 each trial with two arguments: ``callback(number, time_taken)``.
218 """
Serhiy Storchakad3ff7842016-10-23 15:17:05 +0300219 i = 1
220 while True:
221 for j in 1, 2, 5:
222 number = i * j
223 time_taken = self.timeit(number)
224 if callback:
225 callback(number, time_taken)
226 if time_taken >= 0.2:
227 return (number, time_taken)
228 i *= 10
Steven D'Aprano09f4f712016-08-15 01:27:03 +1000229
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
Victor Stinner61de57f2016-10-18 17:56:42 +0200269
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000270 timer = default_timer
271 stmt = "\n".join(args) or "pass"
272 number = 0 # auto-determine
Guido van Rossum6e31aad2003-03-07 01:33:18 +0000273 setup = []
Guido van Rossum0070f002003-03-15 12:25:00 +0000274 repeat = default_repeat
275 verbose = 0
Robert Collins302dbc62015-03-18 09:54:50 +1300276 time_unit = None
Victor Stinnerc3e40f82016-10-18 17:42:48 +0200277 units = {"nsec": 1e-9, "usec": 1e-6, "msec": 1e-3, "sec": 1.0}
Guido van Rossum0070f002003-03-15 12:25:00 +0000278 precision = 3
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000279 for o, a in opts:
280 if o in ("-n", "--number"):
281 number = int(a)
282 if o in ("-s", "--setup"):
Guido van Rossum6e31aad2003-03-07 01:33:18 +0000283 setup.append(a)
Robert Collins302dbc62015-03-18 09:54:50 +1300284 if o in ("-u", "--unit"):
285 if a in units:
286 time_unit = a
287 else:
Victor Stinnerc3e40f82016-10-18 17:42:48 +0200288 print("Unrecognized unit. Please select nsec, usec, msec, or sec.",
Robert Collins302dbc62015-03-18 09:54:50 +1300289 file=sys.stderr)
290 return 2
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000291 if o in ("-r", "--repeat"):
292 repeat = int(a)
293 if repeat <= 0:
294 repeat = 1
Georg Brandlc9d77b22012-05-01 11:56:22 +0200295 if o in ("-p", "--process"):
296 timer = time.process_time
Guido van Rossum0070f002003-03-15 12:25:00 +0000297 if o in ("-v", "--verbose"):
298 if verbose:
299 precision += 1
300 verbose += 1
Guido van Rossume8577b72003-03-06 03:02:10 +0000301 if o in ("-h", "--help"):
Guido van Rossumbe19ed72007-02-09 05:37:30 +0000302 print(__doc__, end=' ')
Guido van Rossume8577b72003-03-06 03:02:10 +0000303 return 0
Guido van Rossum6e31aad2003-03-07 01:33:18 +0000304 setup = "\n".join(setup) or "pass"
Victor Stinner61de57f2016-10-18 17:56:42 +0200305
Raymond Hettinger22952a32003-05-20 04:59:56 +0000306 # Include the current directory, so that local imports work (sys.path
307 # contains the directory of this script, rather than the current
308 # directory)
309 import os
310 sys.path.insert(0, os.curdir)
R David Murraya88da672011-03-16 17:32:27 -0400311 if _wrap_timer is not None:
312 timer = _wrap_timer(timer)
Victor Stinner61de57f2016-10-18 17:56:42 +0200313
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000314 t = Timer(stmt, setup, timer)
315 if number == 0:
316 # determine number so that 0.2 <= total time < 2.0
Steven D'Aprano09f4f712016-08-15 01:27:03 +1000317 callback = None
318 if verbose:
319 def callback(number, time_taken):
Victor Stinnerf8fb82c2016-10-18 17:06:56 +0200320 msg = "{num} loop{s} -> {secs:.{prec}g} secs"
321 plural = (number != 1)
322 print(msg.format(num=number, s='s' if plural else '',
323 secs=time_taken, prec=precision))
Steven D'Aprano09f4f712016-08-15 01:27:03 +1000324 try:
325 number, _ = t.autorange(callback)
326 except:
327 t.print_exc()
328 return 1
Victor Stinner61de57f2016-10-18 17:56:42 +0200329
Victor Stinner62cca922016-10-18 17:55:18 +0200330 if verbose:
331 print()
332
Guido van Rossum538f1d82003-03-14 17:21:00 +0000333 try:
Victor Stinner61de57f2016-10-18 17:56:42 +0200334 raw_timings = t.repeat(repeat, number)
Guido van Rossum538f1d82003-03-14 17:21:00 +0000335 except:
336 t.print_exc()
337 return 1
Victor Stinner61de57f2016-10-18 17:56:42 +0200338
339 def format_time(dt):
340 unit = time_unit
341
342 if unit is not None:
343 scale = units[unit]
344 else:
345 scales = [(scale, unit) for unit, scale in units.items()]
346 scales.sort(reverse=True)
347 for scale, unit in scales:
348 if dt >= scale:
349 break
350
351 return "%.*g %s" % (precision, dt / scale, unit)
352
Guido van Rossum0070f002003-03-15 12:25:00 +0000353 if verbose:
Victor Stinner61de57f2016-10-18 17:56:42 +0200354 print("raw times: %s" % ", ".join(map(format_time, raw_timings)))
Victor Stinner62cca922016-10-18 17:55:18 +0200355 print()
Victor Stinner61de57f2016-10-18 17:56:42 +0200356 timings = [dt / number for dt in raw_timings]
357
358 best = min(timings)
359 print("%d loop%s, best of %d: %s per loop"
360 % (number, 's' if number != 1 else '',
361 repeat, format_time(best)))
362
363 best = min(timings)
364 worst = max(timings)
Robert Collins69de2a52015-08-26 12:40:28 +1200365 if worst >= best * 4:
Robert Collins69de2a52015-08-26 12:40:28 +1200366 import warnings
Victor Stinner61de57f2016-10-18 17:56:42 +0200367 warnings.warn_explicit("The test results are likely unreliable. "
368 "The worst time (%s) was more than four times "
369 "slower than the best time (%s)."
Victor Stinneraf48a912016-10-19 15:48:23 +0200370 % (format_time(worst), format_time(best)),
Victor Stinner61de57f2016-10-18 17:56:42 +0200371 UserWarning, '', 0)
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000372 return None
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000373
374if __name__ == "__main__":
375 sys.exit(main())