timeit versus timing decorator

Question

I'm trying to time some code. First I used a timing decorator:

#!/usr/bin/env python

import time
from itertools import izip
from random import shuffle

def timing_val(func):
    def wrapper(*arg,**kw):
        '''source: http://www.daniweb.com/code/snippet368.html'''
        t1 = time.time()
        res = func(*arg,**kw)
        t2 = time.time()
        return (t2-t1),res,func.func_name
    return wrapper

@timing_val
def time_izip(alist,n):
    i=iter(alist)
    return [x for x in izip(*[i]*n)]

@timing_val
def time_indexing(alist,n):
    return [alist[i:i+n] for i in range(0, len(alist), n)]


func_list=[locals()[key] for key in locals().keys() 
           if callable(locals()[key]) and key.startswith('time')]
shuffle(func_list)  # Shuffle, just in case the order matters

alist=range(1000000)
times=[]
for f in func_list:
    times.append(f(alist,31))

times.sort(key=lambda x: x[0])
for (time,result,func_name) in times:
    print '%s took %0.3fms.' % (func_name, time*1000.)

yields

% test.py
time_indexing took 73.230ms.
time_izip took 122.057ms.

And here I use timeit:

%  python -m timeit -s '' 'alist=range(1000000);[alist[i:i+31] for i in range(0, len(alist), 31)]'
10 loops, best of 3: 64 msec per loop
% python -m timeit -s 'from itertools import izip' 'alist=range(1000000);i=iter(alist);[x for x in izip(*[i]*31)]'
10 loops, best of 3: 66.5 msec per loop

Using timeit the results are virtually the same, but using the timing decorator it appears time_indexing is faster than time_izip.

What accounts for this difference?

Should either method be believed?

If so, which?

Answer 1

Just a guess, but could the difference be the order of magnitude of difference in range() values?

From your original source:

alist=range(1000000)

From your timeit example:

alist=range(100000)

For what it's worth, here are the results on my system with the range set to 1 million:

$ python -V
Python 2.6.4rc2

$ python -m timeit -s 'from itertools import izip' 'alist=range(1000000);i=iter(alist);[x for x in izip(*[i]*31)]'
10 loops, best of 3: 69.6 msec per loop

$ python -m timeit -s '' 'alist=range(1000000);[alist[i:i+31] for i in range(0, len(alist), 31)]'
10 loops, best of 3: 67.6 msec per loop

I wasn't able to get your other code to run, since I could not import the "decorator" module on my system.

---

Update - I see the same discrepancy you do when I run your code without the decorator involved.

$ ./test.py
time_indexing took 84.846ms.
time_izip took 132.574ms.

Thanks for posting this question; I learned something today. =)

Answer 2

regardless of this particular exercise, I'd imagine that using timeit is much safer and reliable option. it is also cross-platform, unlike your solution.

Answer 3

Use timeit. Running the test more than once gives me much better results.

func_list=[locals()[key] for key in locals().keys() 
           if callable(locals()[key]) and key.startswith('time')]

alist=range(1000000)
times=[]
for f in func_list:
    n = 10
    times.append( min(  t for t,_,_ in (f(alist,31) for i in range(n)))) 

for (time,func_name) in zip(times, func_list):
    print '%s took %0.3fms.' % (func_name, time*1000.)

->

<function wrapper at 0x01FCB5F0> took 39.000ms.
<function wrapper at 0x01FCB670> took 41.000ms.

Answer 4

I got tired of from __main__ import foo, now use this -- for simple args, for which %r works, and not in Ipython.
(Why does timeit works only on strings, not thunks / closures i.e. timefunc( f, arbitrary args ) ?)

import timeit

def timef( funcname, *args, **kwargs ):
    """ timeit a func with args, e.g.
            for window in ( 3, 31, 63, 127, 255 ):
                timef( "filter", window, 0 )
    This doesn't work in ipython;
    see Martelli, "ipython plays weird tricks with __main__" in Stackoverflow        
    """
    argstr = ", ".join([ "%r" % a for a in args]) if args  else ""
    kwargstr = ", ".join([ "%s=%r" % (k,v) for k,v in kwargs.items()]) \
        if kwargs  else ""
    comma = ", " if (argstr and kwargstr)  else ""
    fargs = "%s(%s%s%s)" % (funcname, argstr, comma, kwargstr)
        # print "test timef:", fargs
    t = timeit.Timer( fargs, "from __main__ import %s" % funcname )
    ntime = 3
    print "%.0f usec %s" % (t.timeit( ntime ) * 1e6 / ntime, fargs)

#...............................................................................
if __name__ == "__main__":
    def f( *args, **kwargs ):
        pass

    try:
        from __main__ import f
    except:
        print "ipython plays weird tricks with __main__, timef won't work"
    timef( "f")
    timef( "f", 1 )
    timef( "f", """ a b """ )
    timef( "f", 1, 2 )
    timef( "f", x=3 )
    timef( "f", x=3 )
    timef( "f", 1, 2, x=3, y=4 )

Added: see also "ipython plays weird tricks with main", Martelli in running-doctests-through-ipython