Stef Telford | 22 Jul 2009 17:19

Re: SQLObject Speed ?

Oleg Broytmann wrote:
> On Fri, May 22, 2009 at 12:52:52PM -0400, Stef Telford wrote:
>   
>> I am merely wondering where things 'slow 
>> down' so much and if there is anything we can do about it :(
>>     
>
>    Can you run your test program under the python profiler and find out the
> slow spot(s)?
>
> Oleg.
>   
Hello Oleg, Everyone,
    Sorry for the delay in replying.. "real life" sort of got in the 
way. Deepest apologies for that.

    When I benchmarked the SQLObject page of 7000+ objects (give or take 
a few hundred), I got the 80-90 seconds. With plain python objects, I 
got the 0.3 seconds (obviously a lot less going on, so, not surprising 
there). However, when I took out the evals inside sqlobject/main.py, I 
got the page speed to around 15-20 seconds.

    So, this raises the question, is it perhaps better to -not- use 
eval(..) and instead tinker with the objects __attributes__ or __dict__ 
? I am not -that- conversant/knowledgeable in pythons black magic of 
object meta programming but.. I definitely think that if we can get away 
from calling 'evals' when doing object instantiation that would be a 
HUGE performance win.

    And, in the process of putting my money where my mouth is, I am more 
(Continue reading)

Oleg Broytmann | 22 Jul 2009 18:13
X-Face
Picon
Favicon

Re: SQLObject Speed ?

Hi!

On Wed, Jul 22, 2009 at 11:19:36AM -0400, Stef Telford wrote:
> Hello Oleg, Everyone,
>    Sorry for the delay in replying.. "real life" sort of got in the way. 
> Deepest apologies for that.

   No problem. I understand the issue and feel your pain, sure.

>    When I benchmarked the SQLObject page of 7000+ objects (give or take  
> a few hundred), I got the 80-90 seconds. With plain python objects, I  
> got the 0.3 seconds (obviously a lot less going on, so, not surprising  
> there). However, when I took out the evals inside sqlobject/main.py, I  
> got the page speed to around 15-20 seconds.

   Aha, that's the results! Thank you!

   In what way have you "took out the evals"? You cannot just remove them so
you probably replaced them? with what?

>    So, this raises the question, is it perhaps better to -not- use  
> eval(..) and instead tinker with the objects __attributes__ or __dict__  
> ? I am not -that- conversant/knowledgeable in pythons black magic of  
> object meta programming but.. I definitely think that if we can get away  
> from calling 'evals' when doing object instantiation that would be a  
> HUGE performance win.

   That requires some thinking and experimenting. Perhaps those evals
could be replaced with functools.partial - that requires python 2.5, so it
can be implemented after SQLObject 0.11 (which I'm gonna release RSN).
(Continue reading)

Stef Telford | 22 Jul 2009 19:27

Re: SQLObject Speed ?

Hello again Oleg, Everyone

Oleg Broytmann wrote:
> Hi!
>
> On Wed, Jul 22, 2009 at 11:19:36AM -0400, Stef Telford wrote:
>   
>> Hello Oleg, Everyone,
>>    Sorry for the delay in replying.. "real life" sort of got in the way. 
>> Deepest apologies for that.
>>     
>
>    No problem. I understand the issue and feel your pain, sure.
>
>   
*chuckles* this is kind of the problem with OS projects. We use them 
almost 100% here at work but try to spend any -actual- time on improving 
them and.. well.. yes.
>>    When I benchmarked the SQLObject page of 7000+ objects (give or take  
>> a few hundred), I got the 80-90 seconds. With plain python objects, I  
>> got the 0.3 seconds (obviously a lot less going on, so, not surprising  
>> there). However, when I took out the evals inside sqlobject/main.py, I  
>> got the page speed to around 15-20 seconds.
>>     
>
>    Aha, that's the results! Thank you!
>
>    In what way have you "took out the evals"? You cannot just remove them so
> you probably replaced them? with what?
>
(Continue reading)

Oleg Broytmann | 22 Jul 2009 20:03
X-Face
Picon
Favicon

Re: SQLObject Speed ?

On Wed, Jul 22, 2009 at 01:27:41PM -0400, Stef Telford wrote:
>>> Hello Oleg, Everyone,
>>>    Sorry for the delay in replying.. "real life" sort of got in the 
>>> way. Deepest apologies for that.
>>
>>    No problem. I understand the issue and feel your pain, sure.
>>
> *chuckles* this is kind of the problem with OS projects. We use them  
> almost 100% here at work but try to spend any -actual- time on improving  
> them and.. well.. yes.

   Well, I have a lot of job, too; and another problem is that my
mother-in-law is very ill so my wife and me have to sit beside her days and
nights.

> actually.. I -did- remark them out. As I said, all the evals do (I  
> -believe-) is to add the lambda into the python dictionary with a  
> specific name for getattr to find

   Not for getattr - for property... but that's a minor technical detail.

> I have read in numerous places  
> that python's eval is hysterically slow
[skip]
> yes. evals appear to be  
> a 'bad' thing here :\

   Well, those evals are in sqlmeta.addColumn and .addJoin methods, so they
work once for every column in the table, but that's all. After the class
has been created and populated - whatever you do with rows (class instances)
(Continue reading)

Oleg Broytmann | 22 Jul 2009 20:46
X-Face
Picon
Favicon

Re: SQLObject Speed ?

On Wed, Jul 22, 2009 at 02:26:57PM -0400, Stef Telford wrote:
>>> yes. evals appear to be  a 'bad' thing here :\
>>
>>    Well, those evals are in sqlmeta.addColumn and .addJoin methods, so they
>> work once for every column in the table, but that's all. After the class
>> has been created and populated - whatever you do with rows (class instances)
>> - those evals are not executed.
>>
> Ah. hrm. *rubs chin* perhaps it's not the evals then. It seems that the  
> instantiations get .. well .. 'slower' over time.

   Curiouser and curiouser. IWBN to find where the slowness is *near the
end* of the loop - i.e. when instantiation becomes really slow.

> I should stress that  
> the amount of instantiations can reach into thousands easily for me. I  
> know this maybe a niche problem and for 10-30 objects the speed is good.

   Still I'd resolve the issue to at least some extent.

> I have attached the python -m cProfile output, and limited the run to  
> 'only' (?!) 40,000 objects. Hopefully this may make some more sense to  
> you. Gprof is.. definitely.. urm.. quirky :)

