blob: c0362bcc5f3e2483e56e428a58448ce74cbec198 [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
32successive powers of 10 until the total time is at least 0.2 seconds.
33
Guido van Rossume8577b72003-03-06 03:02:10 +000034Note: there is a certain baseline overhead associated with executing a
Terry Jan Reedyd49af5d2013-03-15 03:04:25 -040035pass statement. It differs between versions. The code here doesn't try
36to hide it, but you should be aware of it. The baseline overhead can be
37measured by invoking the program without arguments.
Guido van Rossum6e31aad2003-03-07 01:33:18 +000038
Terry Jan Reedyd49af5d2013-03-15 03:04:25 -040039Classes:
40
41 Timer
42
43Functions:
44
45 timeit(string, string) -> float
46 repeat(string, string) -> list
47 default_timer() -> float
48
Guido van Rossumb3f09d42003-03-05 23:31:58 +000049"""
50
Raymond Hettinger816ed1b2004-01-04 03:47:51 +000051import gc
Guido van Rossumb3f09d42003-03-05 23:31:58 +000052import sys
Guido van Rossumb3f09d42003-03-05 23:31:58 +000053import time
Terry Jan Reedyd49af5d2013-03-15 03:04:25 -040054import itertools
Guido van Rossumb3f09d42003-03-05 23:31:58 +000055
Terry Jan Reedyd49af5d2013-03-15 03:04:25 -040056__all__ = ["Timer", "timeit", "repeat", "default_timer"]
Guido van Rossumb3f09d42003-03-05 23:31:58 +000057
Guido van Rossum538f1d82003-03-14 17:21:00 +000058dummy_src_name = "<timeit-src>"
Guido van Rossumb3f09d42003-03-05 23:31:58 +000059default_number = 1000000
Victor Stinner1b901152016-10-18 17:13:22 +020060default_repeat = 5
Victor Stinnerfe98e2f2012-04-29 03:01:20 +020061default_timer = time.perf_counter
Guido van Rossumb3f09d42003-03-05 23:31:58 +000062
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -040063_globals = globals
64
Guido van Rossumb7ab6002003-03-06 02:32:19 +000065# Don't change the indentation of the template; the reindent() calls
66# in Timer.__init__() depend on setup being indented 4 spaces and stmt
67# being indented 8 spaces.
Guido van Rossumb3f09d42003-03-05 23:31:58 +000068template = """
Serhiy Storchakaf28fa662015-05-30 19:38:26 +030069def inner(_it, _timer{init}):
Raymond Hettingerc800af42011-04-04 09:28:25 -070070 {setup}
Guido van Rossum538f1d82003-03-14 17:21:00 +000071 _t0 = _timer()
Guido van Rossumdd42edc2003-03-21 14:54:19 +000072 for _i in _it:
Raymond Hettingerc800af42011-04-04 09:28:25 -070073 {stmt}
Guido van Rossum538f1d82003-03-14 17:21:00 +000074 _t1 = _timer()
75 return _t1 - _t0
Guido van Rossumb3f09d42003-03-05 23:31:58 +000076"""
77
78def reindent(src, indent):
Guido van Rossumb7ab6002003-03-06 02:32:19 +000079 """Helper to reindent a multi-line statement."""
Guido van Rossume05dcce2003-03-06 13:09:09 +000080 return src.replace("\n", "\n" + " "*indent)
Guido van Rossumb3f09d42003-03-05 23:31:58 +000081
82class Timer:
Guido van Rossumb7ab6002003-03-06 02:32:19 +000083 """Class for timing execution speed of small code snippets.
84
85 The constructor takes a statement to be timed, an additional
86 statement used for setup, and a timer function. Both statements
87 default to 'pass'; the timer function is platform-dependent (see
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -040088 module doc string). If 'globals' is specified, the code will be
89 executed within that namespace (as opposed to inside timeit's
90 namespace).
Guido van Rossumb7ab6002003-03-06 02:32:19 +000091
92 To measure the execution time of the first statement, use the
93 timeit() method. The repeat() method is a convenience to call
94 timeit() multiple times and return a list of results.
95
96 The statements may contain newlines, as long as they don't contain
97 multi-line string literals.
98 """
Guido van Rossumb3f09d42003-03-05 23:31:58 +000099
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400100 def __init__(self, stmt="pass", setup="pass", timer=default_timer,
101 globals=None):
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000102 """Constructor. See class doc string."""
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000103 self.timer = timer
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400104 local_ns = {}
105 global_ns = _globals() if globals is None else globals
Serhiy Storchaka1b560cb2015-05-30 19:44:55 +0300106 init = ''
107 if isinstance(setup, str):
108 # Check that the code can be compiled outside a function
109 compile(setup, dummy_src_name, "exec")
Serhiy Storchakaced770d2015-07-15 22:11:36 +0300110 stmtprefix = setup + '\n'
Serhiy Storchaka1b560cb2015-05-30 19:44:55 +0300111 setup = reindent(setup, 4)
112 elif callable(setup):
113 local_ns['_setup'] = setup
114 init += ', _setup=_setup'
Serhiy Storchakaced770d2015-07-15 22:11:36 +0300115 stmtprefix = ''
Serhiy Storchaka1b560cb2015-05-30 19:44:55 +0300116 setup = '_setup()'
117 else:
118 raise ValueError("setup is neither a string nor callable")
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
Serhiy Storchakaced770d2015-07-15 22:11:36 +0300121 compile(stmtprefix + stmt, dummy_src_name, "exec")
Guido van Rossumd8faa362007-04-27 19:54:29 +0000122 stmt = reindent(stmt, 8)
Florent Xicluna5d1155c2011-10-28 14:45:05 +0200123 elif callable(stmt):
Serhiy Storchaka1b560cb2015-05-30 19:44:55 +0300124 local_ns['_stmt'] = stmt
125 init += ', _stmt=_stmt'
126 stmt = '_stmt()'
Guido van Rossumd8faa362007-04-27 19:54:29 +0000127 else:
128 raise ValueError("stmt is neither a string nor callable")
Serhiy Storchaka1b560cb2015-05-30 19:44:55 +0300129 src = template.format(stmt=stmt, setup=setup, init=init)
130 self.src = src # Save for traceback display
131 code = compile(src, dummy_src_name, "exec")
132 exec(code, global_ns, local_ns)
133 self.inner = local_ns["inner"]
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000134
Guido van Rossum538f1d82003-03-14 17:21:00 +0000135 def print_exc(self, file=None):
136 """Helper to print a traceback from the timed code.
137
138 Typical use:
139
140 t = Timer(...) # outside the try/except
141 try:
142 t.timeit(...) # or t.repeat(...)
143 except:
144 t.print_exc()
145
146 The advantage over the standard traceback is that source lines
147 in the compiled template will be displayed.
148
149 The optional file argument directs where the traceback is
150 sent; it defaults to sys.stderr.
151 """
152 import linecache, traceback
Guido van Rossumd8faa362007-04-27 19:54:29 +0000153 if self.src is not None:
154 linecache.cache[dummy_src_name] = (len(self.src),
155 None,
156 self.src.split("\n"),
157 dummy_src_name)
158 # else the source is already stored somewhere else
159
Guido van Rossum538f1d82003-03-14 17:21:00 +0000160 traceback.print_exc(file=file)
161
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000162 def timeit(self, number=default_number):
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000163 """Time 'number' executions of the main statement.
164
165 To be precise, this executes the setup statement once, and
166 then returns the time it takes to execute the main statement
167 a number of times, as a float measured in seconds. The
168 argument is the number of times through the loop, defaulting
169 to one million. The main statement, the setup statement and
170 the timer function to be used are passed to the constructor.
171 """
Terry Jan Reedyd49af5d2013-03-15 03:04:25 -0400172 it = itertools.repeat(None, number)
Raymond Hettinger816ed1b2004-01-04 03:47:51 +0000173 gcold = gc.isenabled()
174 gc.disable()
Raymond Hettinger3a081f52011-07-29 00:02:04 -0700175 try:
176 timing = self.inner(it, self.timer)
177 finally:
178 if gcold:
179 gc.enable()
Raymond Hettinger816ed1b2004-01-04 03:47:51 +0000180 return timing
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000181
182 def repeat(self, repeat=default_repeat, number=default_number):
Skip Montanarofb2a6cc2003-04-08 19:40:19 +0000183 """Call timeit() a few times.
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000184
Skip Montanarofb2a6cc2003-04-08 19:40:19 +0000185 This is a convenience function that calls the timeit()
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000186 repeatedly, returning a list of results. The first argument
Victor Stinner3ef769f2018-06-06 17:55:18 +0200187 specifies how many times to call timeit(), defaulting to 5;
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000188 the second argument specifies the timer argument, defaulting
189 to one million.
Guido van Rossum55735412003-03-06 16:11:17 +0000190
191 Note: it's tempting to calculate mean and standard deviation
192 from the result vector and report these. However, this is not
193 very useful. In a typical case, the lowest value gives a
194 lower bound for how fast your machine can run the given code
195 snippet; higher values in the result vector are typically not
196 caused by variability in Python's speed, but by other
197 processes interfering with your timing accuracy. So the min()
198 of the result is probably the only number you should be
199 interested in. After that, you should look at the entire
200 vector and apply common sense rather than statistics.
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000201 """
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000202 r = []
203 for i in range(repeat):
204 t = self.timeit(number)
205 r.append(t)
206 return r
207
Steven D'Aprano09f4f712016-08-15 01:27:03 +1000208 def autorange(self, callback=None):
Xiang Zhangecf39bb2017-02-28 11:06:07 +0800209 """Return the number of loops and time taken so that total time >= 0.2.
Steven D'Aprano09f4f712016-08-15 01:27:03 +1000210
Serhiy Storchakad3ff7842016-10-23 15:17:05 +0300211 Calls the timeit method with increasing numbers from the sequence
212 1, 2, 5, 10, 20, 50, ... until the time taken is at least 0.2
213 second. Returns (number, time_taken).
Steven D'Aprano09f4f712016-08-15 01:27:03 +1000214
215 If *callback* is given and is not None, it will be called after
216 each trial with two arguments: ``callback(number, time_taken)``.
217 """
Serhiy Storchakad3ff7842016-10-23 15:17:05 +0300218 i = 1
219 while True:
220 for j in 1, 2, 5:
221 number = i * j
222 time_taken = self.timeit(number)
223 if callback:
224 callback(number, time_taken)
225 if time_taken >= 0.2:
226 return (number, time_taken)
227 i *= 10
Steven D'Aprano09f4f712016-08-15 01:27:03 +1000228
Guido van Rossumd8faa362007-04-27 19:54:29 +0000229def timeit(stmt="pass", setup="pass", timer=default_timer,
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400230 number=default_number, globals=None):
Guido van Rossumd8faa362007-04-27 19:54:29 +0000231 """Convenience function to create Timer object and call timeit method."""
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400232 return Timer(stmt, setup, timer, globals).timeit(number)
Guido van Rossumd8faa362007-04-27 19:54:29 +0000233
234def repeat(stmt="pass", setup="pass", timer=default_timer,
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400235 repeat=default_repeat, number=default_number, globals=None):
Guido van Rossumd8faa362007-04-27 19:54:29 +0000236 """Convenience function to create Timer object and call repeat method."""
Antoine Pitrouef3b9ed2014-08-22 23:13:50 -0400237 return Timer(stmt, setup, timer, globals).repeat(repeat, number)
Guido van Rossumd8faa362007-04-27 19:54:29 +0000238
R David Murraya88da672011-03-16 17:32:27 -0400239def main(args=None, *, _wrap_timer=None):
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000240 """Main program, used when run as a script.
241
R David Murraya88da672011-03-16 17:32:27 -0400242 The optional 'args' argument specifies the command line to be parsed,
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000243 defaulting to sys.argv[1:].
244
245 The return value is an exit code to be passed to sys.exit(); it
246 may be None to indicate success.
Guido van Rossum538f1d82003-03-14 17:21:00 +0000247
248 When an exception happens during timing, a traceback is printed to
249 stderr and the return value is 1. Exceptions at other times
250 (including the template compilation) are not caught.
R David Murraya88da672011-03-16 17:32:27 -0400251
252 '_wrap_timer' is an internal interface used for unit testing. If it
253 is not None, it must be a callable that accepts a timer function
254 and returns another timer function (used for unit testing).
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000255 """
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000256 if args is None:
257 args = sys.argv[1:]
258 import getopt
259 try:
Robert Collins302dbc62015-03-18 09:54:50 +1300260 opts, args = getopt.getopt(args, "n:u:s:r:tcpvh",
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000261 ["number=", "setup=", "repeat=",
Georg Brandlc9d77b22012-05-01 11:56:22 +0200262 "time", "clock", "process",
Robert Collins302dbc62015-03-18 09:54:50 +1300263 "verbose", "unit=", "help"])
Guido van Rossumb940e112007-01-10 16:19:56 +0000264 except getopt.error as err:
Guido van Rossumbe19ed72007-02-09 05:37:30 +0000265 print(err)
266 print("use -h/--help for command line help")
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000267 return 2
Victor Stinner61de57f2016-10-18 17:56:42 +0200268
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000269 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
Victor Stinnerc3e40f82016-10-18 17:42:48 +0200276 units = {"nsec": 1e-9, "usec": 1e-6, "msec": 1e-3, "sec": 1.0}
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:
Victor Stinnerc3e40f82016-10-18 17:42:48 +0200287 print("Unrecognized unit. Please select nsec, usec, msec, or sec.",
Robert Collins302dbc62015-03-18 09:54:50 +1300288 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
Georg Brandlc9d77b22012-05-01 11:56:22 +0200294 if o in ("-p", "--process"):
295 timer = time.process_time
Guido van Rossum0070f002003-03-15 12:25:00 +0000296 if o in ("-v", "--verbose"):
297 if verbose:
298 precision += 1
299 verbose += 1
Guido van Rossume8577b72003-03-06 03:02:10 +0000300 if o in ("-h", "--help"):
Guido van Rossumbe19ed72007-02-09 05:37:30 +0000301 print(__doc__, end=' ')
Guido van Rossume8577b72003-03-06 03:02:10 +0000302 return 0
Guido van Rossum6e31aad2003-03-07 01:33:18 +0000303 setup = "\n".join(setup) or "pass"
Victor Stinner61de57f2016-10-18 17:56:42 +0200304
Raymond Hettinger22952a32003-05-20 04:59:56 +0000305 # Include the current directory, so that local imports work (sys.path
306 # contains the directory of this script, rather than the current
307 # directory)
308 import os
309 sys.path.insert(0, os.curdir)
R David Murraya88da672011-03-16 17:32:27 -0400310 if _wrap_timer is not None:
311 timer = _wrap_timer(timer)
Victor Stinner61de57f2016-10-18 17:56:42 +0200312
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000313 t = Timer(stmt, setup, timer)
314 if number == 0:
315 # determine number so that 0.2 <= total time < 2.0
Steven D'Aprano09f4f712016-08-15 01:27:03 +1000316 callback = None
317 if verbose:
318 def callback(number, time_taken):
Victor Stinnerf8fb82c2016-10-18 17:06:56 +0200319 msg = "{num} loop{s} -> {secs:.{prec}g} secs"
320 plural = (number != 1)
321 print(msg.format(num=number, s='s' if plural else '',
322 secs=time_taken, prec=precision))
Steven D'Aprano09f4f712016-08-15 01:27:03 +1000323 try:
324 number, _ = t.autorange(callback)
325 except:
326 t.print_exc()
327 return 1
Victor Stinner61de57f2016-10-18 17:56:42 +0200328
Victor Stinner62cca922016-10-18 17:55:18 +0200329 if verbose:
330 print()
331
Guido van Rossum538f1d82003-03-14 17:21:00 +0000332 try:
Victor Stinner61de57f2016-10-18 17:56:42 +0200333 raw_timings = t.repeat(repeat, number)
Guido van Rossum538f1d82003-03-14 17:21:00 +0000334 except:
335 t.print_exc()
336 return 1
Victor Stinner61de57f2016-10-18 17:56:42 +0200337
338 def format_time(dt):
339 unit = time_unit
340
341 if unit is not None:
342 scale = units[unit]
343 else:
344 scales = [(scale, unit) for unit, scale in units.items()]
345 scales.sort(reverse=True)
346 for scale, unit in scales:
347 if dt >= scale:
348 break
349
350 return "%.*g %s" % (precision, dt / scale, unit)
351
Guido van Rossum0070f002003-03-15 12:25:00 +0000352 if verbose:
Victor Stinner61de57f2016-10-18 17:56:42 +0200353 print("raw times: %s" % ", ".join(map(format_time, raw_timings)))
Victor Stinner62cca922016-10-18 17:55:18 +0200354 print()
Victor Stinner61de57f2016-10-18 17:56:42 +0200355 timings = [dt / number for dt in raw_timings]
356
357 best = min(timings)
358 print("%d loop%s, best of %d: %s per loop"
359 % (number, 's' if number != 1 else '',
360 repeat, format_time(best)))
361
362 best = min(timings)
363 worst = max(timings)
Robert Collins69de2a52015-08-26 12:40:28 +1200364 if worst >= best * 4:
Robert Collins69de2a52015-08-26 12:40:28 +1200365 import warnings
Victor Stinner61de57f2016-10-18 17:56:42 +0200366 warnings.warn_explicit("The test results are likely unreliable. "
367 "The worst time (%s) was more than four times "
368 "slower than the best time (%s)."
Victor Stinneraf48a912016-10-19 15:48:23 +0200369 % (format_time(worst), format_time(best)),
Victor Stinner61de57f2016-10-18 17:56:42 +0200370 UserWarning, '', 0)
Guido van Rossumb7ab6002003-03-06 02:32:19 +0000371 return None
Guido van Rossumb3f09d42003-03-05 23:31:58 +0000372
373if __name__ == "__main__":
374 sys.exit(main())