S
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..... return x+1
....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)
One solution is to work like this:
.... return x+1
.... """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:
.... _it = [None]*n
.... t = time.time()
.... for _ in _it:
.... foo(1)
.... t = time.time() - t
.... return t
....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:
.... return
.... """
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?
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
....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)
One solution is to work like this:
.... return x+1
.... """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:
.... _it = [None]*n
.... t = time.time()
.... for _ in _it:
.... foo(1)
.... t = time.time() - t
.... return t
....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:
.... return
.... """
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?