>    Ordered by: standard name
> 
>    ncalls  tottime  percall  cumtime  percall filename:lineno(function)
>     40000    0.063    0.000    0.141    0.000 <string>:1(<lambda>)

   Can you sort by ncalls and cumtime columns, cut the first 100-200 lines
(Continue reading)

Stef Telford | 22 Jul 2009 21:03

Re: SQLObject Speed ?

Oleg Broytmann wrote:
> On Wed, Jul 22, 2009 at 02:26:57PM -0400, Stef Telford wrote:
>   
>>>> yes. evals appear to be  a 'bad' thing here :\
>>>>         
>>>    Well, those evals are in sqlmeta.addColumn and .addJoin methods, so they
>>> work once for every column in the table, but that's all. After the class
>>> has been created and populated - whatever you do with rows (class instances)
>>> - those evals are not executed.
>>>
>>>       
>> Ah. hrm. *rubs chin* perhaps it's not the evals then. It seems that the  
>> instantiations get .. well .. 'slower' over time.
>>     
>
>    Curiouser and curiouser. IWBN to find where the slowness is *near the
> end* of the loop - i.e. when instantiation becomes really slow.
>
>   
It could be purely a 'feeling' .. I don't have any numbers to back it up 
and I am not entirely sure -how- to benchmark that. This machine does 
have 8gb of ram in it, and a fairly beefy quad core. I have never seen 
any process get near memory exhaustion, which I could believe the calls 
to 'malloc' could slow down but.. yes.

>>    Ordered by: standard name
>>
>>    ncalls  tottime  percall  cumtime  percall filename:lineno(function)
>>     40000    0.063    0.000    0.141    0.000 <string>:1(<lambda>)
>>     
(Continue reading)

David Turner | 22 Jul 2009 22:16
Gravatar

Re: SQLObject Speed ?

On Wed, 2009-07-22 at 15:03 -0400, Stef Telford wrote:
> Oleg Broytmann wrote:
> > On Wed, Jul 22, 2009 at 02:26:57PM -0400, Stef Telford wrote:
> >   
> >>>> yes. evals appear to be  a 'bad' thing here :\
> >>>>         
> >>>    Well, those evals are in sqlmeta.addColumn and .addJoin methods, so they
> >>> work once for every column in the table, but that's all. After the class
> >>> has been created and populated - whatever you do with rows (class instances)
> >>> - those evals are not executed.
> >>>
> >>>       
> >> Ah. hrm. *rubs chin* perhaps it's not the evals then. It seems that the  
> >> instantiations get .. well .. 'slower' over time.
> >>     
> >
> >    Curiouser and curiouser. IWBN to find where the slowness is *near the
> > end* of the loop - i.e. when instantiation becomes really slow.
> >
> >   
> It could be purely a 'feeling' .. I don't have any numbers to back it up 
> and I am not entirely sure -how- to benchmark that. This machine does 
> have 8gb of ram in it, and a fairly beefy quad core. I have never seen 
> any process get near memory exhaustion, which I could believe the calls 
> to 'malloc' could slow down but.. yes.

