pygccxml-development

[pygccxml-development] Performance regression?

[Allen B. <al...@vr...>]

One of the big projects I use Py++ with seems to be suffering from
performance issues.  I used to be able to generate the bindings in
approximately 10 minutes, now it is taking a little over 80 minutes.

I have been so happy with Py++ as of late that I haven't even been
paying attention to the changes going into Py++ so I don't know what may
be causing the slow down.  :)

I did collect some timing information though in the hopes that someone
smarter then me may be able to spot some corners of Py++ that could be
optimized.

During my run I output basic timings of:

Code generation complete.  took: 5099.32698894
     ...
     module builder init: 253.73842907
     ...
     build creators: 1991.69337511
     write module: 2821.93180895

I ran the whole thing through the cProfile module to see where python
was spending it's time. The raw data is available at:
https://realityforge.vrsource.org/twiki/pub/PyOpenSG/TempArea/gen_bindings.prof.bz2

A report summarizing the results (sorted by time spent exclusively 
within the method) is available here: 
https://realityforge.vrsource.org/twiki/pub/PyOpenSG/TempArea/stats.txt

Hopefully this will provide enough information to give some insight into 
what is going on.  Please let me know if there is any more information I 
can provide.

Thanks,
Allen

Re: [pygccxml-development] Performance regression?

[Roman Y. <rom...@gm...>]

On 8/2/07, Allen Bierbaum <al...@vr...> wrote:
> One of the big projects I use Py++ with seems to be suffering from
> performance issues.  I used to be able to generate the bindings in
> approximately 10 minutes, now it is taking a little over 80 minutes.

:-(. I will try to find out what happened. Can you provide the
versions you are using?
Also I must admit that something strange is going on. I am testing
Py++ on Python-Ogre project and I didn't see x8 performance
deterioration ( hope this is the right word to use).

Do you run same version of script?

> I have been so happy with Py++ as of late that I haven't even been
> paying attention to the changes going into Py++ so I don't know what may
> be causing the slow down.  :)

May be unicode support?

> I did collect some timing information though in the hopes that someone
> smarter then me may be able to spot some corners of Py++ that could be
> optimized.
>
> During my run I output basic timings of:
>
> Code generation complete.  took: 5099.32698894
>      ...
>      module builder init: 253.73842907
>      ...
>      build creators: 1991.69337511
>      write module: 2821.93180895
>
> I ran the whole thing through the cProfile module to see where python
> was spending it's time. The raw data is available at:
> https://realityforge.vrsource.org/twiki/pub/PyOpenSG/TempArea/gen_bindings.prof.bz2
>
> A report summarizing the results (sorted by time spent exclusively
> within the method) is available here:
> https://realityforge.vrsource.org/twiki/pub/PyOpenSG/TempArea/stats.txt

Can you also provide the profile information for your previous version of Py++?

-- 
Roman Yakovenko
C++ Python language binding
http://www.language-binding.net/

Re: [pygccxml-development] Performance regression?

[Allen B. <al...@vr...>]

Roman Yakovenko wrote:
> On 8/2/07, Allen Bierbaum <al...@vr...> wrote:
>> One of the big projects I use Py++ with seems to be suffering from
>> performance issues.  I used to be able to generate the bindings in
>> approximately 10 minutes, now it is taking a little over 80 minutes.
> 
> :-(. I will try to find out what happened. Can you provide the
> versions you are using?

Is is the latest version of Py++ with Python 2.5 and Ubuntu 7.04.  The 
previous work was done with Python 2.4 and FC6.

> Also I must admit that something strange is going on. I am testing
> Py++ on Python-Ogre project and I didn't see x8 performance
> deterioration ( hope this is the right word to use).
> 
> Do you run same version of script?

In the meantime the script has been extended to use some of the more 
advanced Py++ functionality in places.  I could probably back some of 
these changes out if we need to see the performance of an old version of 
Py++.

That said, nothing significant has changed in the binding generation 
script (just adding a couple transforms to a few classes).  The other 
thing of note is that the amount of time spent in the script is about 
the same as before.  The internal code of Py++ is where the increase is 
occuring.

> 
>> I have been so happy with Py++ as of late that I haven't even been
>> paying attention to the changes going into Py++ so I don't know what may
>> be causing the slow down.  :)
> 
> May be unicode support?

I guess this is possible.  If this is it, then there is not much that 
can be done to solve this part of it.  The best that could be done is to 
minimize the amount of comparisons performed by making some of the code 
smarter or caching some values.

