2003-04-09 03:49:40 +08:00
|
|
|
#! /usr/bin/env python
|
|
|
|
|
2003-03-07 09:33:18 +08:00
|
|
|
"""Tool for measuring execution time of small code snippets.
|
2003-03-06 07:31:58 +08:00
|
|
|
|
2003-03-06 10:32:19 +08:00
|
|
|
This module avoids a number of common traps for measuring execution
|
|
|
|
times. See also Tim Peters' introduction to the Algorithms chapter in
|
|
|
|
the Python Cookbook, published by O'Reilly.
|
2003-03-06 07:31:58 +08:00
|
|
|
|
2003-03-06 10:32:19 +08:00
|
|
|
Library usage: see the Timer class.
|
2003-03-06 07:31:58 +08:00
|
|
|
|
|
|
|
Command line usage:
|
2003-03-06 11:02:10 +08:00
|
|
|
python timeit.py [-n N] [-r N] [-s S] [-t] [-c] [-h] [statement]
|
2003-03-06 07:31:58 +08:00
|
|
|
|
|
|
|
Options:
|
2003-03-06 10:32:19 +08:00
|
|
|
-n/--number N: how many times to execute 'statement' (default: see below)
|
2003-03-15 20:25:00 +08:00
|
|
|
-r/--repeat N: how many times to repeat the timer (default 3)
|
2003-03-07 09:33:18 +08:00
|
|
|
-s/--setup S: statement to be executed once initially (default 'pass')
|
2003-03-06 07:31:58 +08:00
|
|
|
-t/--time: use time.time() (default on Unix)
|
|
|
|
-c/--clock: use time.clock() (default on Windows)
|
2003-03-15 20:25:00 +08:00
|
|
|
-v/--verbose: print raw timing results; repeat for more digits precision
|
2003-03-06 11:02:10 +08:00
|
|
|
-h/--help: print this usage message and exit
|
2003-03-06 07:31:58 +08:00
|
|
|
statement: statement to be timed (default 'pass')
|
2003-03-06 10:32:19 +08:00
|
|
|
|
|
|
|
A multi-line statement may be given by specifying each line as a
|
|
|
|
separate argument; indented lines are possible by enclosing an
|
2003-03-07 09:33:18 +08:00
|
|
|
argument in quotes and using leading spaces. Multiple -s options are
|
|
|
|
treated similarly.
|
2003-03-06 10:32:19 +08:00
|
|
|
|
|
|
|
If -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 difference in default timer function is because on Windows,
|
|
|
|
clock() has microsecond granularity but time()'s granularity is 1/60th
|
|
|
|
of a second; on Unix, clock() has 1/100th of a second granularity and
|
|
|
|
time() is much more precise. On either platform, the default timer
|
2003-09-20 19:09:28 +08:00
|
|
|
functions measure wall clock time, not the CPU time. This means that
|
2003-03-06 10:32:19 +08:00
|
|
|
other processes running on the same computer may interfere with the
|
|
|
|
timing. The best thing to do when accurate timing is necessary is to
|
2003-03-15 20:25:00 +08:00
|
|
|
repeat the timing a few times and use the best time. The -r option is
|
|
|
|
good for this; the default of 3 repetitions is probably enough in most
|
|
|
|
cases. On Unix, you can use clock() to measure CPU time.
|
2003-03-06 11:02:10 +08:00
|
|
|
|
|
|
|
Note: there is a certain baseline overhead associated with executing a
|
|
|
|
pass statement. The code here doesn't try to hide it, but you should
|
2003-03-07 09:33:18 +08:00
|
|
|
be aware of it. The baseline overhead can be measured by invoking the
|
|
|
|
program without arguments.
|
2003-03-06 10:32:19 +08:00
|
|
|
|
2003-03-07 09:33:18 +08:00
|
|
|
The baseline overhead differs between Python versions! Also, to
|
|
|
|
fairly compare older Python versions to Python 2.3, you may want to
|
|
|
|
use python -O for the older versions to avoid timing SET_LINENO
|
|
|
|
instructions.
|
|
|
|
"""
|
2003-03-07 00:11:17 +08:00
|
|
|
|
2003-03-06 07:31:58 +08:00
|
|
|
import sys
|
|
|
|
import time
|
2003-03-07 09:33:18 +08:00
|
|
|
try:
|
|
|
|
import itertools
|
|
|
|
except ImportError:
|
|
|
|
# Must be an older Python version (see timeit() below)
|
|
|
|
itertools = None
|
2003-03-06 07:31:58 +08:00
|
|
|
|
|
|
|
__all__ = ["Timer"]
|
|
|
|
|
2003-03-15 01:21:00 +08:00
|
|
|
dummy_src_name = "<timeit-src>"
|
2003-03-06 07:31:58 +08:00
|
|
|
default_number = 1000000
|
2003-03-15 20:25:00 +08:00
|
|
|
default_repeat = 3
|
2003-03-06 07:31:58 +08:00
|
|
|
|
|
|
|
if sys.platform == "win32":
|
|
|
|
# On Windows, the best timer is time.clock()
|
|
|
|
default_timer = time.clock
|
|
|
|
else:
|
|
|
|
# On most other platforms the best timer is time.time()
|
|
|
|
default_timer = time.time
|
|
|
|
|
2003-03-06 10:32:19 +08:00
|
|
|
# Don't change the indentation of the template; the reindent() calls
|
|
|
|
# in Timer.__init__() depend on setup being indented 4 spaces and stmt
|
|
|
|
# being indented 8 spaces.
|
2003-03-06 07:31:58 +08:00
|
|
|
template = """
|
2003-03-21 22:54:19 +08:00
|
|
|
def inner(_it, _timer):
|
2003-03-06 07:31:58 +08:00
|
|
|
%(setup)s
|
2003-03-15 01:21:00 +08:00
|
|
|
_t0 = _timer()
|
2003-03-21 22:54:19 +08:00
|
|
|
for _i in _it:
|
2003-03-06 07:31:58 +08:00
|
|
|
%(stmt)s
|
2003-03-15 01:21:00 +08:00
|
|
|
_t1 = _timer()
|
|
|
|
return _t1 - _t0
|
2003-03-06 07:31:58 +08:00
|
|
|
"""
|
|
|
|
|
|
|
|
def reindent(src, indent):
|
2003-03-06 10:32:19 +08:00
|
|
|
"""Helper to reindent a multi-line statement."""
|
2003-03-06 21:09:09 +08:00
|
|
|
return src.replace("\n", "\n" + " "*indent)
|
2003-03-06 07:31:58 +08:00
|
|
|
|
|
|
|
class Timer:
|
2003-03-06 10:32:19 +08:00
|
|
|
"""Class for timing execution speed of small code snippets.
|
|
|
|
|
|
|
|
The constructor takes a statement to be timed, an additional
|
|
|
|
statement used for setup, and a timer function. Both statements
|
|
|
|
default to 'pass'; the timer function is platform-dependent (see
|
|
|
|
module doc string).
|
|
|
|
|
|
|
|
To measure the execution time of the first statement, use the
|
|
|
|
timeit() method. The repeat() method is a convenience to call
|
|
|
|
timeit() multiple times and return a list of results.
|
|
|
|
|
|
|
|
The statements may contain newlines, as long as they don't contain
|
|
|
|
multi-line string literals.
|
|
|
|
"""
|
2003-03-06 07:31:58 +08:00
|
|
|
|
|
|
|
def __init__(self, stmt="pass", setup="pass", timer=default_timer):
|
2003-03-06 10:32:19 +08:00
|
|
|
"""Constructor. See class doc string."""
|
2003-03-06 07:31:58 +08:00
|
|
|
self.timer = timer
|
|
|
|
stmt = reindent(stmt, 8)
|
|
|
|
setup = reindent(setup, 4)
|
|
|
|
src = template % {'stmt': stmt, 'setup': setup}
|
2003-03-15 01:21:00 +08:00
|
|
|
self.src = src # Save for traceback display
|
|
|
|
code = compile(src, dummy_src_name, "exec")
|
2003-03-06 07:31:58 +08:00
|
|
|
ns = {}
|
|
|
|
exec code in globals(), ns
|
|
|
|
self.inner = ns["inner"]
|
|
|
|
|
2003-03-15 01:21:00 +08:00
|
|
|
def print_exc(self, file=None):
|
|
|
|
"""Helper to print a traceback from the timed code.
|
|
|
|
|
|
|
|
Typical use:
|
|
|
|
|
|
|
|
t = Timer(...) # outside the try/except
|
|
|
|
try:
|
|
|
|
t.timeit(...) # or t.repeat(...)
|
|
|
|
except:
|
|
|
|
t.print_exc()
|
|
|
|
|
|
|
|
The advantage over the standard traceback is that source lines
|
|
|
|
in the compiled template will be displayed.
|
|
|
|
|
|
|
|
The optional file argument directs where the traceback is
|
|
|
|
sent; it defaults to sys.stderr.
|
|
|
|
"""
|
|
|
|
import linecache, traceback
|
|
|
|
linecache.cache[dummy_src_name] = (len(self.src),
|
|
|
|
None,
|
|
|
|
self.src.split("\n"),
|
|
|
|
dummy_src_name)
|
|
|
|
traceback.print_exc(file=file)
|
|
|
|
|
2003-03-06 07:31:58 +08:00
|
|
|
def timeit(self, number=default_number):
|
2003-03-06 10:32:19 +08:00
|
|
|
"""Time 'number' executions of the main statement.
|
|
|
|
|
|
|
|
To be precise, this executes the setup statement once, and
|
|
|
|
then returns the time it takes to execute the main statement
|
|
|
|
a number of times, as a float measured in seconds. 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.
|
|
|
|
"""
|
2003-03-07 09:33:18 +08:00
|
|
|
if itertools:
|
2003-03-21 22:54:19 +08:00
|
|
|
it = itertools.repeat(None, number)
|
2003-03-07 09:33:18 +08:00
|
|
|
else:
|
2003-03-21 22:54:19 +08:00
|
|
|
it = [None] * number
|
|
|
|
return self.inner(it, self.timer)
|
2003-03-06 07:31:58 +08:00
|
|
|
|
|
|
|
def repeat(self, repeat=default_repeat, number=default_number):
|
2003-04-09 03:40:19 +08:00
|
|
|
"""Call timeit() a few times.
|
2003-03-06 10:32:19 +08:00
|
|
|
|
2003-04-09 03:40:19 +08:00
|
|
|
This is a convenience function that calls the timeit()
|
2003-03-06 10:32:19 +08:00
|
|
|
repeatedly, returning a list of results. The first argument
|
2003-04-09 03:40:19 +08:00
|
|
|
specifies how many times to call timeit(), defaulting to 3;
|
2003-03-06 10:32:19 +08:00
|
|
|
the second argument specifies the timer argument, defaulting
|
|
|
|
to one million.
|
2003-03-07 00:11:17 +08:00
|
|
|
|
|
|
|
Note: it's tempting to calculate mean and standard deviation
|
|
|
|
from the result 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 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-03-06 10:32:19 +08:00
|
|
|
"""
|
2003-03-06 07:31:58 +08:00
|
|
|
r = []
|
|
|
|
for i in range(repeat):
|
|
|
|
t = self.timeit(number)
|
|
|
|
r.append(t)
|
|
|
|
return r
|
|
|
|
|
|
|
|
def main(args=None):
|
2003-03-06 10:32:19 +08:00
|
|
|
"""Main program, used when run as a script.
|
|
|
|
|
|
|
|
The optional argument specifies the command line to be parsed,
|
|
|
|
defaulting to sys.argv[1:].
|
|
|
|
|
|
|
|
The return value is an exit code to be passed to sys.exit(); it
|
|
|
|
may be None to indicate success.
|
2003-03-15 01:21:00 +08:00
|
|
|
|
|
|
|
When an exception happens during timing, a traceback is printed to
|
|
|
|
stderr and the return value is 1. Exceptions at other times
|
|
|
|
(including the template compilation) are not caught.
|
2003-03-06 10:32:19 +08:00
|
|
|
"""
|
2003-03-06 07:31:58 +08:00
|
|
|
if args is None:
|
|
|
|
args = sys.argv[1:]
|
|
|
|
import getopt
|
|
|
|
try:
|
2003-03-15 20:25:00 +08:00
|
|
|
opts, args = getopt.getopt(args, "n:s:r:tcvh",
|
2003-03-06 07:31:58 +08:00
|
|
|
["number=", "setup=", "repeat=",
|
2003-03-15 20:25:00 +08:00
|
|
|
"time", "clock", "verbose", "help"])
|
2003-03-06 07:31:58 +08:00
|
|
|
except getopt.error, err:
|
|
|
|
print err
|
2003-03-06 11:02:10 +08:00
|
|
|
print "use -h/--help for command line help"
|
2003-03-06 07:31:58 +08:00
|
|
|
return 2
|
|
|
|
timer = default_timer
|
|
|
|
stmt = "\n".join(args) or "pass"
|
|
|
|
number = 0 # auto-determine
|
2003-03-07 09:33:18 +08:00
|
|
|
setup = []
|
2003-03-15 20:25:00 +08:00
|
|
|
repeat = default_repeat
|
|
|
|
verbose = 0
|
|
|
|
precision = 3
|
2003-03-06 07:31:58 +08:00
|
|
|
for o, a in opts:
|
|
|
|
if o in ("-n", "--number"):
|
|
|
|
number = int(a)
|
|
|
|
if o in ("-s", "--setup"):
|
2003-03-07 09:33:18 +08:00
|
|
|
setup.append(a)
|
2003-03-06 07:31:58 +08:00
|
|
|
if o in ("-r", "--repeat"):
|
|
|
|
repeat = int(a)
|
|
|
|
if repeat <= 0:
|
|
|
|
repeat = 1
|
2003-03-06 11:02:10 +08:00
|
|
|
if o in ("-t", "--time"):
|
2003-03-06 07:31:58 +08:00
|
|
|
timer = time.time
|
2003-03-06 11:02:10 +08:00
|
|
|
if o in ("-c", "--clock"):
|
2003-03-06 07:31:58 +08:00
|
|
|
timer = time.clock
|
2003-03-15 20:25:00 +08:00
|
|
|
if o in ("-v", "--verbose"):
|
|
|
|
if verbose:
|
|
|
|
precision += 1
|
|
|
|
verbose += 1
|
2003-03-06 11:02:10 +08:00
|
|
|
if o in ("-h", "--help"):
|
|
|
|
print __doc__,
|
|
|
|
return 0
|
2003-03-07 09:33:18 +08:00
|
|
|
setup = "\n".join(setup) or "pass"
|
2003-05-20 12:59:56 +08:00
|
|
|
# Include the current directory, so that local imports work (sys.path
|
|
|
|
# contains the directory of this script, rather than the current
|
|
|
|
# directory)
|
|
|
|
import os
|
|
|
|
sys.path.insert(0, os.curdir)
|
2003-03-06 07:31:58 +08:00
|
|
|
t = Timer(stmt, setup, timer)
|
|
|
|
if number == 0:
|
|
|
|
# determine number so that 0.2 <= total time < 2.0
|
|
|
|
for i in range(1, 10):
|
|
|
|
number = 10**i
|
2003-03-15 01:21:00 +08:00
|
|
|
try:
|
|
|
|
x = t.timeit(number)
|
|
|
|
except:
|
|
|
|
t.print_exc()
|
|
|
|
return 1
|
2003-03-15 20:25:00 +08:00
|
|
|
if verbose:
|
|
|
|
print "%d loops -> %.*g secs" % (number, precision, x)
|
2003-03-06 07:31:58 +08:00
|
|
|
if x >= 0.2:
|
|
|
|
break
|
2003-03-15 01:21:00 +08:00
|
|
|
try:
|
|
|
|
r = t.repeat(repeat, number)
|
|
|
|
except:
|
|
|
|
t.print_exc()
|
|
|
|
return 1
|
2003-03-06 07:31:58 +08:00
|
|
|
best = min(r)
|
2003-03-15 20:25:00 +08:00
|
|
|
if verbose:
|
|
|
|
print "raw times:", " ".join(["%.*g" % (precision, x) for x in r])
|
2003-03-06 07:31:58 +08:00
|
|
|
print "%d loops," % number,
|
|
|
|
usec = best * 1e6 / number
|
2003-10-21 07:38:28 +08:00
|
|
|
if usec < 1000:
|
|
|
|
print "best of %d: %.*g usec per loop" % (repeat, precision, usec)
|
|
|
|
else:
|
|
|
|
msec = usec / 1000
|
|
|
|
if msec < 1000:
|
|
|
|
print "best of %d: %.*g msec per loop" % (repeat, precision, msec)
|
|
|
|
else:
|
|
|
|
sec = msec / 1000
|
|
|
|
print "best of %d: %.*g sec per loop" % (repeat, precision, sec)
|
2003-03-06 10:32:19 +08:00
|
|
|
return None
|
2003-03-06 07:31:58 +08:00
|
|
|
|
|
|
|
if __name__ == "__main__":
|
|
|
|
sys.exit(main())
|