| 1 | \section{\module{timeit} ---
|
|---|
| 2 | Measure execution time of small code snippets}
|
|---|
| 3 |
|
|---|
| 4 | \declaremodule{standard}{timeit}
|
|---|
| 5 | \modulesynopsis{Measure the execution time of small code snippets.}
|
|---|
| 6 |
|
|---|
| 7 | \versionadded{2.3}
|
|---|
| 8 | \index{Benchmarking}
|
|---|
| 9 | \index{Performance}
|
|---|
| 10 |
|
|---|
| 11 | This module provides a simple way to time small bits of Python code.
|
|---|
| 12 | It has both command line as well as callable interfaces. It avoids a
|
|---|
| 13 | number of common traps for measuring execution times. See also Tim
|
|---|
| 14 | Peters' introduction to the ``Algorithms'' chapter in the
|
|---|
| 15 | \citetitle{Python Cookbook}, published by O'Reilly.
|
|---|
| 16 |
|
|---|
| 17 | The module defines the following public class:
|
|---|
| 18 |
|
|---|
| 19 | \begin{classdesc}{Timer}{\optional{stmt=\code{'pass'}
|
|---|
| 20 | \optional{, setup=\code{'pass'}
|
|---|
| 21 | \optional{, timer=<timer function>}}}}
|
|---|
| 22 | Class for timing execution speed of small code snippets.
|
|---|
| 23 |
|
|---|
| 24 | The constructor takes a statement to be timed, an additional statement
|
|---|
| 25 | used for setup, and a timer function. Both statements default to
|
|---|
| 26 | \code{'pass'}; the timer function is platform-dependent (see the
|
|---|
| 27 | module doc string). The statements may contain newlines, as long as
|
|---|
| 28 | they don't contain multi-line string literals.
|
|---|
| 29 |
|
|---|
| 30 | To measure the execution time of the first statement, use the
|
|---|
| 31 | \method{timeit()} method. The \method{repeat()} method is a
|
|---|
| 32 | convenience to call \method{timeit()} multiple times and return a list
|
|---|
| 33 | of results.
|
|---|
| 34 | \end{classdesc}
|
|---|
| 35 |
|
|---|
| 36 | \begin{methoddesc}{print_exc}{\optional{file=\constant{None}}}
|
|---|
| 37 | Helper to print a traceback from the timed code.
|
|---|
| 38 |
|
|---|
| 39 | Typical use:
|
|---|
| 40 |
|
|---|
| 41 | \begin{verbatim}
|
|---|
| 42 | t = Timer(...) # outside the try/except
|
|---|
| 43 | try:
|
|---|
| 44 | t.timeit(...) # or t.repeat(...)
|
|---|
| 45 | except:
|
|---|
| 46 | t.print_exc()
|
|---|
| 47 | \end{verbatim}
|
|---|
| 48 |
|
|---|
| 49 | The advantage over the standard traceback is that source lines in the
|
|---|
| 50 | compiled template will be displayed.
|
|---|
| 51 | The optional \var{file} argument directs where the traceback is sent;
|
|---|
| 52 | it defaults to \code{sys.stderr}.
|
|---|
| 53 | \end{methoddesc}
|
|---|
| 54 |
|
|---|
| 55 | \begin{methoddesc}{repeat}{\optional{repeat\code{=3} \optional{,
|
|---|
| 56 | number\code{=1000000}}}}
|
|---|
| 57 | Call \method{timeit()} a few times.
|
|---|
| 58 |
|
|---|
| 59 | This is a convenience function that calls the \method{timeit()}
|
|---|
| 60 | repeatedly, returning a list of results. The first argument specifies
|
|---|
| 61 | how many times to call \method{timeit()}. The second argument
|
|---|
| 62 | specifies the \var{number} argument for \function{timeit()}.
|
|---|
| 63 |
|
|---|
| 64 | \begin{notice}
|
|---|
| 65 | It's tempting to calculate mean and standard deviation from the result
|
|---|
| 66 | vector and report these. However, this is not very useful. In a typical
|
|---|
| 67 | case, the lowest value gives a lower bound for how fast your machine can run
|
|---|
| 68 | the given code snippet; higher values in the result vector are typically not
|
|---|
| 69 | caused by variability in Python's speed, but by other processes interfering
|
|---|
| 70 | with your timing accuracy. So the \function{min()} of the result is
|
|---|
| 71 | probably the only number you should be interested in. After that, you
|
|---|
| 72 | should look at the entire vector and apply common sense rather than
|
|---|
| 73 | statistics.
|
|---|
| 74 | \end{notice}
|
|---|
| 75 | \end{methoddesc}
|
|---|
| 76 |
|
|---|
| 77 | \begin{methoddesc}{timeit}{\optional{number\code{=1000000}}}
|
|---|
| 78 | Time \var{number} executions of the main statement.
|
|---|
| 79 | This executes the setup statement once, and then
|
|---|
| 80 | returns the time it takes to execute the main statement a number of
|
|---|
| 81 | times, measured in seconds as a float. The argument is the number of
|
|---|
| 82 | times through the loop, defaulting to one million. The main
|
|---|
| 83 | statement, the setup statement and the timer function to be used are
|
|---|
| 84 | passed to the constructor.
|
|---|
| 85 |
|
|---|
| 86 | \begin{notice}
|
|---|
| 87 | By default, \method{timeit()} temporarily turns off garbage collection
|
|---|
| 88 | during the timing. The advantage of this approach is that it makes
|
|---|
| 89 | independent timings more comparable. This disadvantage is that GC
|
|---|
| 90 | may be an important component of the performance of the function being
|
|---|
| 91 | measured. If so, GC can be re-enabled as the first statement in the
|
|---|
| 92 | \var{setup} string. For example:
|
|---|
| 93 | \begin{verbatim}
|
|---|
| 94 | timeit.Timer('for i in xrange(10): oct(i)', 'gc.enable()').timeit()
|
|---|
| 95 | \end{verbatim}
|
|---|
| 96 | \end{notice}
|
|---|
| 97 | \end{methoddesc}
|
|---|
| 98 |
|
|---|
| 99 |
|
|---|
| 100 | \subsection{Command Line Interface}
|
|---|
| 101 |
|
|---|
| 102 | When called as a program from the command line, the following form is used:
|
|---|
| 103 |
|
|---|
| 104 | \begin{verbatim}
|
|---|
| 105 | python timeit.py [-n N] [-r N] [-s S] [-t] [-c] [-h] [statement ...]
|
|---|
| 106 | \end{verbatim}
|
|---|
| 107 |
|
|---|
| 108 | where the following options are understood:
|
|---|
| 109 |
|
|---|
| 110 | \begin{description}
|
|---|
| 111 | \item[-n N/\longprogramopt{number=N}] how many times to execute 'statement'
|
|---|
| 112 | \item[-r N/\longprogramopt{repeat=N}] how many times to repeat the timer (default 3)
|
|---|
| 113 | \item[-s S/\longprogramopt{setup=S}] statement to be executed once initially (default
|
|---|
| 114 | \code{'pass'})
|
|---|
| 115 | \item[-t/\longprogramopt{time}] use \function{time.time()}
|
|---|
| 116 | (default on all platforms but Windows)
|
|---|
| 117 | \item[-c/\longprogramopt{clock}] use \function{time.clock()} (default on Windows)
|
|---|
| 118 | \item[-v/\longprogramopt{verbose}] print raw timing results; repeat for more digits
|
|---|
| 119 | precision
|
|---|
| 120 | \item[-h/\longprogramopt{help}] print a short usage message and exit
|
|---|
| 121 | \end{description}
|
|---|
| 122 |
|
|---|
| 123 | A multi-line statement may be given by specifying each line as a
|
|---|
| 124 | separate statement argument; indented lines are possible by enclosing
|
|---|
| 125 | an argument in quotes and using leading spaces. Multiple
|
|---|
| 126 | \programopt{-s} options are treated similarly.
|
|---|
| 127 |
|
|---|
| 128 | If \programopt{-n} is not given, a suitable number of loops is
|
|---|
| 129 | calculated by trying successive powers of 10 until the total time is
|
|---|
| 130 | at least 0.2 seconds.
|
|---|
| 131 |
|
|---|
| 132 | The default timer function is platform dependent. On Windows,
|
|---|
| 133 | \function{time.clock()} has microsecond granularity but
|
|---|
| 134 | \function{time.time()}'s granularity is 1/60th of a second; on \UNIX,
|
|---|
| 135 | \function{time.clock()} has 1/100th of a second granularity and
|
|---|
| 136 | \function{time.time()} is much more precise. On either platform, the
|
|---|
| 137 | default timer functions measure wall clock time, not the CPU time.
|
|---|
| 138 | This means that other processes running on the same computer may
|
|---|
| 139 | interfere with the timing. The best thing to do when accurate timing
|
|---|
| 140 | is necessary is to repeat the timing a few times and use the best
|
|---|
| 141 | time. The \programopt{-r} option is good for this; the default of 3
|
|---|
| 142 | repetitions is probably enough in most cases. On \UNIX, you can use
|
|---|
| 143 | \function{time.clock()} to measure CPU time.
|
|---|
| 144 |
|
|---|
| 145 | \begin{notice}
|
|---|
| 146 | There is a certain baseline overhead associated with executing a
|
|---|
| 147 | pass statement. The code here doesn't try to hide it, but you
|
|---|
| 148 | should be aware of it. The baseline overhead can be measured by
|
|---|
| 149 | invoking the program without arguments.
|
|---|
| 150 | \end{notice}
|
|---|
| 151 |
|
|---|
| 152 | The baseline overhead differs between Python versions! Also, to
|
|---|
| 153 | fairly compare older Python versions to Python 2.3, you may want to
|
|---|
| 154 | use Python's \programopt{-O} option for the older versions to avoid
|
|---|
| 155 | timing \code{SET_LINENO} instructions.
|
|---|
| 156 |
|
|---|
| 157 | \subsection{Examples}
|
|---|
| 158 |
|
|---|
| 159 | Here are two example sessions (one using the command line, one using
|
|---|
| 160 | the module interface) that compare the cost of using
|
|---|
| 161 | \function{hasattr()} vs. \keyword{try}/\keyword{except} to test for
|
|---|
| 162 | missing and present object attributes.
|
|---|
| 163 |
|
|---|
| 164 | \begin{verbatim}
|
|---|
| 165 | % timeit.py 'try:' ' str.__nonzero__' 'except AttributeError:' ' pass'
|
|---|
| 166 | 100000 loops, best of 3: 15.7 usec per loop
|
|---|
| 167 | % timeit.py 'if hasattr(str, "__nonzero__"): pass'
|
|---|
| 168 | 100000 loops, best of 3: 4.26 usec per loop
|
|---|
| 169 | % timeit.py 'try:' ' int.__nonzero__' 'except AttributeError:' ' pass'
|
|---|
| 170 | 1000000 loops, best of 3: 1.43 usec per loop
|
|---|
| 171 | % timeit.py 'if hasattr(int, "__nonzero__"): pass'
|
|---|
| 172 | 100000 loops, best of 3: 2.23 usec per loop
|
|---|
| 173 | \end{verbatim}
|
|---|
| 174 |
|
|---|
| 175 | \begin{verbatim}
|
|---|
| 176 | >>> import timeit
|
|---|
| 177 | >>> s = """\
|
|---|
| 178 | ... try:
|
|---|
| 179 | ... str.__nonzero__
|
|---|
| 180 | ... except AttributeError:
|
|---|
| 181 | ... pass
|
|---|
| 182 | ... """
|
|---|
| 183 | >>> t = timeit.Timer(stmt=s)
|
|---|
| 184 | >>> print "%.2f usec/pass" % (1000000 * t.timeit(number=100000)/100000)
|
|---|
| 185 | 17.09 usec/pass
|
|---|
| 186 | >>> s = """\
|
|---|
| 187 | ... if hasattr(str, '__nonzero__'): pass
|
|---|
| 188 | ... """
|
|---|
| 189 | >>> t = timeit.Timer(stmt=s)
|
|---|
| 190 | >>> print "%.2f usec/pass" % (1000000 * t.timeit(number=100000)/100000)
|
|---|
| 191 | 4.85 usec/pass
|
|---|
| 192 | >>> s = """\
|
|---|
| 193 | ... try:
|
|---|
| 194 | ... int.__nonzero__
|
|---|
| 195 | ... except AttributeError:
|
|---|
| 196 | ... pass
|
|---|
| 197 | ... """
|
|---|
| 198 | >>> t = timeit.Timer(stmt=s)
|
|---|
| 199 | >>> print "%.2f usec/pass" % (1000000 * t.timeit(number=100000)/100000)
|
|---|
| 200 | 1.97 usec/pass
|
|---|
| 201 | >>> s = """\
|
|---|
| 202 | ... if hasattr(int, '__nonzero__'): pass
|
|---|
| 203 | ... """
|
|---|
| 204 | >>> t = timeit.Timer(stmt=s)
|
|---|
| 205 | >>> print "%.2f usec/pass" % (1000000 * t.timeit(number=100000)/100000)
|
|---|
| 206 | 3.15 usec/pass
|
|---|
| 207 | \end{verbatim}
|
|---|
| 208 |
|
|---|
| 209 | To give the \module{timeit} module access to functions you
|
|---|
| 210 | define, you can pass a \code{setup} parameter which contains an import
|
|---|
| 211 | statement:
|
|---|
| 212 |
|
|---|
| 213 | \begin{verbatim}
|
|---|
| 214 | def test():
|
|---|
| 215 | "Stupid test function"
|
|---|
| 216 | L = []
|
|---|
| 217 | for i in range(100):
|
|---|
| 218 | L.append(i)
|
|---|
| 219 |
|
|---|
| 220 | if __name__=='__main__':
|
|---|
| 221 | from timeit import Timer
|
|---|
| 222 | t = Timer("test()", "from __main__ import test")
|
|---|
| 223 | print t.timeit()
|
|---|
| 224 | \end{verbatim}
|
|---|