Python's GC takes time roughly proportional to the number of live
objects.  The GC is called every 700 allocations (7000, 70000 for older
generations), so allocation also takes time proportional to number of
live objects.
(Continue reading)

David Turner | 22 Jul 2009 23:03
Gravatar

Re: SQLObject Speed ?

On Wed, 2009-07-22 at 16:16 -0400, David Turner wrote:
> On Wed, 2009-07-22 at 15:03 -0400, Stef Telford wrote:
> > Oleg Broytmann wrote:
> > > On Wed, Jul 22, 2009 at 02:26:57PM -0400, Stef Telford wrote:
> > >   
> > >>>> yes. evals appear to be  a 'bad' thing here :\
> > >>>>         
> > >>>    Well, those evals are in sqlmeta.addColumn and .addJoin methods, so they
> > >>> work once for every column in the table, but that's all. After the class
> > >>> has been created and populated - whatever you do with rows (class instances)
> > >>> - those evals are not executed.
> > >>>
> > >>>       
> > >> Ah. hrm. *rubs chin* perhaps it's not the evals then. It seems that the  
> > >> instantiations get .. well .. 'slower' over time.
> > >>     
> > >
> > >    Curiouser and curiouser. IWBN to find where the slowness is *near the
> > > end* of the loop - i.e. when instantiation becomes really slow.
> > >
> > >   
> > It could be purely a 'feeling' .. I don't have any numbers to back it up 
> > and I am not entirely sure -how- to benchmark that. This machine does 
> > have 8gb of ram in it, and a fairly beefy quad core. I have never seen 
> > any process get near memory exhaustion, which I could believe the calls 
> > to 'malloc' could slow down but.. yes.
> 
> Python's GC takes time roughly proportional to the number of live
> objects.  The GC is called every 700 allocations (7000, 70000 for older
> generations), so allocation also takes time proportional to number of
(Continue reading)

Stef Telford | 22 Jul 2009 23:10

Re: SQLObject Speed ?

David Turner wrote:
> On Wed, 2009-07-22 at 16:16 -0400, David Turner wrote:
>   
>> On Wed, 2009-07-22 at 15:03 -0400, Stef Telford wrote:
>>     
>>> Oleg Broytmann wrote:
>>>       
>>>> On Wed, Jul 22, 2009 at 02:26:57PM -0400, Stef Telford wrote:
>>>>   
>>>>         
>>>>>>> yes. evals appear to be  a 'bad' thing here :\
>>>>>>>         
>>>>>>>               
>>>>>>    Well, those evals are in sqlmeta.addColumn and .addJoin methods, so they
>>>>>> work once for every column in the table, but that's all. After the class
>>>>>> has been created and populated - whatever you do with rows (class instances)
>>>>>> - those evals are not executed.
>>>>>>
>>>>>>       
>>>>>>             
>>>>> Ah. hrm. *rubs chin* perhaps it's not the evals then. It seems that the  
>>>>> instantiations get .. well .. 'slower' over time.
>>>>>     
>>>>>           
>>>>    Curiouser and curiouser. IWBN to find where the slowness is *near the
>>>> end* of the loop - i.e. when instantiation becomes really slow.
>>>>
>>>>   
>>>>         
>>> It could be purely a 'feeling' .. I don't have any numbers to back it up 
(Continue reading)

Stef Telford | 22 Jul 2009 23:18

Re: SQLObject Speed ?

Oleg Broytmann wrote:
> On Wed, Jul 22, 2009 at 03:03:52PM -0400, Stef Telford wrote:
>   
>> surely, please find the output attached at the bottom.
>>     
>
>    Thank you!
>
>   
No, Honestly, Thank you :)
>>    Ordered by: cumulative time
>>
>>    ncalls  tottime  percall  cumtime  percall filename:lineno(function)
>>         1    0.127    0.127   83.346   83.346 sresults.py:175(__iter__)
>>     40001    0.308    0.000   79.876    0.002 dbconnection.py:649(next)
>>     
>
>    Hmm. Does the program try to draw the entire table in one huge slurp?
>
>   
Actually, no. This page does 40k of bookings (a single object type) but 
the query isn't "Sequential" (it's not grabbing 0-40,000 is what I 
mean). I can do a page which has lots of different object types if this 
would help ?
>>     40000    0.375    0.000   39.282    0.001 main.py:872(get)
>>     40002   10.018    0.000   39.252    0.001 {method 'fetchone' of 'psycopg2._psycopg.cursor' objects}
>>     
>
>    Half of the time the program spends drawing rows one by one. This
> probably could be optimized by using fetchmany or fetchall.
(Continue reading)


Gmane