Profiling weirdness: Timer.timeit(), fibonacci and memoization

[ssecorp]

I am not clear about the results here.
from timeit import Timer
import Decorators

def fib(n):
a, b = 1, 0
while n:
a, b, n = b, a+b, n-1
return b

@Decorators.memoize
def fibmem(nbr):
if nbr 1:
return fibmem(nbr-1) + fibmem(nbr-2)
if nbr == 1:
return 1
if nbr == 0:
return 0

s = 100

t1 = Timer('fib(s)', 'from __main__ import fib, s')
t2 = Timer('fibmem(s)', 'from __main__ import fibmem, s')
t1.repeat(number=1)
t2.repeat(number=1)
print t1.timeit()
print t2.timeit()

>>>

35.3092010297
1.6516613145

>>>

So memoization is 20+ times faster than the idiomatic way?
Or am I missing something here?
Ok for fun I added memoization to the idiomatic one:

from timeit import Timer
import Decorators

@Decorators.memoize
def fib(n):
a, b = 1, 0
while n:
a, b, n = b, a+b, n-1
return b

@Decorators.memoize
def fibmem(nbr):
if nbr 1:
return fibmem(nbr-1) + fibmem(nbr-2)
if nbr == 1:
return 1
if nbr == 0:
return 0

s = 100

t1 = Timer('fib(s)', 'from __main__ import fib, s')
t2 = Timer('fibmem(s)', 'from __main__ import fibmem, s')
t1.repeat(number=1)
t2.repeat(number=1)
print t1.timeit()
print t2.timeit()
didn't think it would make a difference there but it certainly did.

>>>

1.59592657726
1.60179436213

>>================================ RESTART ================================

2.66468922726
3.0870236301

>>================================ RESTART ================================

1.62921684181
1.51585159566

>>================================ RESTART ================================

1.49457319296
1.60948472501

>>================================ RESTART ================================

1.48718203012
1.6645559701

>>>

[Stefaan Himpe]

Nothing weird about this ...
The difference will become larger as your input value becomes larger.

You can easily understand why if you try to calculate fib(10) by hand,
i.e. work through the algorithm with pencil and paper,
then compare the work you have to do to the memoized version which just
takes fib(9) and fib(8) from memory and adds them together.

Best regards,
Stefaan.

[Rob Williscroft]

Stefaan Himpe wrote in news:2m********************@newsfe16.ams2 in
comp.lang.python:

Nothing weird about this ...
The difference will become larger as your input value becomes larger.

You can easily understand why if you try to calculate fib(10) by hand,
i.e. work through the algorithm with pencil and paper,
then compare the work you have to do to the memoized version which just
takes fib(9) and fib(8) from memory and adds them together.

I think you missed the point.

The problem is that the un-decorated, loop only version takes
35 seconds when called by timeit.Timer. However if you apply
the decorator it takes less that a second. In *both* cases
the function (fib) only gets called once.

Note, I timed the call fib(100) with time.clock() and got a
value of less than 1 ms, the memozed version takes about 10
times longer.

So the question is: whats going on with timeit.Timer ?

Rob.
--
http://www.victim-prime.dsl.pipex.com/

