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