measure large function objects.
Because the timeit module takes the code snippet argument as a string, it
is quite handy to use from the command line, but it is less convenient for
timing large pieces of code or when working in the interactive
interpreter. E.g. variations on this *don't* work:
$ python
Python 2.4.3 (#1, Jun 13 2006, 11:46:08)
[GCC 4.1.1 20060525 (Red Hat 4.1.1-1)] on linux2
Type "help", "copyright", "credits" or "license" for more information.
.... return x+1>>>
def foo(x):
....
Traceback (most recent call last):>>assert foo(1) == 2 # do lots of interactive testing
import timeit
timeit.Timer("foo(1)").timeit()
File "<stdin>", line 1, in ?
File "/usr/lib/python2.4/timeit.py", line 161, in timeit
timing = self.inner(it, self.timer)
File "<timeit-src>", line 6, in inner
NameError: global name 'foo' is not defined
One solution is to work like this:>>>
.... return x+1>>foo_str = """def foo(x):
.... """
0.006793975830078125>>exec foo_str
assert foo(1) == 2
timeit.Timer("foo(1)", foo_str).timeit(10000)
Not so useful if you are timing functions from existing code, and very
easy to get foo_str and foo out of sync.
One solution is to resign oneself that timeit is just no good for timing
actual function objects, and to resort to writing ad hoc and potentially
buggy timing code any time you want to time a function:
.... _it = [None]*n>>import time
def timer(n=10000):
.... t = time.time()
.... for _ in _it:
.... foo(1)
.... t = time.time() - t
.... return t
....
0.0082669258117675781>>timer()
That's hardly best practice -- good enough for rough and ready "how fast
is this?" but not scalable beyond one or two functions.
Do others have other suggestions or techniques they use?
I thought I could write a function, similar to the timeit.Timer.timeit()
method, which would take a function object instead of a string, plus
arbitrary arguments, and carefully time how long it takes to execute. I
ended up with something like this:
def ftimer(func, args, kwargs, number=1000000, timer=time.time):
it = itertools.repeat(None, number)
gc_saved = gc.isenabled()
gc.disable()
t0 = timer()
for i in it:
func(*args, **kwargs)
t1 = timer()
if gc_saved:
gc.enable()
return t1 - t0
(Aside: I should put the timing code in a try block, with the gc
restoration code under finally. Next version.)
Much to my surprise, this seems to give me elapsed times about double that
of timeit, at least for small functions that do little work.
I expected that executing the function would be faster than the timeit
module, which goes to show how badly off my intuition regarding the
overhead of timeit was.
I presume the problem is that the time it takes to unroll the *args and
**kwargs is making a significant difference to the time taken. But even if
I remove those arguments, and just call functions that take no arguments,
there is still a significant difference. My ftimer results are
consistently 10-20% longer than timeit. Example:
.... return>>setup_null = """def null():
.... """
0.7631678581237793>>exec setup_null
timeit.Timer("null()", setup_null).timeit()
1.8860080242156982>>ftimer(null, [], {})
0.90903997421264648>>ftimer2(null) # version that doesn't pass *args and **kwargs
Can anyone help me understand these results? Why is the overhead
associated with timeit apparently so much smaller than the overhead in my
ftimer functions?
Am I barking up the wrong tree here? Is there a flaw in my reasoning, and
I'm measuring execution time the wrong way?
Or is it that the timeit module and my ftimer functions are measuring
subtly different things?
--
Steven.
