1#! /usr/bin/env python3 2 3"""Tool for measuring execution time of small code snippets. 4 5This 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. 8 9Library usage: see the Timer class. 10 11Command line usage: 12 python timeit.py [-n N] [-r N] [-s S] [-p] [-h] [--] [statement] 13 14Options: 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 5) 17 -s/--setup S: statement to be executed once initially (default 'pass'). 18 Execution time of this setup statement is NOT timed. 19 -p/--process: use time.process_time() (default is time.perf_counter()) 20 -v/--verbose: print raw timing results; repeat for more digits precision 21 -u/--unit: set the output time unit (nsec, usec, msec, or sec) 22 -h/--help: print this usage message and exit 23 --: separate options from statement, use when statement starts with - 24 statement: statement to be timed (default 'pass') 25 26A multi-line statement may be given by specifying each line as a 27separate argument; indented lines are possible by enclosing an 28argument in quotes and using leading spaces. Multiple -s options are 29treated similarly. 30 31If -n is not given, a suitable number of loops is calculated by trying 32increasing numbers from the sequence 1, 2, 5, 10, 20, 50, ... until the 33total time is at least 0.2 seconds. 34 35Note: there is a certain baseline overhead associated with executing a 36pass 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. 39 40Classes: 41 42 Timer 43 44Functions: 45 46 timeit(string, string) -> float 47 repeat(string, string) -> list 48 default_timer() -> float 49 50""" 51 52import gc 53import itertools 54import sys 55import time 56 57__all__ = ["Timer", "timeit", "repeat", "default_timer"] 58 59dummy_src_name = "<timeit-src>" 60default_number = 1000000 61default_repeat = 5 62default_timer = time.perf_counter 63 64_globals = globals 65 66# 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. 69template = """ 70def inner(_it, _timer{init}): 71 {setup} 72 _t0 = _timer() 73 for _i in _it: 74 {stmt} 75 pass 76 _t1 = _timer() 77 return _t1 - _t0 78""" 79 80 81def reindent(src, indent): 82 """Helper to reindent a multi-line statement.""" 83 return src.replace("\n", "\n" + " " * indent) 84 85 86class Timer: 87 """Class for timing execution speed of small code snippets. 88 89 The constructor takes a statement to be timed, an additional 90 statement used for setup, and a timer function. Both statements 91 default to 'pass'; the timer function is platform-dependent (see 92 module doc string). If 'globals' is specified, the code will be 93 executed within that namespace (as opposed to inside timeit's 94 namespace). 95 96 To measure the execution time of the first statement, use the 97 timeit() method. The repeat() method is a convenience to call 98 timeit() multiple times and return a list of results. 99 100 The statements may contain newlines, as long as they don't contain 101 multi-line string literals. 102 """ 103 104 def __init__(self, stmt="pass", setup="pass", timer=default_timer, 105 globals=None): 106 """Constructor. See class doc string.""" 107 self.timer = timer 108 local_ns = {} 109 global_ns = _globals() if globals is None else globals 110 init = '' 111 if isinstance(setup, str): 112 # Check that the code can be compiled outside a function 113 compile(setup, dummy_src_name, "exec") 114 stmtprefix = setup + '\n' 115 setup = reindent(setup, 4) 116 elif callable(setup): 117 local_ns['_setup'] = setup 118 init += ', _setup=_setup' 119 stmtprefix = '' 120 setup = '_setup()' 121 else: 122 raise ValueError("setup is neither a string nor callable") 123 if isinstance(stmt, str): 124 # Check that the code can be compiled outside a function 125 compile(stmtprefix + stmt, dummy_src_name, "exec") 126 stmt = reindent(stmt, 8) 127 elif callable(stmt): 128 local_ns['_stmt'] = stmt 129 init += ', _stmt=_stmt' 130 stmt = '_stmt()' 131 else: 132 raise ValueError("stmt is neither a string nor callable") 133 src = template.format(stmt=stmt, setup=setup, init=init) 134 self.src = src # Save for traceback display 135 code = compile(src, dummy_src_name, "exec") 136 exec(code, global_ns, local_ns) 137 self.inner = local_ns["inner"] 138 139 def print_exc(self, file=None): 140 """Helper to print a traceback from the timed code. 141 142 Typical use: 143 144 t = Timer(...) # outside the try/except 145 try: 146 t.timeit(...) # or t.repeat(...) 147 except: 148 t.print_exc() 149 150 The advantage over the standard traceback is that source lines 151 in the compiled template will be displayed. 152 153 The optional file argument directs where the traceback is 154 sent; it defaults to sys.stderr. 155 """ 156 import linecache, traceback 157 if self.src is not None: 158 linecache.cache[dummy_src_name] = (len(self.src), 159 None, 160 self.src.split("\n"), 161 dummy_src_name) 162 # else the source is already stored somewhere else 163 164 traceback.print_exc(file=file) 165 166 def timeit(self, number=default_number): 167 """Time 'number' executions of the main statement. 168 169 To be precise, this executes the setup statement once, and 170 then returns the time it takes to execute the main statement 171 a number of times, as float seconds if using the default timer. The 172 argument is the number of times through the loop, defaulting 173 to one million. The main statement, the setup statement and 174 the timer function to be used are passed to the constructor. 175 """ 176 it = itertools.repeat(None, number) 177 gcold = gc.isenabled() 178 gc.disable() 179 try: 180 timing = self.inner(it, self.timer) 181 finally: 182 if gcold: 183 gc.enable() 184 return timing 185 186 def repeat(self, repeat=default_repeat, number=default_number): 187 """Call timeit() a few times. 188 189 This is a convenience function that calls the timeit() 190 repeatedly, returning a list of results. The first argument 191 specifies how many times to call timeit(), defaulting to 5; 192 the second argument specifies the timer argument, defaulting 193 to one million. 194 195 Note: it's tempting to calculate mean and standard deviation 196 from the result vector and report these. However, this is not 197 very useful. In a typical case, the lowest value gives a 198 lower bound for how fast your machine can run the given code 199 snippet; higher values in the result vector are typically not 200 caused by variability in Python's speed, but by other 201 processes interfering with your timing accuracy. So the min() 202 of the result is probably the only number you should be 203 interested in. After that, you should look at the entire 204 vector and apply common sense rather than statistics. 205 """ 206 r = [] 207 for i in range(repeat): 208 t = self.timeit(number) 209 r.append(t) 210 return r 211 212 def autorange(self, callback=None): 213 """Return the number of loops and time taken so that total time >= 0.2. 214 215 Calls the timeit method with increasing numbers from the sequence 216 1, 2, 5, 10, 20, 50, ... until the time taken is at least 0.2 217 second. Returns (number, time_taken). 218 219 If *callback* is given and is not None, it will be called after 220 each trial with two arguments: ``callback(number, time_taken)``. 221 """ 222 i = 1 223 while True: 224 for j in 1, 2, 5: 225 number = i * j 226 time_taken = self.timeit(number) 227 if callback: 228 callback(number, time_taken) 229 if time_taken >= 0.2: 230 return (number, time_taken) 231 i *= 10 232 233 234def timeit(stmt="pass", setup="pass", timer=default_timer, 235 number=default_number, globals=None): 236 """Convenience function to create Timer object and call timeit method.""" 237 return Timer(stmt, setup, timer, globals).timeit(number) 238 239 240def repeat(stmt="pass", setup="pass", timer=default_timer, 241 repeat=default_repeat, number=default_number, globals=None): 242 """Convenience function to create Timer object and call repeat method.""" 243 return Timer(stmt, setup, timer, globals).repeat(repeat, number) 244 245 246def main(args=None, *, _wrap_timer=None): 247 """Main program, used when run as a script. 248 249 The optional 'args' argument specifies the command line to be parsed, 250 defaulting to sys.argv[1:]. 251 252 The return value is an exit code to be passed to sys.exit(); it 253 may be None to indicate success. 254 255 When an exception happens during timing, a traceback is printed to 256 stderr and the return value is 1. Exceptions at other times 257 (including the template compilation) are not caught. 258 259 '_wrap_timer' is an internal interface used for unit testing. If it 260 is not None, it must be a callable that accepts a timer function 261 and returns another timer function (used for unit testing). 262 """ 263 if args is None: 264 args = sys.argv[1:] 265 import getopt 266 try: 267 opts, args = getopt.getopt(args, "n:u:s:r:pvh", 268 ["number=", "setup=", "repeat=", 269 "process", "verbose", "unit=", "help"]) 270 except getopt.error as err: 271 print(err) 272 print("use -h/--help for command line help") 273 return 2 274 275 timer = default_timer 276 stmt = "\n".join(args) or "pass" 277 number = 0 # auto-determine 278 setup = [] 279 repeat = default_repeat 280 verbose = 0 281 time_unit = None 282 units = {"nsec": 1e-9, "usec": 1e-6, "msec": 1e-3, "sec": 1.0} 283 precision = 3 284 for o, a in opts: 285 if o in ("-n", "--number"): 286 number = int(a) 287 if o in ("-s", "--setup"): 288 setup.append(a) 289 if o in ("-u", "--unit"): 290 if a in units: 291 time_unit = a 292 else: 293 print("Unrecognized unit. Please select nsec, usec, msec, or sec.", 294 file=sys.stderr) 295 return 2 296 if o in ("-r", "--repeat"): 297 repeat = int(a) 298 if repeat <= 0: 299 repeat = 1 300 if o in ("-p", "--process"): 301 timer = time.process_time 302 if o in ("-v", "--verbose"): 303 if verbose: 304 precision += 1 305 verbose += 1 306 if o in ("-h", "--help"): 307 print(__doc__, end=' ') 308 return 0 309 setup = "\n".join(setup) or "pass" 310 311 # Include the current directory, so that local imports work (sys.path 312 # contains the directory of this script, rather than the current 313 # directory) 314 import os 315 sys.path.insert(0, os.curdir) 316 if _wrap_timer is not None: 317 timer = _wrap_timer(timer) 318 319 t = Timer(stmt, setup, timer) 320 if number == 0: 321 # determine number so that 0.2 <= total time < 2.0 322 callback = None 323 if verbose: 324 def callback(number, time_taken): 325 msg = "{num} loop{s} -> {secs:.{prec}g} secs" 326 plural = (number != 1) 327 print(msg.format(num=number, s='s' if plural else '', 328 secs=time_taken, prec=precision)) 329 try: 330 number, _ = t.autorange(callback) 331 except: 332 t.print_exc() 333 return 1 334 335 if verbose: 336 print() 337 338 try: 339 raw_timings = t.repeat(repeat, number) 340 except: 341 t.print_exc() 342 return 1 343 344 def format_time(dt): 345 unit = time_unit 346 347 if unit is not None: 348 scale = units[unit] 349 else: 350 scales = [(scale, unit) for unit, scale in units.items()] 351 scales.sort(reverse=True) 352 for scale, unit in scales: 353 if dt >= scale: 354 break 355 356 return "%.*g %s" % (precision, dt / scale, unit) 357 358 if verbose: 359 print("raw times: %s" % ", ".join(map(format_time, raw_timings))) 360 print() 361 timings = [dt / number for dt in raw_timings] 362 363 best = min(timings) 364 print("%d loop%s, best of %d: %s per loop" 365 % (number, 's' if number != 1 else '', 366 repeat, format_time(best))) 367 368 best = min(timings) 369 worst = max(timings) 370 if worst >= best * 4: 371 import warnings 372 warnings.warn_explicit("The test results are likely unreliable. " 373 "The worst time (%s) was more than four times " 374 "slower than the best time (%s)." 375 % (format_time(worst), format_time(best)), 376 UserWarning, '', 0) 377 return None 378 379 380if __name__ == "__main__": 381 sys.exit(main()) 382