Confusion while counting elapsed time in python?

Question

So I wanted to compare the performance of python between 2.6 and 3.1, so I wrote this simple program test.py that will perform some basic lengthy operation:

from time import time
start = time()
q = 2 ** 1000000000
q += 3 << 1000000000
print(q.__sizeof__(), time() - start)

I didn't get what I expected, since after launching the commands time python2.6 test.py and time python3.1 test.py respectively, the output was the following:

(133333364, 0.37349200248718262)

real    0m35.586s
user    0m28.130s
sys 0m2.110s

and,

133333360 0.312520027161

real    0m26.413s
user    0m17.330s
sys 0m2.190s

I assumed that the results for both versions would be close when comparing the output of the time command and that done inside the program. What is the explanation for this?

Answer 1

There may be many explanations, such as a different set of directories (and zipfiles) on sys.path, automatically loaded/executed code at initialization, other processes running on the platform -- your code is not at all isolated nor repeatable, therefore its results are of very little value. Use python -mtimeit to measure things much, much better.

Edit: some numbers...:

$ py26 -mtimeit 'q=2**1000000000; q+=3<<1000000000'
10 loops, best of 3: 466 msec per loop
$ py31 -mtimeit 'q=2**1000000000; q+=3<<1000000000'
10 loops, best of 3: 444 msec per loop

these accurately measure the += time (slightly better / more optimized in 3.1, repeatably). If you want to measure the shifting or raising to power times, then you can't use literals, of course (since literal expressions get computed at compile time, not at run time: part of why you want all your significant code to be in functions in modules, not in top-level code nor in your main script... so the compiler can do as much of the work as easily feasible, despite its lack of any serious optimizations;-). E.g.:

$ py31 -mtimeit -s't=2' 'q=t**1000000'
10 loops, best of 3: 19.4 msec per loop
$ py31 -mtimeit -s't=3' 'q=t<<1000000'
10000 loops, best of 3: 150 usec per loop

(just takes too long to do them with the larger RHS operand you're using and I'm getting impatient;-). Mixing the ops would of course be a sad disaster in terms of measuring, since the relatively fast ones would essentially disappear in the mix!-) Fortunately, there is no good reason for such mixing -- timeit, after all, is for micro benchmarking!-)

Answer 2

Heh, iteresting problem, took me a while to figure it out:

from time import time
start = time()
q = 2 ** 1000000000 # number literal
q += 3 << 1000000000 # still a literal
print(q.__sizeof__(), time() - start)

Python's compiler (!) computes q. When the script runs, the interpreter takes the time, loads the already computed value and takes the time again. Now unsurprisingly, the two times are pretty much the same.

time on the other hand measures how long the full run (compile+run) takes.