Timing Iteration Alternatives

Luckily, Python makes it easy to time code. For example, to get the total time taken to run multiple calls to a function with arbitrary positional arguments, the following first-cut function might suffice:

# File timer0.py
import time
def timer(func, *args):                 # Simplistic timing function
    start = time.clock()
    for i in range(1000):
        func(*args)
    return time.clock() - start         # Total elapsed time in seconds

This works—it fetches time values from Python’s time module, and subtracts the system start time from the stop time after running 1,000 calls to the passed-in function with the passed-in arguments. On my computer in Python 3.3:

>>> from timer0 import timer
>>> timer(pow, 2, 1000)                 # Time to call pow(2, 1000) 1000 times
0.00296260674205626
>>> timer(str.upper, 'spam')            # Time to call 'spam'.upper() 1000 times
0.0005165746166859719

Though simple, this timer is also fairly limited, and deliberately exhibits some classic mistakes in both function design and benchmarking. Among these, it:

In other words, timing code is more complex than you might expect! To be more general and accurate, let’s expand this into still simple but more useful timer utility functions we can use both to see how iteration alternative options stack up now, and apply to other timing needs in the future. These functions are coded in a module file so they can be used in a variety of programs, and have docstrings giving some basic details that PyDoc can display on request—see Figure 15-2 in Chapter 15 for a screenshot of the documentation pages rendered for the timing modules we’re coding here:

# File timer.py
"""
Homegrown timing tools for function calls.
Does total time, best-of time, and best-of-totals time
"""

import time, sys
timer = time.clock if sys.platform[:3] == 'win' else time.time

def total(reps, func, *pargs, **kargs):
    """
    Total time to run func() reps times.
    Returns (total time, last result)
    """
    repslist = list(range(reps))                 # Hoist out, equalize 2.x, 3.x
    start = timer()                              # Or perf_counter/other in 3.3+
    for i in repslist:
        ret = func(*pargs, **kargs)
    elapsed = timer() - start
    return (elapsed, ret)

def bestof(reps, func, *pargs, **kargs):
    """
    Quickest func() among reps runs.
    Returns (best time, last result)
    """
    best = 2 ** 32                               # 136 years seems large enough
    for i in range(reps):                        # range usage not timed here
        start = timer()
        ret = func(*pargs, **kargs)
        elapsed = timer() - start                # Or call total() with reps=1
        if elapsed < best: best = elapsed        # Or add to list and take min()
    return (best, ret)

def bestoftotal(reps1, reps2, func, *pargs, **kargs):
    """
    Best of totals:
    (best of reps1 runs of (total of reps2 runs of func))
    """
    return bestof(reps1, total, reps2, func, *pargs, **kargs)

Operationally, this module implements both total time and best time calls, and a nested best of totals that combines the other two. In each, it times a call to any function with any positional and keyword arguments passed individually, by fetching the start time, calling the function, and subtracting the start time from the stop time. Points to notice about how this version addresses the shortcomings of its predecessor:

From a larger perspective, because these functions are coded in a module file, they become generally useful tools anywhere we wish to import them. Modules and imports were introduced in Chapter 3, and you’ll learn more about them in the next part of this book; for now, simply import the module and call the function to use one of this file’s timers. In simple usage, this module is similar to its predecessor, but will be more robust in larger contexts. In Python 3.3 again:

>>> import timer
>>> timer.total(1000, pow, 2, 1000)[0]          # Compare to timer0 results above
0.0029542985410557776
>>> timer.total(1000, str.upper, 'spam')        # Returns (time, last call's result)
(0.000504845391709686, 'SPAM')

>>> timer.bestof(1000, str.upper, 'spam')       # 1/1000 as long as total time
(4.887177027512735e-07, 'SPAM')
>>> timer.bestof(1000, pow, 2, 1000000)[0]
0.00393515497972885

