|
| 1 | +#! /usr/bin/env python3 |
| 2 | + |
| 3 | +"""Tool for measuring execution time of small code snippets. |
| 4 | +
|
| 5 | +This module avoids a number of common traps for measuring execution |
| 6 | +times. See also Tim Peters' introduction to the Algorithms chapter in |
| 7 | +the Python Cookbook, published by O'Reilly. |
| 8 | +
|
| 9 | +Library usage: see the Timer class. |
| 10 | +
|
| 11 | +Command line usage: |
| 12 | + python timeit.py [-n N] [-r N] [-s S] [-t] [-c] [-p] [-h] [--] [statement] |
| 13 | +
|
| 14 | +Options: |
| 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 3) |
| 17 | + -s/--setup S: statement to be executed once initially (default 'pass') |
| 18 | + -p/--process: use time.process_time() (default is time.perf_counter()) |
| 19 | + -t/--time: use time.time() (deprecated) |
| 20 | + -c/--clock: use time.clock() (deprecated) |
| 21 | + -v/--verbose: print raw timing results; repeat for more digits precision |
| 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 | +
|
| 26 | +A multi-line statement may be given by specifying each line as a |
| 27 | +separate argument; indented lines are possible by enclosing an |
| 28 | +argument in quotes and using leading spaces. Multiple -s options are |
| 29 | +treated similarly. |
| 30 | +
|
| 31 | +If -n is not given, a suitable number of loops is calculated by trying |
| 32 | +successive powers of 10 until the total time is at least 0.2 seconds. |
| 33 | +
|
| 34 | +The difference in default timer function is because on Windows, |
| 35 | +clock() has microsecond granularity but time()'s granularity is 1/60th |
| 36 | +of a second; on Unix, clock() has 1/100th of a second granularity and |
| 37 | +time() is much more precise. On either platform, the default timer |
| 38 | +functions measure wall clock time, not the CPU time. This means that |
| 39 | +other processes running on the same computer may interfere with the |
| 40 | +timing. The best thing to do when accurate timing is necessary is to |
| 41 | +repeat the timing a few times and use the best time. The -r option is |
| 42 | +good for this; the default of 3 repetitions is probably enough in most |
| 43 | +cases. On Unix, you can use clock() to measure CPU time. |
| 44 | +
|
| 45 | +Note: there is a certain baseline overhead associated with executing a |
| 46 | +pass statement. The code here doesn't try to hide it, but you should |
| 47 | +be aware of it. The baseline overhead can be measured by invoking the |
| 48 | +program without arguments. |
| 49 | +
|
| 50 | +The baseline overhead differs between Python versions! Also, to |
| 51 | +fairly compare older Python versions to Python 2.3, you may want to |
| 52 | +use python -O for the older versions to avoid timing SET_LINENO |
| 53 | +instructions. |
| 54 | +""" |
| 55 | + |
| 56 | +import gc |
| 57 | +import sys |
| 58 | +import time |
| 59 | +try: |
| 60 | + import itertools |
| 61 | +except ImportError: |
| 62 | + # Must be an older Python version (see timeit() below) |
| 63 | + itertools = None |
| 64 | + |
| 65 | +__all__ = ["Timer"] |
| 66 | + |
| 67 | +dummy_src_name = "<timeit-src>" |
| 68 | +default_number = 1000000 |
| 69 | +default_repeat = 3 |
| 70 | +default_timer = time.perf_counter |
| 71 | + |
| 72 | +# Don't change the indentation of the template; the reindent() calls |
| 73 | +# in Timer.__init__() depend on setup being indented 4 spaces and stmt |
| 74 | +# being indented 8 spaces. |
| 75 | +template = """ |
| 76 | +def inner(_it, _timer): |
| 77 | + {setup} |
| 78 | + _t0 = _timer() |
| 79 | + for _i in _it: |
| 80 | + {stmt} |
| 81 | + _t1 = _timer() |
| 82 | + return _t1 - _t0 |
| 83 | +""" |
| 84 | + |
| 85 | +def reindent(src, indent): |
| 86 | + """Helper to reindent a multi-line statement.""" |
| 87 | + return src.replace("\n", "\n" + " "*indent) |
| 88 | + |
| 89 | +def _template_func(setup, func): |
| 90 | + """Create a timer function. Used if the "statement" is a callable.""" |
| 91 | + def inner(_it, _timer, _func=func): |
| 92 | + setup() |
| 93 | + _t0 = _timer() |
| 94 | + for _i in _it: |
| 95 | + _func() |
| 96 | + _t1 = _timer() |
| 97 | + return _t1 - _t0 |
| 98 | + return inner |
| 99 | + |
| 100 | +class Timer: |
| 101 | + """Class for timing execution speed of small code snippets. |
| 102 | +
|
| 103 | + The constructor takes a statement to be timed, an additional |
| 104 | + statement used for setup, and a timer function. Both statements |
| 105 | + default to 'pass'; the timer function is platform-dependent (see |
| 106 | + module doc string). |
| 107 | +
|
| 108 | + To measure the execution time of the first statement, use the |
| 109 | + timeit() method. The repeat() method is a convenience to call |
| 110 | + timeit() multiple times and return a list of results. |
| 111 | +
|
| 112 | + The statements may contain newlines, as long as they don't contain |
| 113 | + multi-line string literals. |
| 114 | + """ |
| 115 | + |
| 116 | + def __init__(self, stmt="pass", setup="pass", timer=default_timer): |
| 117 | + """Constructor. See class doc string.""" |
| 118 | + self.timer = timer |
| 119 | + ns = {} |
| 120 | + if isinstance(stmt, str): |
| 121 | + stmt = reindent(stmt, 8) |
| 122 | + if isinstance(setup, str): |
| 123 | + setup = reindent(setup, 4) |
| 124 | + src = template.format(stmt=stmt, setup=setup) |
| 125 | + elif callable(setup): |
| 126 | + src = template.format(stmt=stmt, setup='_setup()') |
| 127 | + ns['_setup'] = setup |
| 128 | + else: |
| 129 | + raise ValueError("setup is neither a string nor callable") |
| 130 | + self.src = src # Save for traceback display |
| 131 | + code = compile(src, dummy_src_name, "exec") |
| 132 | + exec(code, globals(), ns) |
| 133 | + self.inner = ns["inner"] |
| 134 | + elif callable(stmt): |
| 135 | + self.src = None |
| 136 | + if isinstance(setup, str): |
| 137 | + _setup = setup |
| 138 | + def setup(): |
| 139 | + exec(_setup, globals(), ns) |
| 140 | + elif not callable(setup): |
| 141 | + raise ValueError("setup is neither a string nor callable") |
| 142 | + self.inner = _template_func(setup, stmt) |
| 143 | + else: |
| 144 | + raise ValueError("stmt is neither a string nor callable") |
| 145 | + |
| 146 | + def print_exc(self, file=None): |
| 147 | + """Helper to print a traceback from the timed code. |
| 148 | +
|
| 149 | + Typical use: |
| 150 | +
|
| 151 | + t = Timer(...) # outside the try/except |
| 152 | + try: |
| 153 | + t.timeit(...) # or t.repeat(...) |
| 154 | + except: |
| 155 | + t.print_exc() |
| 156 | +
|
| 157 | + The advantage over the standard traceback is that source lines |
| 158 | + in the compiled template will be displayed. |
| 159 | +
|
| 160 | + The optional file argument directs where the traceback is |
| 161 | + sent; it defaults to sys.stderr. |
| 162 | + """ |
| 163 | + import linecache, traceback |
| 164 | + if self.src is not None: |
| 165 | + linecache.cache[dummy_src_name] = (len(self.src), |
| 166 | + None, |
| 167 | + self.src.split("\n"), |
| 168 | + dummy_src_name) |
| 169 | + # else the source is already stored somewhere else |
| 170 | + |
| 171 | + traceback.print_exc(file=file) |
| 172 | + |
| 173 | + def timeit(self, number=default_number): |
| 174 | + """Time 'number' executions of the main statement. |
| 175 | +
|
| 176 | + To be precise, this executes the setup statement once, and |
| 177 | + then returns the time it takes to execute the main statement |
| 178 | + a number of times, as a float measured in seconds. The |
| 179 | + argument is the number of times through the loop, defaulting |
| 180 | + to one million. The main statement, the setup statement and |
| 181 | + the timer function to be used are passed to the constructor. |
| 182 | + """ |
| 183 | + if itertools: |
| 184 | + it = itertools.repeat(None, number) |
| 185 | + else: |
| 186 | + it = [None] * number |
| 187 | + gcold = gc.isenabled() |
| 188 | + gc.disable() |
| 189 | + try: |
| 190 | + timing = self.inner(it, self.timer) |
| 191 | + finally: |
| 192 | + if gcold: |
| 193 | + gc.enable() |
| 194 | + return timing |
| 195 | + |
| 196 | + def repeat(self, repeat=default_repeat, number=default_number): |
| 197 | + """Call timeit() a few times. |
| 198 | +
|
| 199 | + This is a convenience function that calls the timeit() |
| 200 | + repeatedly, returning a list of results. The first argument |
| 201 | + specifies how many times to call timeit(), defaulting to 3; |
| 202 | + the second argument specifies the timer argument, defaulting |
| 203 | + to one million. |
| 204 | +
|
| 205 | + Note: it's tempting to calculate mean and standard deviation |
| 206 | + from the result vector and report these. However, this is not |
| 207 | + very useful. In a typical case, the lowest value gives a |
| 208 | + lower bound for how fast your machine can run the given code |
| 209 | + snippet; higher values in the result vector are typically not |
| 210 | + caused by variability in Python's speed, but by other |
| 211 | + processes interfering with your timing accuracy. So the min() |
| 212 | + of the result is probably the only number you should be |
| 213 | + interested in. After that, you should look at the entire |
| 214 | + vector and apply common sense rather than statistics. |
| 215 | + """ |
| 216 | + r = [] |
| 217 | + for i in range(repeat): |
| 218 | + t = self.timeit(number) |
| 219 | + r.append(t) |
| 220 | + return r |
| 221 | + |
| 222 | +def timeit(stmt="pass", setup="pass", timer=default_timer, |
| 223 | + number=default_number): |
| 224 | + """Convenience function to create Timer object and call timeit method.""" |
| 225 | + return Timer(stmt, setup, timer).timeit(number) |
| 226 | + |
| 227 | +def repeat(stmt="pass", setup="pass", timer=default_timer, |
| 228 | + repeat=default_repeat, number=default_number): |
| 229 | + """Convenience function to create Timer object and call repeat method.""" |
| 230 | + return Timer(stmt, setup, timer).repeat(repeat, number) |
| 231 | + |
| 232 | +def main(args=None, *, _wrap_timer=None): |
| 233 | + """Main program, used when run as a script. |
| 234 | +
|
| 235 | + The optional 'args' argument specifies the command line to be parsed, |
| 236 | + defaulting to sys.argv[1:]. |
| 237 | +
|
| 238 | + The return value is an exit code to be passed to sys.exit(); it |
| 239 | + may be None to indicate success. |
| 240 | +
|
| 241 | + When an exception happens during timing, a traceback is printed to |
| 242 | + stderr and the return value is 1. Exceptions at other times |
| 243 | + (including the template compilation) are not caught. |
| 244 | +
|
| 245 | + '_wrap_timer' is an internal interface used for unit testing. If it |
| 246 | + is not None, it must be a callable that accepts a timer function |
| 247 | + and returns another timer function (used for unit testing). |
| 248 | + """ |
| 249 | + if args is None: |
| 250 | + args = sys.argv[1:] |
| 251 | + import getopt |
| 252 | + try: |
| 253 | + opts, args = getopt.getopt(args, "n:s:r:tcpvh", |
| 254 | + ["number=", "setup=", "repeat=", |
| 255 | + "time", "clock", "process", |
| 256 | + "verbose", "help"]) |
| 257 | + except getopt.error as err: |
| 258 | + print(err) |
| 259 | + print("use -h/--help for command line help") |
| 260 | + return 2 |
| 261 | + timer = default_timer |
| 262 | + stmt = "\n".join(args) or "pass" |
| 263 | + number = 0 # auto-determine |
| 264 | + setup = [] |
| 265 | + repeat = default_repeat |
| 266 | + verbose = 0 |
| 267 | + precision = 3 |
| 268 | + for o, a in opts: |
| 269 | + if o in ("-n", "--number"): |
| 270 | + number = int(a) |
| 271 | + if o in ("-s", "--setup"): |
| 272 | + setup.append(a) |
| 273 | + if o in ("-r", "--repeat"): |
| 274 | + repeat = int(a) |
| 275 | + if repeat <= 0: |
| 276 | + repeat = 1 |
| 277 | + if o in ("-t", "--time"): |
| 278 | + timer = time.time |
| 279 | + if o in ("-c", "--clock"): |
| 280 | + timer = time.clock |
| 281 | + if o in ("-p", "--process"): |
| 282 | + timer = time.process_time |
| 283 | + if o in ("-v", "--verbose"): |
| 284 | + if verbose: |
| 285 | + precision += 1 |
| 286 | + verbose += 1 |
| 287 | + if o in ("-h", "--help"): |
| 288 | + print(__doc__, end=' ') |
| 289 | + return 0 |
| 290 | + setup = "\n".join(setup) or "pass" |
| 291 | + # Include the current directory, so that local imports work (sys.path |
| 292 | + # contains the directory of this script, rather than the current |
| 293 | + # directory) |
| 294 | + import os |
| 295 | + sys.path.insert(0, os.curdir) |
| 296 | + if _wrap_timer is not None: |
| 297 | + timer = _wrap_timer(timer) |
| 298 | + t = Timer(stmt, setup, timer) |
| 299 | + if number == 0: |
| 300 | + # determine number so that 0.2 <= total time < 2.0 |
| 301 | + for i in range(1, 10): |
| 302 | + number = 10**i |
| 303 | + try: |
| 304 | + x = t.timeit(number) |
| 305 | + except: |
| 306 | + t.print_exc() |
| 307 | + return 1 |
| 308 | + if
CCEF
verbose: |
| 309 | + print("%d loops -> %.*g secs" % (number, precision, x)) |
| 310 | + if x >= 0.2: |
| 311 | + break |
| 312 | + try: |
| 313 | + r = t.repeat(repeat, number) |
| 314 | + except: |
| 315 | + t.print_exc() |
| 316 | + return 1 |
| 317 | + best = min(r) |
| 318 | + if verbose: |
| 319 | + print("raw times:", " ".join(["%.*g" % (precision, x) for x in r])) |
| 320 | + print("%d loops," % number, end=' ') |
| 321 | + usec = best * 1e6 / number |
| 322 | + if usec < 1000: |
| 323 | + print("best of %d: %.*g usec per loop" % (repeat, precision, usec)) |
| 324 | + else: |
| 325 | + msec = usec / 1000 |
| 326 | + if msec < 1000: |
| 327 | + print("best of %d: %.*g msec per loop" % (repeat, precision, msec)) |
| 328 | + else: |
| 329 | + sec = msec / 1000 |
| 330 | + print("best of %d: %.*g sec per loop" % (repeat, precision, sec)) |
| 331 | + return None |
| 332 | + |
| 333 | +if __name__ == "__main__": |
| 334 | + sys.exit(main()) |
0 commit comments