> 
>> I did collect some timing information though in the hopes that someone
>> smarter then me may be able to spot some corners of Py++ that could be
>> optimized.
>>
>> During my run I output basic timings of:
>>
>> Code generation complete.  took: 5099.32698894
>>      ...
>>      module builder init: 253.73842907
>>      ...
>>      build creators: 1991.69337511
>>      write module: 2821.93180895
>>
>> I ran the whole thing through the cProfile module to see where python
>> was spending it's time. The raw data is available at:
>> https://realityforge.vrsource.org/twiki/pub/PyOpenSG/TempArea/gen_bindings.prof.bz2
>>
>> A report summarizing the results (sorted by time spent exclusively
>> within the method) is available here:
>> https://realityforge.vrsource.org/twiki/pub/PyOpenSG/TempArea/stats.txt
> 
> Can you also provide the profile information for your previous version of Py++?

That is quite a bit harder.  The script doesn't work with older versions 
of Py++ as far as I know.  If this is something that you really really 
need, I could try to find some time over the weekend.

I was hoping that you may just see something in the profile output that 
would point to a corner case in Py++ that is causing the slowdown.

One other thing that may be useful is converting the cProfile (lsprof) 
output into a calltree.  This should show who is calling the various 
methods and how often.  This may help in pointing out some particularly 
expensive method.  You can use the script here: 
http://ddaa.net/blog/python/lsprof-calltree to convert the data.

-Allen

Re: [pygccxml-development] Performance regression?

[Roman Y. <rom...@gm...>]

On 8/2/07, Allen Bierbaum <al...@vr...> wrote:
> > :-(. I will try to find out what happened. Can you provide the
> > versions you are using?
>
> Is is the latest version of Py++ with Python 2.5 and Ubuntu 7.04.  The
> previous work was done with Python 2.4 and FC6.

I actually wanted to know the version\revisions of Py++ the previous
and the current one. I studied the profile file you post and didn't
find something suspicious.

> > Also I must admit that something strange is going on. I am testing
> > Py++ on Python-Ogre project and I didn't see x8 performance
> > deterioration ( hope this is the right word to use).
> >
> > Do you run same version of script?
>
> In the meantime the script has been extended to use some of the more
> advanced Py++ functionality in places.  I could probably back some of
> these changes out if we need to see the performance of an old version of
> Py++.
>
> That said, nothing significant has changed in the binding generation
> script (just adding a couple transforms to a few classes).  The other
> thing of note is that the amount of time spent in the script is about
> the same as before.  The internal code of Py++ is where the increase is
> occuring.

Here is a list of changes for two months in Py++ and pygccxml projects:

* adding support for GCC-XML attributes - it has performance penalty
but you cannot even measure it
* adding unicode support - this one potenitally could cause
performance issues, but I didn't find them when I tested the code. May
be you can try to use previous version of the function, without
unicode support to verify this?
* Py++ is able to save md5 sum of every written file. It will reuse it
later, which will allow to save time, by avoiding loading the files
from disk. It is described here:
http://pygccxml.svn.sourceforge.net/viewvc/pygccxml/pyplusplus_dev/docs/documentation/best_practices.rest?revision=1019&view=markup
* warnings - the underlying mechanism of warning reporting has
changed. I think that this changed doesn't influence the performance,
but it worse to check.
* improving "include" directive code generation - Py++ generates
include directive only if the include is really needed.

I don't see any other change that could somehow influence on performance.

> >
> >> I have been so happy with Py++ as of late that I haven't even been
> >> paying attention to the changes going into Py++ so I don't know what may
> >> be causing the slow down.  :)
> >
> > May be unicode support?
>
> I guess this is possible.  If this is it, then there is not much that
> can be done to solve this part of it.  The best that could be done is to
> minimize the amount of comparisons performed by making some of the code
> smarter or caching some values.

What do you propose?

> >
> >> I did collect some timing information though in the hopes that someone
> >> smarter then me may be able to spot some corners of Py++ that could be
> >> optimized.
> >>
> >> During my run I output basic timings of:
> >>
> >> Code generation complete.  took: 5099.32698894
> >>      ...
> >>      module builder init: 253.73842907
> >>      ...
> >>      build creators: 1991.69337511
> >>      write module: 2821.93180895
> > Can you also provide the profile information for your previous version of Py++?
>
> That is quite a bit harder.  The script doesn't work with older versions
> of Py++ as far as I know.  If this is something that you really really
> need, I could try to find some time over the weekend.

I definitely need to see the comparison. I hope I will be able to
concentrate my attention on the part that changed.

> I was hoping that you may just see something in the profile output that
> would point to a corner case in Py++ that is causing the slowdown.

I didn't see anything :-(

> One other thing that may be useful is converting the cProfile (lsprof)
> output into a calltree.  This should show who is calling the various
> methods and how often.  This may help in pointing out some particularly
> expensive method.  You can use the script here:
> http://ddaa.net/blog/python/lsprof-calltree to convert the data.

I will try this.