>>> timer.bestof(50, timer.total, 1000, str.upper, 'spam')
(0.0005468751145372153, (0.0005004469323637295, 'SPAM'))
>>> timer.bestoftotal(50, 1000, str.upper, 'spam')
(0.000566912540591602, (0.0005195069228989269, 'SPAM'))

The last two calls here calculate the best-of-totals times—the lowest time among 50 runs, each of which computes the total time to call str.upper 1,000 times (roughly corresponding to the total times at the start of this listing). The function used in the last call is really just a convenience that maps to the call form preceding it; both return the best-of tuple, which embeds the last total call’s result tuple.

Compare these last two results to the following generator-based alternative:

>>> min(timer.total(1000, str.upper, 'spam') for i in range(50))
(0.0005155971812769167, 'SPAM')

Taking the min of an iteration of total results this way has a similar effect because the times in the result tuples dominate comparisons made by min (they are leftmost in the tuple). We could use this in our module too (and will in later variations); it varies slightly by omitting a very small overhead in the best-of function’s code and not nesting result tuples, though either result suffices for relative comparisons. As is, the best-of function must pick a high initial lowest time value—though 136 years is probably longer than most of the tests you’re likely to run!

>>> ((((2 ** 32) / 60) / 60) / 24) / 365           # Plus a few extra days
136.19251953323186
>>> ((((2 ** 32) // 60) // 60) // 24) // 365       # Floor: see Chapter 5
136

if sys.version_info[0] >= 3 and sys.version_info[1] >= 3:
    timer = time.perf_counter     # or process_time
else:
    timer = time.clock if sys.platform[:3] == 'win' else time.time

try:
    timer = time.perf_counter     # or process_time
except AttributeError:
    timer = time.clock if sys.platform[:3] == 'win' else time.time

Now, to time iteration tool speed (our original goal), run the following script—it uses the timer module we wrote to time the relative speeds of the list construction techniques we’ve studied:

# File timeseqs.py
"Test the relative speed of iteration tool alternatives."

import sys, timer                                # Import timer functions
reps = 10000
repslist = list(range(reps))                     # Hoist out, list in both 2.X/3.X

def forLoop():
    res = []
    for x in repslist:
        res.append(abs(x))
    return res

def listComp():
    return [abs(x) for x in repslist]

def mapCall():
    return list(map(abs, repslist))              # Use list() here in 3.X only!
  # return map(abs, repslist)

def genExpr():
    return list(abs(x) for x in repslist)        # list() required to force results

def genFunc():
    def gen():
        for x in repslist:
            yield abs(x)
    return list(gen())                           # list() required to force results

print(sys.version)
for test in (forLoop, listComp, mapCall, genExpr, genFunc):
    (bestof, (total, result)) = timer.bestoftotal(5, 1000, test)
    print ('%-9s: %.5f => [%s...%s]' %
           (test.__name__, bestof, result[0], result[-1]))

This script tests five alternative ways to build lists of results. As shown, its reported times reflect on the order of 10 million steps for each of the five test functions—each builds a list of 10,000 items 1,000 times. This process is repeated 5 times to get the best-of time for each of the 5 test functions, yielding a whopping 250 million total steps for the script at large (impressive but reasonable on most machines these days).

Notice how we have to run the results of the generator expression and function through the built-in list call to force them to yield all of their values; if we did not, in both 2.X and 3.X we would just produce generators that never do any real work. In Python 3.X only we must do the same for the map result, since it is now an iterable object as well; for 2.X, the list around map must be removed manually to avoid charging an extra list construction overhead per test (though its impact seems negligible in most tests).

In a similar way, the inner loops’ range result is hoisted out to the top of the module to remove its construction cost from total time, and wrapped in a list call so that its traversal cost isn’t skewed by being a generator in 3.X only (much as we did in the timer module too). This may be overshadowed by the cost of the inner iterations loop, but it’s best to remove as many variables as we can.

Also notice how the code at the bottom steps through a tuple of five function objects and prints the __name__ of each: as we’ve seen, this is a built-in attribute that gives a function’s name.^[42]

When the script of the prior section is run under Python 3.3, I get these results on my Windows 7 laptop—map is slightly faster than list comprehensions, both are quicker than for loops, and generator expressions and functions place in the middle (times here are total time in seconds):

C:\code> c:\python33\python timeseqs.py
3.3.0 (v3.3.0:bd8afb90ebf2, Sep 29 2012, 10:57:17) [MSC v.1600 64 bit (AMD64)]
forLoop  : 1.33290 => [0...9999]
listComp : 0.69658 => [0...9999]
mapCall  : 0.56483 => [0...9999]
genExpr  : 1.08457 => [0...9999]
genFunc  : 1.07623 => [0...9999]

If you study this code and its output long enough, you’ll notice that generator expressions run slower than list comprehensions today. Although wrapping a generator expression in a list call makes it functionally equivalent to a square-bracketed list comprehension, the internal implementations of the two expressions appear to differ (though we’re also effectively timing the list call for the generator test):

return [abs(x) for x in repslist]            # 0.69 seconds
return list(abs(x) for x in repslist)        # 1.08 seconds: differs internally

Though the exact cause would require deeper analysis (and possibly source code study), this seems to make sense given that the generator expression must do extra work to save and restore its state during value production; the list comprehension does not, and runs quicker by a small constant here and in later tests.

Interestingly, when I ran this on Windows Vista under Python 3.0 for the fourth edition of this book, and on Windows XP with Python 2.5 for the third, the results were relatively similar—list comprehensions were nearly twice as fast as equivalent for loop statements, and map was slightly quicker than list comprehensions when mapping a function such as the abs (absolute value) built-in this way. Python 2.5’s absolute times were roughly four to five times slower than the current 3.3 output, but this likely reflects quicker laptops much more than any improvements in Python.

In fact, most of the Python 2.7 results for this script are slightly quicker than 3.3 on this same machine today—I removed the list call from the map test in the following to avoid creating the results list twice in that test, though it adds only a very small constant time if left in:

c:\code> c:\python27\python timeseqs.py
2.7.3 (default, Apr 10 2012, 23:24:47) [MSC v.1500 64 bit (AMD64)]
forLoop  : 1.24902 => [0...9999]
listComp : 0.66970 => [0...9999]
mapCall  : 0.57018 => [0...9999]
genExpr  : 0.90339 => [0...9999]
genFunc  : 0.90542 => [0...9999]

For comparison, following are the same tests’ speed results under the current PyPy, the optimized Python implementation discussed in Chapter 2, whose current 1.9 release implements the Python 2.7 language. PyPy is roughly 10X (an order of magnitude) quicker here; it will do even better when we revisit Python version comparisons later in this chapter using tools with different code structures (though it will lose on a few other tests as well):

c:\code> c:\PyPy\pypy-1.9\pypy.exe timeseqs.py
2.7.2 (341e1e3821ff, Jun 07 2012, 15:43:00)
[PyPy 1.9.0 with MSC v.1500 32 bit]
forLoop  : 0.10106 => [0...9999]
listComp : 0.05629 => [0...9999]
mapCall  : 0.10022 => [0...9999]
genExpr  : 0.17234 => [0...9999]
genFunc  : 0.17519 => [0...9999]

On PyPy alone, list comprehensions beat map in this test, but the fact that all of PyPy’s results are so much quicker today seems the larger point here. On CPython, map is still quickest so far.

# File timeseqs2.py (differing parts)
...
def forLoop():
    res = []
    for x in repslist:
        res.append(x + 10)
    return res

def listComp():
    return [x + 10 for x in repslist]

def mapCall():
    return list(map((lambda x: x + 10), repslist))          # list() in 3.X only

def genExpr():
    return list(x + 10 for x in repslist)                   # list() in 2.X + 3.X

def genFunc():
    def gen():
        for x in repslist:
            yield x + 10
    return list(gen())                                      # list in 2.X + 3.X
...

c:\code> c:\python33\python timeseqs2.py
3.3.0 (v3.3.0:bd8afb90ebf2, Sep 29 2012, 10:57:17) [MSC v.1600 64 bit (AMD64)]
forLoop  : 1.35136 => [10...10009]
listComp : 0.73730 => [10...10009]
mapCall  : 1.68588 => [10...10009]
genExpr  : 1.10963 => [10...10009]
genFunc  : 1.11074 => [10...10009]

def F(x): return x
def listComp():
    return [F(x) for x in repslist]
def mapCall():
    return list(map(F, repslist))

The timing module of the preceding section works, but it could be a bit more user-friendly. Most obviously, its functions require passing in a repetitions count as a first argument, and provide no default for it—a minor point, perhaps, but less than ideal in a general-purpose tool. We could also leverage the min technique we saw earlier to simplify the return value slightly and remove a minor overhead charge.

The following implements an alternative timer module that addresses these points, allowing the repeat count to be passed in as a keyword argument named _reps:

# File timer2.py (2.X and 3.X)
"""
total(spam, 1, 2, a=3, b=4, _reps=1000) calls and times spam(1, 2, a=3, b=4)
_reps times, and returns total time for all runs, with final result.

bestof(spam, 1, 2, a=3, b=4, _reps=5) runs best-of-N timer to attempt to
filter out system load variation, and returns best time among _reps tests.

bestoftotal(spam 1, 2, a=3, b=4, _rep1=5, reps=1000) runs best-of-totals
test, which takes the best among _reps1 runs of (the total of _reps runs);
"""

import time, sys
timer = time.clock if sys.platform[:3] == 'win' else time.time

def total(func, *pargs, **kargs):
    _reps = kargs.pop('_reps', 1000)    # Passed-in or default reps
    repslist = list(range(_reps))       # Hoist range out for 2.X lists
    start = timer()
    for i in repslist:
        ret = func(*pargs, **kargs)
    elapsed = timer() - start
    return (elapsed, ret)

def bestof(func, *pargs, **kargs):
    _reps = kargs.pop('_reps', 5)
    best = 2 ** 32
    for i in range(_reps):
        start = timer()
        ret = func(*pargs, **kargs)
        elapsed = timer() - start
        if elapsed < best: best = elapsed
    return (best, ret)

def bestoftotal(func, *pargs, **kargs):
    _reps1 = kargs.pop('_reps1', 5)
    return min(total(func, *pargs, **kargs) for i in range(_reps1))

This module’s docstring at the top of the file describes its intended usage. It uses dictionary pop operations to remove the _reps argument from arguments intended for the test function and provide it with a default (it has an unusual name to avoid clashing with real keyword arguments meant for the function being timed).

Notice how the best of totals here uses the min and generator scheme we saw earlier instead of nested calls, in part because this simplifies results and avoids a minor time overhead in the prior version (whose code fetches best of time after total time has been computed), but also because it must support two distinct repetition keywords with defaults—total and bestof can’t both use the same argument name. Add argument prints in the code if it would help to trace its operation.

To test with this new timer module, you can change the timing scripts as follows, or use the precoded version in the book’s examples file timeseqs_timer2.py; the results are essentially the same as before (this is primarily just an API change), so I won’t list them again here:

import sys, timer2
...
for test in (forLoop, listComp, mapCall, genExpr, genFunc):
    (total, result) = timer2.bestoftotal(test, _reps1=5, _reps=1000)

# Or:
#   (total, result) = timer2.bestoftotal(test)
#   (total, result) = timer2.bestof(test, _reps=5)
#   (total, result) = timer2.total(test, _reps=1000)
#   (bestof, (total, result)) = timer2.bestof(timer2.total, test, _reps=5)

    print ('%-9s: %.5f => [%s...%s]' %
           (test.__name__, total, result[0], result[-1]))

You can also run a few interactive tests as we did for the original version—the results are again essentially the same as before, but we pass in the repetition counts as keywords that provide defaults if omitted; in Python 3.3:

>>> from timer2 import total, bestof, bestoftotal
>>> total(pow, 2, 1000)[0]                                 # 2 ** 1000, 1K dflt reps
0.0029562534118596773
>>> total(pow, 2, 1000, _reps=1000)[0]                     # 2 ** 1000, 1K reps
0.0029733585316193967
>>> total(pow, 2, 1000, _reps=1000000)[0]                  # 2 ** 1000, 1M reps
1.2451676814889865

>>> bestof(pow, 2, 100000)[0]                              # 2 ** 100K, 5 dflt reps
0.0007550688578703557
>>> bestof(pow, 2, 1000000, _reps=30)[0]                   # 2 ** 1M, best of 30
0.004040229286800923

>>> bestoftotal(str.upper, 'spam', _reps1=30, _reps=1000)  # Best of 30, tot of 1K
(0.0004945823198454491, 'SPAM')
>>> bestof(total, str.upper, 'spam', _reps=30)             # Nested calls work too
(0.0005463863968202531, (0.0004994694969298052, 'SPAM'))

To see how keywords are supported now, define a function with more arguments and pass some by name:

>>> def spam(a, b, c, d): return a + b + c + d

>>> total(spam, 1, 2, c=3, d=4, _reps=1000)
(0.0009730369554290519, 10)
>>> bestof(spam, 1, 2, c=3, d=4, _reps=1000)
(9.774353202374186e-07, 10)
>>> bestoftotal(spam, 1, 2, c=3, d=4, _reps1=1000, _reps=1000)
(0.00037289161070930277, 10)
>>> bestoftotal(spam, *(1, 2), _reps1=1000, _reps=1000, **dict(c=3, d=4))
(0.00037289161070930277, 10)

# File timer3.py (3.X only)
"""
Same usage as timer2.py, but uses 3.X keyword-only default arguments
instead of dict pops for simpler code.  No need to hoist range() out
of tests in 3.X: always a generator in 3.X, and this can't run on 2.X.
"""
import time, sys
timer = time.clock if sys.platform[:3] == 'win' else time.time

def total(func, *pargs, _reps=1000, **kargs):
    start = timer()
    for i in range(_reps):
        ret = func(*pargs, **kargs)
    elapsed = timer() - start
    return (elapsed, ret)

def bestof(func, *pargs, _reps=5, **kargs):
    best = 2 ** 32
    for i in range(_reps):
        start = timer()
        ret = func(*pargs, **kargs)
        elapsed = timer() - start
        if elapsed < best: best = elapsed
    return (best, ret)

def bestoftotal(func, *pargs, _reps1=5, **kargs):
    return min(total(func, *pargs, **kargs) for i in range(_reps1))

 (elapsed, ret) = total(func, *pargs, _reps=1, **kargs)

For more insight, try modifying the repetition counts used by these modules, or explore the alternative timeit module in Python’s standard library, which automates timing of code, supports command-line usage modes, and finesses some platform-specific issues—in fact, we’ll put it to work in the next section.

You might also want to look at the profile standard library module for a complete source code profiler tool. We’ll learn more about it in Chapter 36 in the context of development tools for large projects. In general, you should profile code to isolate bottlenecks before recoding and timing alternatives as we’ve done here.

You might try modifying or emulating the timing script to measure the speed of the 3.X and 2.7 set and dictionary comprehensions shown in the preceding chapter, and their for loop equivalents. Using them is less common in Python programs than building lists of results, so we’ll leave this task in the suggested exercise column (please, no wagering...); the next section will partly spoil the surprise.

Finally, keep the timing module we wrote here filed away for future reference—we’ll repurpose it to measure performance of alternative numeric square root operations in an exercise at the end of this chapter. If you’re interested in pursuing this topic further, we’ll also experiment with techniques for timing dictionary comprehensions versus for loops interactively in the exercises.