Timing a function object versus timeit

[Steven D'Aprano]

The timeit module is ideal for measuring small code snippets; I want to
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.
>>>
>>> def foo(x):
... return x+1
...
>>> assert foo(1) == 2 # do lots of interactive testing
>>>
>>> import timeit
>>> timeit.Timer("foo(1)").timeit()
Traceback (most recent call last):
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:

>>> foo_str = """def foo(x):
... return x+1
... """
>>> exec foo_str
>>> assert foo(1) == 2
>>> timeit.Timer("foo(1)", foo_str).timeit(10000)
0.006793975830078125

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:

>>> import time
>>> def timer(n=10000):
... _it = [None]*n
... t = time.time()
... for _ in _it:
... foo(1)
... t = time.time() - t
... return t
...
>>> timer()
0.0082669258117675781

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:

>>> setup_null = """def null():
... return
... """
>>> exec setup_null
>>> timeit.Timer("null()", setup_null).timeit()
0.7631678581237793
>>> ftimer(null, [], {})
1.8860080242156982
>>> ftimer2(null) # version that doesn't pass *args and **kwargs
0.90903997421264648

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.

[Carl Banks]

Steven D'Aprano wrote:
> The timeit module is ideal for measuring small code snippets; I want to
> 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:

[snip]

> Do others have other suggestions or techniques they use?

Python 2.4.3 (#2, Jun 19 2006, 12:51:44)
[GCC 4.0.3 20060212 (prerelease) (Debian 4.0.2-9)] on linux2

Type "help", "copyright", "credits" or "license" for more information.
>>> def foo(x):
... return x+1
...

>>> import timeit
>>> timeit.Timer("foo(1)","from __main__ import foo")
1.1497418880462646

Carl Banks

[Steven D'Aprano]

On Fri, 03 Nov 2006 18:02:37 -0800, Carl Banks wrote:

>>>> import timeit
>>>> timeit.Timer("foo(1)","from __main__ import foo")
> 1.1497418880462646

Well, that was scarily simple.

Thank you.

--
Steven.