[Steven D'Aprano]

On Sat, 02 Aug 2008 06:02:02 -0700, ssecorp wrote:

I am not clear about the results here.
from timeit import Timer
import Decorators

def fib(n):
a, b = 1, 0
while n:
a, b, n = b, a+b, n-1
return b

[...]

s = 100

t1 = Timer('fib(s)', 'from __main__ import fib, s')
t2 = Timer('fibmem(s)', 'from __main__ import fibmem, s')
t1.repeat(number=1)
t2.repeat(number=1)
print t1.timeit()
print t2.timeit()
35.3092010297
1.6516613145

So memoization is 20+ times faster than the idiomatic way? Or am I
missing something here?

Memoization *can be* faster, not *is* -- memoization requires work, and
if it is more work to look something up than to calculate it, then it
will be a pessimation instead of an optimization. That's probably less of
an issue with high-level languages like Python, but in low level
languages you would need to start thinking about processor caches and all
sorts of complications.

But I digress... in Python, yes, I would expect a significant speedup
with memoization. That's why people use it.

Ok for fun I added memoization to the idiomatic one:

[...]

didn't think it would make a difference there but it certainly did.

1.59592657726
1.60179436213

Just curious, but why don't you show the results of the call to repeat()?
It makes me uncomfortable to see somebody showing only half their output.

But yes, with memoization, the lookup to find the Fibonacci number should
decrease the time it takes to calculate the Fibonacci number. I'm not
sure why you are surprised. Regardless of which Fibonacci algorithm you
are using, the Timer object is essentially timing one million lookups,
minus 100 calculations of the Fibonacci number. The 999,900 cache lookups
will dominate the time, far outweighing the 100 calculations, regardless
of which method of calculation you choose. That's why the results are
almost identical.

--
Steven

[Steven D'Aprano]

On Sat, 02 Aug 2008 16:14:11 -0500, Rob Williscroft wrote:

Stefaan Himpe wrote in news:2m********************@newsfe16.ams2 in
comp.lang.python:

>Nothing weird about this ...
The difference will become larger as your input value becomes larger.

You can easily understand why if you try to calculate fib(10) by hand,
i.e. work through the algorithm with pencil and paper, then compare the
work you have to do to the memoized version which just takes fib(9) and
fib(8) from memory and adds them together.

I think you missed the point.

The problem is that the un-decorated, loop only version takes 35 seconds
when called by timeit.Timer. However if you apply the decorator it
takes less that a second. In *both* cases the function (fib) only gets
called once.

I think you are completely misreading the results of the Timeit calls.
That's not correct: you're calling it one million times, not once.

You should apply a "sanity check" to results. At the interactive console,
call the undecorated fib(100) once. Does it take 35 seconds? If so, your
computer is terribly slow -- on mine, it returns instantly.

Note that in your email, you showed only half the output:
[quote]
t1 = Timer('fib(s)', 'from __main__ import fib, s')
t2 = Timer('fibmem(s)', 'from __main__ import fibmem, s')
t1.repeat(number=1)
t2.repeat(number=1)
print t1.timeit()
print t2.timeit()

>>>

35.3092010297
1.6516613145
[end quote]

You had two calls to Timer.repeat() methods, and you didn't show the
output. *They* call the Fibonacci functions once. When I do that, I get
output looking like this:

>>t1 = Timer('fib(s)', 'from __main__ import fib, s')
t1.repeat(number=1)

[7.9870223999023438e-05, 5.5074691772460938e-05, 5.4121017456054688e-05]

You then call the Timer.timeit() method, which calls the function one
million times by default. That's the output you show: notice that 35s
divided by one million is 3.5e-05s, around what I get using the repeat()
method. There's no mystery.

Note, I timed the call fib(100) with time.clock() and got a value of
less than 1 ms, the memozed version takes about 10 times longer.

You shouldn't give much credence to timing results from calling a
function once (unless the function does a *lot* of work). Your operating
system is doing all sorts of work in the background. It can easily
interrupt your process mid-calculation to do something else, and your
timing code will then include that. You'll then wrongly conclude that the
function is slower than it really is.

Also, keep in mind that time.clock() is likely to be significantly less
accurate if you are using Linux. The timeit module automatically choose
the best function to use (time.clock vs time.time) for you.

So the question is: whats going on with timeit.Timer ?

As far as I can see, nothing. I think you have misunderstood the results
you got.

--
Steven

[ssecorp]

I think you are confusing 2 people in this thread but that doesn't
really matter.
What surprised me was that I didn't think fib would benefit from
memoization because it didn't repeat the same calculations. fibmem
without memoization is the classic naive implementation that grows
exponentially and obv that would benefit from memoization.
from timeit import Timer
import Decorators

@Decorators.memoize
def fib(n):
a, b = 1, 0
while n:
a, b, n = b, a+b, n-1
return b

@Decorators.memoize
def fibmem(nbr):
if nbr 1:
return fibmem(nbr-1) + fibmem(nbr-2)
if nbr == 1:
return 1
if nbr == 0:
return 0

s = 100
t1 = Timer('fib(s)', 'from __main__ import fib, s')
t2 = Timer('fibmem(s)', 'from __main__ import fibmem, s')
print t1.repeat(number=1)
print t2.repeat(number=1)
print t1.timeit()
print t2.timeit()

>>>

[4.8888895097002557e-005, 3.6317464929201785e-006,
3.0730162632401604e-006]
[0.0014432001832635141, 5.5873022968000452e-006,
3.0730162632417596e-006]
1.4421612244
1.34121264015

>>>

[Rob Williscroft]

Steven D'Aprano wrote in news:00**********************@news.astraweb.com in
comp.lang.python:

>So the question is: whats going on with timeit.Timer ?

As far as I can see, nothing. I think you have misunderstood the results
you got.

No, the answer is that is it repeats a million times. It might better be
called repeat_one_million_times().

Or put another way, myself and the OP misinterpreted what the call
t1.repeat( number = 1 ) did.

its a confusing API.

For the OP:

The call t1.timeit() is equivalent to t1.repeat( number = 1000000 ).

So it bennefits from memoization because the call *is* repeated, not
just called once like you intended.

Rob.
--
http://www.victim-prime.dsl.pipex.com/

[Steven D'Aprano]

On Sun, 03 Aug 2008 09:46:45 -0500, Rob Williscroft wrote:

Steven D'Aprano wrote in news:00**********************@news.astraweb.com
in comp.lang.python:

>>So the question is: whats going on with timeit.Timer ?

As far as I can see, nothing. I think you have misunderstood the
results you got.

No, the answer is that is it repeats a million times. It might better
be called repeat_one_million_times().

But that would be seriously broken if you call it like this:

Timer.repeat_one_million_times(5, 1000)

It doesn't repeat one million times. It repeats five times, of 1000 loops
each.

Or put another way, myself and the OP misinterpreted what the call
t1.repeat( number = 1 ) did.

its a confusing API.

There's certainly confusion happening. Perhaps reading the doc strings
might clear up some confusion? help(Timer.repeat) and help(Timer.timeit)
state very clearly that they default to one million iterations.

For the OP:

The call t1.timeit() is equivalent to t1.repeat( number = 1000000 ).

No it isn't. Try running the code and looking at the results it gives.

t1.repeat(number=10**6) returns a list of three numbers. The function is
called *three* million times in total.

t1.timeit() returns a single number.

In fact, t1.timeit() is equivalent to
t1.repeat(repeat=1, number=1000000), (apart from it being in a list).
That can be written more simply as: t1.repeat(1)
--
Steven