2003-04-08 22:38:53 -03:00
|
|
|
\section{\module{timeit} ---
|
|
|
|
Measure execution time of small code snippets}
|
|
|
|
|
|
|
|
\declaremodule{standard}{timeit}
|
|
|
|
\modulesynopsis{Measure the execution time of small code snippets.}
|
|
|
|
|
2003-04-09 01:06:37 -03:00
|
|
|
\versionadded{2.3}
|
2003-04-08 22:38:53 -03:00
|
|
|
\index{Benchmarking}
|
|
|
|
\index{Performance}
|
|
|
|
|
2003-04-09 01:06:37 -03:00
|
|
|
This module provides a simple way to time small bits of Python code.
|
|
|
|
It has both command line as well as callable interfaces. It avoids a
|
|
|
|
number of common traps for measuring execution times. See also Tim
|
|
|
|
Peters' introduction to the ``Algorithms'' chapter in the
|
|
|
|
\citetitle{Python Cookbook}, published by O'Reilly.
|
2003-04-08 22:38:53 -03:00
|
|
|
|
2003-04-09 01:06:37 -03:00
|
|
|
The module defines the following public class:
|
2003-04-08 22:38:53 -03:00
|
|
|
|
2003-04-09 01:06:37 -03:00
|
|
|
\begin{classdesc}{Timer}{\optional{stmt=\code{'pass'}
|
|
|
|
\optional{, setup=\code{'pass'}
|
|
|
|
\optional{, timer=<timer function>}}}}
|
2003-04-08 22:38:53 -03:00
|
|
|
Class for timing execution speed of small code snippets.
|
|
|
|
|
2003-04-09 01:06:37 -03:00
|
|
|
The constructor takes a statement to be timed, an additional statement
|
|
|
|
used for setup, and a timer function. Both statements default to
|
|
|
|
\code{'pass'}; the timer function is platform-dependent (see the
|
|
|
|
module doc string). The statements may contain newlines, as long as
|
|
|
|
they don't contain multi-line string literals.
|
2003-04-08 22:38:53 -03:00
|
|
|
|
2003-04-09 01:06:37 -03:00
|
|
|
To measure the execution time of the first statement, use the
|
|
|
|
\method{timeit()} method. The \method{repeat()} method is a
|
|
|
|
convenience to call \method{timeit()} multiple times and return a list
|
|
|
|
of results.
|
|
|
|
\end{classdesc}
|
2003-04-08 22:38:53 -03:00
|
|
|
|
2003-04-09 01:06:37 -03:00
|
|
|
\begin{methoddesc}{print_exc}{\optional{file=\constant{None}}}
|
2003-04-08 22:38:53 -03:00
|
|
|
Helper to print a traceback from the timed code.
|
|
|
|
|
|
|
|
Typical use:
|
|
|
|
|
|
|
|
\begin{verbatim}
|
|
|
|
t = Timer(...) # outside the try/except
|
|
|
|
try:
|
|
|
|
t.timeit(...) # or t.repeat(...)
|
|
|
|
except:
|
|
|
|
t.print_exc()
|
|
|
|
\end{verbatim}
|
|
|
|
|
|
|
|
The advantage over the standard traceback is that source lines in the
|
|
|
|
compiled template will be displayed.
|
2003-04-09 01:06:37 -03:00
|
|
|
The optional \var{file} argument directs where the traceback is sent;
|
|
|
|
it defaults to \code{sys.stderr}.
|
2003-04-08 22:38:53 -03:00
|
|
|
\end{methoddesc}
|
|
|
|
|
2003-05-10 00:35:37 -03:00
|
|
|
\begin{methoddesc}{repeat}{\optional{repeat\code{=3} \optional{,
|
2003-04-09 01:06:37 -03:00
|
|
|
number\code{=1000000}}}}
|
2003-04-08 22:38:53 -03:00
|
|
|
Call \method{timeit()} a few times.
|
|
|
|
|
2003-04-09 01:06:37 -03:00
|
|
|
This is a convenience function that calls the \method{timeit()}
|
|
|
|
repeatedly, returning a list of results. The first argument specifies
|
|
|
|
how many times to call \method{timeit()}. The second argument
|
|
|
|
specifies the \var{number} argument for \function{timeit()}.
|
2003-04-08 22:38:53 -03:00
|
|
|
|
2003-04-09 01:06:37 -03:00
|
|
|
\begin{notice}
|
|
|
|
It's tempting to calculate mean and standard deviation from the result
|
2003-04-08 22:38:53 -03:00
|
|
|
vector and report these. However, this is not very useful. In a typical
|
|
|
|
case, the lowest value gives a lower bound for how fast your machine can run
|
|
|
|
the given code snippet; higher values in the result vector are typically not
|
|
|
|
caused by variability in Python's speed, but by other processes interfering
|
|
|
|
with your timing accuracy. So the \function{min()} of the result is
|
|
|
|
probably the only number you should be interested in. After that, you
|
|
|
|
should look at the entire vector and apply common sense rather than
|
|
|
|
statistics.
|
2003-04-09 01:06:37 -03:00
|
|
|
\end{notice}
|
2003-04-08 22:38:53 -03:00
|
|
|
\end{methoddesc}
|
|
|
|
|
2003-04-09 01:06:37 -03:00
|
|
|
\begin{methoddesc}{timeit}{\optional{number\code{=1000000}}}
|
|
|
|
Time \var{number} executions of the main statement.
|
|
|
|
This executes the setup statement once, and then
|
|
|
|
returns the time it takes to execute the main statement a number of
|
|
|
|
times, measured in seconds as a float. The argument is the number of
|
|
|
|
times through the loop, defaulting to one million. The main
|
|
|
|
statement, the setup statement and the timer function to be used are
|
|
|
|
passed to the constructor.
|
2004-01-04 17:19:18 -04:00
|
|
|
|
|
|
|
\begin{notice}
|
|
|
|
By default, \method{timeit()} temporarily turns off garbage collection
|
|
|
|
during the timing. The advantage of this approach is that it makes
|
|
|
|
independent timings more comparable. This disadvantage is that GC
|
|
|
|
may be an important component of the performance of the function being
|
|
|
|
measured. If so, GC can be re-enabled as the first statement in the
|
|
|
|
\var{setup} string. For example:
|
|
|
|
\begin{verbatim}
|
|
|
|
timeit.Timer('for i in xrange(10): oct(i)', 'gc.enable()').timeit()
|
|
|
|
\end{verbatim}
|
|
|
|
\end{notice}
|
2003-04-08 22:38:53 -03:00
|
|
|
\end{methoddesc}
|
2003-04-09 01:06:37 -03:00
|
|
|
|
2003-04-08 22:38:53 -03:00
|
|
|
|
|
|
|
\subsection{Command Line Interface}
|
|
|
|
|
|
|
|
When called as a program from the command line, the following form is used:
|
|
|
|
|
|
|
|
\begin{verbatim}
|
2007-03-22 05:05:53 -03:00
|
|
|
python -m timeit [-n N] [-r N] [-s S] [-t] [-c] [-h] [statement ...]
|
2003-04-08 22:38:53 -03:00
|
|
|
\end{verbatim}
|
|
|
|
|
|
|
|
where the following options are understood:
|
|
|
|
|
|
|
|
\begin{description}
|
2003-08-31 01:20:12 -03:00
|
|
|
\item[-n N/\longprogramopt{number=N}] how many times to execute 'statement'
|
|
|
|
\item[-r N/\longprogramopt{repeat=N}] how many times to repeat the timer (default 3)
|
|
|
|
\item[-s S/\longprogramopt{setup=S}] statement to be executed once initially (default
|
2003-04-09 01:06:37 -03:00
|
|
|
\code{'pass'})
|
2003-08-31 01:20:12 -03:00
|
|
|
\item[-t/\longprogramopt{time}] use \function{time.time()}
|
2003-04-09 01:06:37 -03:00
|
|
|
(default on all platforms but Windows)
|
2003-08-31 01:20:12 -03:00
|
|
|
\item[-c/\longprogramopt{clock}] use \function{time.clock()} (default on Windows)
|
|
|
|
\item[-v/\longprogramopt{verbose}] print raw timing results; repeat for more digits
|
2003-04-09 01:06:37 -03:00
|
|
|
precision
|
2003-08-31 01:20:12 -03:00
|
|
|
\item[-h/\longprogramopt{help}] print a short usage message and exit
|
2003-04-08 22:38:53 -03:00
|
|
|
\end{description}
|
|
|
|
|
2003-04-09 01:06:37 -03:00
|
|
|
A multi-line statement may be given by specifying each line as a
|
|
|
|
separate statement argument; indented lines are possible by enclosing
|
|
|
|
an argument in quotes and using leading spaces. Multiple
|
|
|
|
\programopt{-s} options are treated similarly.
|
|
|
|
|
|
|
|
If \programopt{-n} is not given, a suitable number of loops is
|
|
|
|
calculated by trying successive powers of 10 until the total time is
|
|
|
|
at least 0.2 seconds.
|
|
|
|
|
|
|
|
The default timer function is platform dependent. On Windows,
|
|
|
|
\function{time.clock()} has microsecond granularity but
|
|
|
|
\function{time.time()}'s granularity is 1/60th of a second; on \UNIX,
|
|
|
|
\function{time.clock()} has 1/100th of a second granularity and
|
|
|
|
\function{time.time()} is much more precise. On either platform, the
|
2003-09-20 08:09:28 -03:00
|
|
|
default timer functions measure wall clock time, not the CPU time.
|
2003-04-09 01:06:37 -03:00
|
|
|
This means that other processes running on the same computer may
|
|
|
|
interfere with the timing. The best thing to do when accurate timing
|
|
|
|
is necessary is to repeat the timing a few times and use the best
|
|
|
|
time. The \programopt{-r} option is good for this; the default of 3
|
|
|
|
repetitions is probably enough in most cases. On \UNIX, you can use
|
|
|
|
\function{time.clock()} to measure CPU time.
|
|
|
|
|
|
|
|
\begin{notice}
|
|
|
|
There is a certain baseline overhead associated with executing a
|
|
|
|
pass statement. The code here doesn't try to hide it, but you
|
|
|
|
should be aware of it. The baseline overhead can be measured by
|
|
|
|
invoking the program without arguments.
|
|
|
|
\end{notice}
|
|
|
|
|
|
|
|
The baseline overhead differs between Python versions! Also, to
|
|
|
|
fairly compare older Python versions to Python 2.3, you may want to
|
|
|
|
use Python's \programopt{-O} option for the older versions to avoid
|
|
|
|
timing \code{SET_LINENO} instructions.
|
2003-04-08 22:38:53 -03:00
|
|
|
|
|
|
|
\subsection{Examples}
|
|
|
|
|
2003-04-09 01:06:37 -03:00
|
|
|
Here are two example sessions (one using the command line, one using
|
|
|
|
the module interface) that compare the cost of using
|
|
|
|
\function{hasattr()} vs. \keyword{try}/\keyword{except} to test for
|
|
|
|
missing and present object attributes.
|
2003-04-08 22:38:53 -03:00
|
|
|
|
|
|
|
\begin{verbatim}
|
2003-04-09 01:06:37 -03:00
|
|
|
% timeit.py 'try:' ' str.__nonzero__' 'except AttributeError:' ' pass'
|
2003-04-08 22:38:53 -03:00
|
|
|
100000 loops, best of 3: 15.7 usec per loop
|
2003-04-09 01:06:37 -03:00
|
|
|
% timeit.py 'if hasattr(str, "__nonzero__"): pass'
|
2003-04-08 22:38:53 -03:00
|
|
|
100000 loops, best of 3: 4.26 usec per loop
|
2003-04-09 01:06:37 -03:00
|
|
|
% timeit.py 'try:' ' int.__nonzero__' 'except AttributeError:' ' pass'
|
2003-04-08 22:38:53 -03:00
|
|
|
1000000 loops, best of 3: 1.43 usec per loop
|
2003-04-09 01:06:37 -03:00
|
|
|
% timeit.py 'if hasattr(int, "__nonzero__"): pass'
|
2003-04-08 22:38:53 -03:00
|
|
|
100000 loops, best of 3: 2.23 usec per loop
|
|
|
|
\end{verbatim}
|
|
|
|
|
|
|
|
\begin{verbatim}
|
|
|
|
>>> import timeit
|
|
|
|
>>> s = """\
|
|
|
|
... try:
|
2003-04-09 01:06:37 -03:00
|
|
|
... str.__nonzero__
|
2003-04-08 22:38:53 -03:00
|
|
|
... except AttributeError:
|
2003-04-09 01:06:37 -03:00
|
|
|
... pass
|
2003-04-08 22:38:53 -03:00
|
|
|
... """
|
|
|
|
>>> t = timeit.Timer(stmt=s)
|
|
|
|
>>> print "%.2f usec/pass" % (1000000 * t.timeit(number=100000)/100000)
|
|
|
|
17.09 usec/pass
|
|
|
|
>>> s = """\
|
|
|
|
... if hasattr(str, '__nonzero__'): pass
|
|
|
|
... """
|
|
|
|
>>> t = timeit.Timer(stmt=s)
|
|
|
|
>>> print "%.2f usec/pass" % (1000000 * t.timeit(number=100000)/100000)
|
|
|
|
4.85 usec/pass
|
|
|
|
>>> s = """\
|
|
|
|
... try:
|
2003-04-09 01:06:37 -03:00
|
|
|
... int.__nonzero__
|
2003-04-08 22:38:53 -03:00
|
|
|
... except AttributeError:
|
2003-04-09 01:06:37 -03:00
|
|
|
... pass
|
2003-04-08 22:38:53 -03:00
|
|
|
... """
|
|
|
|
>>> t = timeit.Timer(stmt=s)
|
|
|
|
>>> print "%.2f usec/pass" % (1000000 * t.timeit(number=100000)/100000)
|
|
|
|
1.97 usec/pass
|
|
|
|
>>> s = """\
|
|
|
|
... if hasattr(int, '__nonzero__'): pass
|
|
|
|
... """
|
|
|
|
>>> t = timeit.Timer(stmt=s)
|
|
|
|
>>> print "%.2f usec/pass" % (1000000 * t.timeit(number=100000)/100000)
|
|
|
|
3.15 usec/pass
|
|
|
|
\end{verbatim}
|
2003-05-09 15:21:02 -03:00
|
|
|
|
|
|
|
To give the \module{timeit} module access to functions you
|
|
|
|
define, you can pass a \code{setup} parameter which contains an import
|
|
|
|
statement:
|
|
|
|
|
|
|
|
\begin{verbatim}
|
|
|
|
def test():
|
|
|
|
"Stupid test function"
|
|
|
|
L = []
|
|
|
|
for i in range(100):
|
|
|
|
L.append(i)
|
|
|
|
|
|
|
|
if __name__=='__main__':
|
|
|
|
from timeit import Timer
|
|
|
|
t = Timer("test()", "from __main__ import test")
|
|
|
|
print t.timeit()
|
|
|
|
\end{verbatim}
|