Method much slower than function?

[Matimus]

Re: Method much slower than function?

The first time you read the file, it has to read it from disk.

The second time, it's probably just reading from the buffer
cache in RAM.

I can verify this type of behavior when reading large files. Opening
the file doesn't take long, but the first read will take a while
(multiple seconds depending on the size of the file). When the file is
opened a second time, the initial read takes significantly less time.

Matt

[Diez B. Roggisch]

Re: Method much slower than function?

Grant Edwards schrieb:

On 2007-06-14, Leo Kislov <Leo.Kislov@gma il.comwrote:

>On Jun 13, 5:40 pm, ido...@gmail.co m wrote:

>>Hi all,
>>>
>>I am running Python 2.5 on Feisty Ubuntu. I came across some code that
>>is substantially slower when in a method than in a function.
>>>
>>>>>cProfile.r un("bar.readgen ome(open('cb_fo o'))")
>> 20004 function calls in 10.214 CPU seconds
>>>>>cProfile.r un("z=r.readgen ome(open('cb_fo o'))")
>> 20004 function calls in 0.041 CPU seconds
>>>

>I suspect open files are cached

>
They shouldn't be.
>

>so the second reader picks up where the first one left: at the
>of the file.

>
That sounds like a bug. Opening a file a second time should
produce a "new" file object with the file-pointer at the
beginning of the file.

It's a OS thing.

Diez

[Peter Otten]

Re: Method much slower than function?

Peter Otten wrote:

Leo Kislov wrote:
>

>On Jun 13, 5:40 pm, ido...@gmail.co m wrote:

>>Hi all,
>>>
>>I am running Python 2.5 on Feisty Ubuntu. I came across some code that
>>is substantially slower when in a method than in a function.
>>>
>>>cProfile.run ("bar.readgenom e(open('cb_foo' ))")
>>>
>> 20004 function calls in 10.214 CPU seconds

>>

>>>cProfile.run ("z=r.readgenom e(open('cb_foo' ))")
>>>
>> 20004 function calls in 0.041 CPU seconds
>>>

>>
>I suspect open files are cached so the second reader
>picks up where the first one left: at the of the file.
>The second call doesn't do any text processing at all.
>>
> -- Leo

>
Indeed, the effect of attribute access is much smaller than what the OP is
seeing:

I have to take that back

$ cat iadd.py
class A(object):
def add_attr(self):
self.x = 0
for i in xrange(100000):
self.x += 1
def add_local(self) :
x = 0
for i in xrange(100000):
x += 1
>
add_local = A().add_local
add_attr = A().add_attr
$ python2.5 -m timeit -s 'from iadd import add_local' 'add_local()'
10 loops, best of 3: 21.6 msec per loop
$ python2.5 -m timeit -s 'from iadd import add_attr' 'add_attr()'
10 loops, best of 3: 52.2 msec per loop

Iddo, adding integers is not a good model for the effect you are seeing.
Caching, while happening on the OS-level isn't, either.

As already mentioned in this thread there is a special optimization for

some_string += another_string

in the Python C-source. This optimization works by mutating on the C-level
the string that is immutable on the Python-level, and is limited to cases
where there are no other names referencing some_string. The statement

self.s += t

is executed internally as

tmp = self.s [1]
tmp += t [2]
self.s = tmp [3]

where tmp is not visible from the Python level. Unfortunately after [1]
there are two references to the string in question (tmp and self.s) so the
optimization cannot kick in.

Peter

[Chris Mellon]

Re: Method much slower than function?

On 6/14/07, Peter Otten <__peter__@web. dewrote:

Peter Otten wrote:
>

Leo Kislov wrote:

On Jun 13, 5:40 pm, ido...@gmail.co m wrote:
>Hi all,
>>
>I am running Python 2.5 on Feisty Ubuntu. I came across some code that
>is substantially slower when in a method than in a function.
>>
>>cProfile.run( "bar.readgenome (open('cb_foo') )")
>>
> 20004 function calls in 10.214 CPU seconds
>
>>cProfile.run( "z=r.readgenome (open('cb_foo') )")
>>
> 20004 function calls in 0.041 CPU seconds
>>
>
I suspect open files are cached so the second reader
picks up where the first one left: at the of the file.
The second call doesn't do any text processing at all.
>
-- Leo

Indeed, the effect of attribute access is much smaller than what the OP is
seeing:

>
I have to take that back
>

Your tests (which I have snipped) show attribute access being about 3x
slower than local access, which is consistent with my own tests. The
OP is seeing a speed difference of 2 orders of magnitude. That's far
outside the range that attribute access should account for.