-- 
Roman Yakovenko
C++ Python language binding
http://www.language-binding.net/

Re: [pygccxml-development] Performance regression?

[Allen B. <al...@vr...>]

Thanks to Roman's most recent changes, the performance problem I was 
running into has been removed.

My new timings are:

Code generation complete.  took: 219.872961044
   ...
   module builder init: 115.682010889
   ...
   build creators: 11.5951149464
   write module: 67.6457870007

The summary is that Roman has succeeded in making Py++ ~25x faster 
overall for my test case and he has made the building of creators run 
~170x faster.  I for one am very happy with that increase. :)

Thanks a million Roman.  This single set of changes will save me hours 
and hours of waiting.

-Allen


Allen Bierbaum wrote:
> One of the big projects I use Py++ with seems to be suffering from
> performance issues.  I used to be able to generate the bindings in
> approximately 10 minutes, now it is taking a little over 80 minutes.
> 
> I have been so happy with Py++ as of late that I haven't even been
> paying attention to the changes going into Py++ so I don't know what may
> be causing the slow down.  :)
> 
> I did collect some timing information though in the hopes that someone
> smarter then me may be able to spot some corners of Py++ that could be
> optimized.
> 
> During my run I output basic timings of:
> 
> Code generation complete.  took: 5099.32698894
>      ...
>      module builder init: 253.73842907
>      ...
>      build creators: 1991.69337511
>      write module: 2821.93180895
> 
> I ran the whole thing through the cProfile module to see where python
> was spending it's time. The raw data is available at:
> https://realityforge.vrsource.org/twiki/pub/PyOpenSG/TempArea/gen_bindings.prof.bz2
> 
> A report summarizing the results (sorted by time spent exclusively 
> within the method) is available here: 
> https://realityforge.vrsource.org/twiki/pub/PyOpenSG/TempArea/stats.txt
> 
> Hopefully this will provide enough information to give some insight into 
> what is going on.  Please let me know if there is any more information I 
> can provide.
> 
> Thanks,
> Allen
> 
> 
> 
> -------------------------------------------------------------------------
> This SF.net email is sponsored by: Splunk Inc.
> Still grepping through log files to find problems?  Stop.
> Now Search log events and configuration files using AJAX and a browser.
> Download your FREE copy of Splunk now >>  http://get.splunk.com/
> _______________________________________________
> pygccxml-development mailing list
> pyg...@li...
> https://lists.sourceforge.net/lists/listinfo/pygccxml-development
> 

Re: [pygccxml-development] Performance regression?

[Roman Y. <rom...@gm...>]

On 8/21/07, Allen Bierbaum <al...@vr...> wrote:
> Thanks to Roman's most recent changes, the performance problem I was
> running into has been removed.
>
> My new timings are:
>
> Code generation complete.  took: 219.872961044
>    ...
>    module builder init: 115.682010889
>    ...
>    build creators: 11.5951149464
>    write module: 67.6457870007
>
> The summary is that Roman has succeeded in making Py++ ~25x faster
> overall for my test case and he has made the building of creators run
> ~170x faster.  I for one am very happy with that increase. :)

Nice numbers!

> Thanks a million Roman.  This single set of changes will save me hours
> and hours of waiting.

Enjoy :-)

P.S.  pstats module have interactive mode - very very helpful.

-- 
Roman Yakovenko
C++ Python language binding
http://www.language-binding.net/

Re: [pygccxml-development] Performance regression?

[Allen B. <al...@vr...>]

Roman Yakovenko wrote:
> On 8/21/07, Allen Bierbaum <al...@vr...> wrote:
>> Thanks to Roman's most recent changes, the performance problem I was
>> running into has been removed.
>>
>> My new timings are:
>>
>> Code generation complete.  took: 219.872961044
>>    ...
>>    module builder init: 115.682010889
>>    ...
>>    build creators: 11.5951149464
>>    write module: 67.6457870007
>>
>> The summary is that Roman has succeeded in making Py++ ~25x faster
>> overall for my test case and he has made the building of creators run
>> ~170x faster.  I for one am very happy with that increase. :)
> 
> Nice numbers!
> 
>> Thanks a million Roman.  This single set of changes will save me hours
>> and hours of waiting.
> 
> Enjoy :-)
> 
> P.S.  pstats module have interactive mode - very very helpful.
> 

Do you have a link to some documentation about this mode?

-Allen

Re: [pygccxml-development] Performance regression?

[Roman Y. <rom...@gm...>]

On 8/21/07, Allen Bierbaum <al...@vr...> wrote:
> Do you have a link to some documentation about this mode?

The interactive mode comes with documentation:

> python -m pstats
% help


That's all you need to know to start.


-- 
Roman Yakovenko
C++ Python language binding
http://www.language-binding.net/