[Steven D'Aprano]

Re: Method much slower than function?

On Thu, 14 Jun 2007 00:40:12 +0000, idoerg wrote:

>>>cProfile.run ("bar.readgenom e(open('cb_foo' ))")

20004 function calls in 10.214 CPU seconds

This calls the method on the CLASS, instead of an instance. When I try it,
I get this:

TypeError: unbound method readgenome() must be called with bar instance as
first argument (got file instance instead)

So you're running something subtly different than what you think you're
running. Maybe you assigned bar = bar() at some point?

However, having said that, the speed difference does seem to be real: even
when I correct the above issue, I get a large time difference using
either cProfile.run() or profile.run(), and timeit agrees:

>>f = bar().readgenom e
>>timeit.Timer( "f(open('cb_foo '))", "from __main__ import f").timeit(5 )

18.515995025634 766

>>timeit.Timer( "readgenome(ope n('cb_foo'))", "from __main__ import readgenome").ti meit(5)

0.1940619945526 123

That's a difference of two orders of magnitude, and I can't see why.


--
Steven.

[Grant Edwards]

Re: Method much slower than function?

On 2007-06-14, Steven D'Aprano <steve@REMOVE.T HIS.cybersource .com.auwrote:

However, having said that, the speed difference does seem to be real: even
when I correct the above issue, I get a large time difference using
either cProfile.run() or profile.run(), and timeit agrees:
>

>>>f = bar().readgenom e
>>>timeit.Timer ("f(open('cb_fo o'))", "from __main__ import f").timeit(5 )

18.515995025634 766

>>>timeit.Timer ("readgenome(op en('cb_foo'))", "from __main__ import readgenome").ti meit(5)

0.1940619945526 123
>
That's a difference of two orders of magnitude, and I can't see why.

Is it independent of the test order?

What happens when you reverse the order?

What happens if you run the same test twice in a row?

--
Grant Edwards grante Yow! Thank god!! ... It's
at HENNY YOUNGMAN!!
visi.com

[Steven D'Aprano]

Re: Method much slower than function?

On Thu, 14 Jun 2007 00:40:12 +0000, idoerg wrote:

Hi all,
>
I am running Python 2.5 on Feisty Ubuntu. I came across some code that
is substantially slower when in a method than in a function.

After further testing, I think I have found the cause of the speed
difference -- and it isn't that the code is a method.

Here's my test code:


def readgenome(file handle):
s = ""
for line in filehandle.xrea dlines():
s += line.strip()

class SlowClass:
def readgenome(self , filehandle):
self.s = ""
for line in filehandle.xrea dlines():
self.s += line.strip()

class FastClass:
def readgenome(self , filehandle):
s = ""
for line in filehandle.xrea dlines():
s += line.strip()
self.s = s


Now I test them. For brevity, I am leaving out the verbose profiling
output, and just showing the total function calls and CPU time.

>>import cProfile
>>cProfile.run( "readgenome(ope n('cb_foo'))")

20005 function calls in 0.071 CPU seconds

>>cProfile.run( "SlowClass().re adgenome(open(' cb_foo'))")

20005 function calls in 4.030 CPU seconds

>>cProfile.run( "FastClass().re adgenome(open(' cb_foo'))")

20005 function calls in 0.077 CPU seconds


So you can see that the slow-down for calling a method (compared to a
function) is very small.

I think what we're seeing in the SlowClass case is the "normal" speed of
repeated string concatenations. That's REALLY slow. In the function and
FastClass cases, the compiler optimization is able to optimize that slow
behaviour away.

So, nothing to do with methods vs. functions, and everything to do with
the O(N**2) behaviour of repeated string concatenation.


--
Steven.

[Peter Otten]

Re: Method much slower than function?

Chris Mellon wrote:

On 6/14/07, Peter Otten <__peter__@web. dewrote:

>Peter Otten wrote:
>>

Leo Kislov wrote:
>
>On Jun 13, 5:40 pm, ido...@gmail.co m wrote:
>>Hi all,
>>>
>>I am running Python 2.5 on Feisty Ubuntu. I came across some code
>>that is substantially slower when in a method than in a function.
>>>
>>>cProfile.run ("bar.readgenom e(open('cb_foo' ))")
>>>
>> 20004 function calls in 10.214 CPU seconds
>>
>>>cProfile.run ("z=r.readgenom e(open('cb_foo' ))")
>>>
>> 20004 function calls in 0.041 CPU seconds
>>>
>>
>I suspect open files are cached so the second reader
>picks up where the first one left: at the of the file.
>The second call doesn't do any text processing at all.
>>
> -- Leo
>
Indeed, the effect of attribute access is much smaller than what the OP
is seeing:

>>
>I have to take that back
>>

>
Your tests (which I have snipped) show attribute access being about 3x
slower than local access, which is consistent with my own tests. The
OP is seeing a speed difference of 2 orders of magnitude. That's far
outside the range that attribute access should account for.

Not if it conspires to defeat an optimization for string concatenation

$ cat iadd.py
class A(object):
def add_attr(self):
self.x = ""
for i in xrange(10000):
self.x += " yadda"
def add_local(self) :
x = ""
for i in xrange(10000):
x += " yadda"

add_local = A().add_local
add_attr = A().add_attr
$ python2.5 -m timeit -s'from iadd import add_local' 'add_local()'
100 loops, best of 3: 3.15 msec per loop
$ python2.5 -m timeit -s'from iadd import add_attr' 'add_attr()'
10 loops, best of 3: 83.3 msec per loop

As the length of self.x grows performance will continue to degrade.
The original test is worthless as I tried to explain in the section you
snipped.

Peter

[sjdevnull@yahoo.com]

Re: Method much slower than function?

On Jun 14, 1:12 am, "Gabriel Genellina" <gagsl-...@yahoo.com.a r>
wrote:

En Thu, 14 Jun 2007 01:39:29 -0300, sjdevn...@yahoo .com
<sjdevn...@yaho o.comescribió:
>
>
>

Gabriel Genellina wrote:

In addition, += is rather inefficient for strings; the usual idiom is
using ''.join(items)

>

Ehh. Python 2.5 (and probably some earlier versions) optimize += on
strings pretty well.

>

a=""
for i in xrange(100000):
a+="a"

>

and:

>

a=[]
for i in xrange(100000):
a.append("a")
a="".join(a)

>

take virtually the same amount of time on my machine (2.5), and the
non-join version is clearer, IMO. I'd still use join in case I wind
up running under an older Python, but it's probably not a big issue
here.

>
Yes, for concatenating a lot of a's, sure... Try again using strings
around the size of your expected lines - and make sure they are all
different too.
>
pyimport timeit
py>
pydef f1():
... a=""
... for i in xrange(100000):
... a+=str(i)*20
...
pydef f2():
... a=[]
... for i in xrange(100000):
... a.append(str(i) *20)
... a="".join(a)
...
pyprint timeit.Timer("f 2()", "from __main__ import f2").repeat(num ber=1)
[0.4267366383157 6358, 0.4280759146763 0662, 0.4440148119383 8876]
pyprint timeit.Timer("f 1()", "from __main__ import f1").repeat(num ber=1)
>
...after a few minutes I aborted the process...

Are you using an old version of python? I get a fairly small
difference between the 2:

Python 2.5 (r25:51908, Jan 23 2007, 18:42:39)
[GCC 3.3.3 20040412 (Red Hat Linux 3.3.3-7)] on ELIDED
Type "help", "copyright" , "credits" or "license" for more information.

>>import timeit
>>a=""
>>def f1():

.... a=""
.... for i in xrange(100000):
.... a+=str(i)*20
....

>>def f2():

.... a=[]
.... for i in xrange(100000):
.... a.append(str(i) *20)
.... a="".join(a)
....

>>print timeit.Timer("f 2()", "from __main__ import f2").repeat(num ber=1)

[0.9135529994964 5996, 0.8656101226806 6406, 0.8437118530273 4375]

>>print timeit.Timer("f 1()", "from __main__ import f1").repeat(num ber=1)

[0.9463789463043 2129, 0.8994619846343 9941, 1.1703209877014 16]

[sjdevnull@yahoo.com]

Re: Method much slower than function?

On Jun 14, 1:10 am, Paul Rubin <http://phr...@NOSPAM.i nvalidwrote:

"sjdevn...@yaho o.com" <sjdevn...@yaho o.comwrites:

take virtually the same amount of time on my machine (2.5), and the
non-join version is clearer, IMO. I'd still use join in case I wind
up running under an older Python, but it's probably not a big issue here.

>
You should not rely on using 2.5

I use generator expressions and passed-in values to generators and
other features of 2.5. Whether or not to rely on a new version is
really a judgement call based on how much time/effort/money the new
features save you vs. the cost of losing portability to older
versions.

or even on that optimization staying in CPython.

You also shouldn't count on dicts being O(1) on lookup, or "i in
myDict" being faster than "i in myList". A lot of quality of
implementation issues outside of the language specification have to be
considered when you're worried about running time.

Unlike fast dictionary lookup at least the += optimization in CPython
is specified in the docs (as well as noting that "".join is greatly
preferred if you're working across different versions and
implementations ).

Best is to use StringIO or something comparable.

Yes, or the join() variant.

[Josiah Carlson]

Re: Method much slower than function?

sjdevnull@yahoo .com wrote:

On Jun 14, 1:10 am, Paul Rubin <http://phr...@NOSPAM.i nvalidwrote:

>"sjdevn...@yah oo.com" <sjdevn...@yaho o.comwrites:

>>take virtually the same amount of time on my machine (2.5), and the
>>non-join version is clearer, IMO. I'd still use join in case I wind
>>up running under an older Python, but it's probably not a big issue here.

>You should not rely on using 2.5

>
I use generator expressions and passed-in values to generators and
other features of 2.5.

For reference, generator expressions are a 2.4 feature.

>or even on that optimization staying in CPython.

>
You also shouldn't count on dicts being O(1) on lookup, or "i in
myDict" being faster than "i in myList".

Python dictionaries (and most decent hash table implementations ) may not
be O(1) technically, but they are expected O(1) and perform O(1) in
practice (at least for the Python implementations ). If you have
particular inputs that force Python dictionaries to perform poorly (or
as slow as 'i in lst' for large dictionaries and lists), then you should
post a bug report in the sourceforge tracker.


- Josiah

[Josiah Carlson]

Re: Method much slower than function?

Francesco Guerrieri wrote:

On 6/14/07, Peter Otten <__peter__@web. dewrote:

>Gabriel Genellina wrote:

...
pyprint timeit.Timer("f 2()", "from __main__ import

>f2").repeat(nu mber=1)

[0.4267366383157 6358, 0.4280759146763 0662, 0.4440148119383 8876]
pyprint timeit.Timer("f 1()", "from __main__ import

>f1").repeat(nu mber=1)

>
...after a few minutes I aborted the process...

>>
>I can't confirm this.

>
[...]
>

>$ python2.5 -m timeit -s 'from join import f1' 'f1()'
>10 loops, best of 3: 212 msec per loop
>$ python2.5 -m timeit -s 'from join import f2' 'f2()'
>10 loops, best of 3: 259 msec per loop
>$ python2.5 -m timeit -s 'from join import f3' 'f3()'
>10 loops, best of 3: 236 msec per loop

>
On my machine (using python 2.5 under win xp) the results are:

>>>print timeit.Timer("f 2()", "from __main__ import f2").repeat(num ber
>>>= 1)

[0.1972683482282 3575, 0.1932469745640 8974, 0.1947449259421 2861]

>>>print timeit.Timer("f 1()", "from __main__ import f1").repeat(num ber
>>>= 1)

[21.982707133304 167, 21.905312587963 252, 22.843430035622 767]
>
so it seems that there is a rather sensible difference.
what's the reason of the apparent inconsistency with Peter's test?

It sounds like a platform memory resize difference.


- Josiah

[Gabriel Genellina]

Re: Method much slower than function?

En Thu, 14 Jun 2007 05:54:25 -0300, Francesco Guerrieri
<f.guerrieri@gm ail.comescribió :

On 6/14/07, Peter Otten <__peter__@web. dewrote:

>Gabriel Genellina wrote:

...
pyprint timeit.Timer("f 2()", "from __main__ import

>f2").repeat(nu mber=1)

[0.4267366383157 6358, 0.4280759146763 0662, 0.4440148119383 8876]
pyprint timeit.Timer("f 1()", "from __main__ import

>f1").repeat(nu mber=1)

>
...after a few minutes I aborted the process...

>>
>I can't confirm this.

>
[...]
>

>$ python2.5 -m timeit -s 'from join import f1' 'f1()'
>10 loops, best of 3: 212 msec per loop
>$ python2.5 -m timeit -s 'from join import f2' 'f2()'
>10 loops, best of 3: 259 msec per loop
>$ python2.5 -m timeit -s 'from join import f3' 'f3()'
>10 loops, best of 3: 236 msec per loop

>
On my machine (using python 2.5 under win xp) the results are:

>>>print timeit.Timer("f 2()", "from __main__ import f2").repeat(num ber =
>>>1)

[0.1972683482282 3575, 0.1932469745640 8974, 0.1947449259421 2861]

>>>print timeit.Timer("f 1()", "from __main__ import f1").repeat(num ber =
>>>1)

[21.982707133304 167, 21.905312587963 252, 22.843430035622 767]
>
so it seems that there is a rather sensible difference.
what's the reason of the apparent inconsistency with Peter's test?

I left the test running and went to sleep. Now, the results:

C:\TEMP>python -m timeit -s "from join import f1" "f1()"
10 loops, best of 3: 47.7 sec per loop

C:\TEMP>python -m timeit -s "from join import f2" "f2()"
10 loops, best of 3: 317 msec per loop

C:\TEMP>python -m timeit -s "from join import f3" "f3()"
10 loops, best of 3: 297 msec per loop

Yes, 47.7 *seconds* to build the string using the += operator.
I don't know what's the difference: python version (this is not 2.5.1
final), hardware, OS... but certainly in this PC it is *very* important.
Memory usage was around 40MB (for a 10MB string) and CPU usage went to 99%
(!).

--
Gabriel Genellina