[cairo] Performance analysis of a Cairo application

[Jeff Muizelaar]

On Fri, Oct 19, 2007 at 04:18:12PM -0200, Ivan Baldo wrote:
>    Hello Dan, thanks for answering!
> 
> 
> El 18/10/07 19:38, Dan Amelang escribió:
> >On 10/17/07, Ivan Baldo <ibaldo at adinet.com.uy> wrote:
> >  
> >>    Hello.
> >>    I want my (under development) application to run faster, so I want
> >>to know where most of the time is spent to focus this optimization effort.
> >>...
> >>    Instead I am getting things like this:
> >>    1% main()
> >>99% draw()
> >>    50% drawThings1()
> >>    50% drawThings2()
> >>    Thats because both functions have equal complexity on my code, but I
> >>know that actually drawThings1 is using Cairo in a way that it is slower
> >>for Cairo or my graphics card to process than drawThings2.
> >>    
> >
> >And how do you know this?
> >  
>    Intuition, and I know that it isn't the right way to profile 
> programs and optimize them, thats why I looked at gprof and oprofile, 
> but didn't get meaningful results for my purpose, so after googling a 
> bit I decided that it was time to ask for help :-).
> 
> 
> >The Right Thing To Do is use oprofile to get global, system-wide
> >profiles what will contain performance information for both your
> >application code, cairo, and the X server. That should be all you
> >need, don't worry about the work your graphics card is doing. It's
> >unlikely that your graphics card is involved in the bottleneck, in
> >fact, on many (most?) systems today, the graphics card isn't doing
> >that much to accelerate cairo (yet).
> >
> >So you want to find out what your CPU is spending its time doing, and
> >oprofile is the way to get that.
> >  
>    I get that with oprofile, you are right, but it is not what I am 
> looking because it is not centered on _the outside effects accumulated 
> on my application_.
>    Maybe I am not being clear by email (or my bad English), to help 
> explain this a bit (and to simplify my research) I made this simple 
> standalone Cairo XRender application (based on the Cairo boilerplate 
> code) that it is attached.
>    It has two functions (testfast and testslow) that call one function 
> that does the actual work but only varying the size of the drawing.
>    I get this output:
> Elapsed times: fast 3710ms (22%), slow 12892ms (77%), total 16602ms.
>    It doesn't matter if I use gprof or qprof or oprofile, none of this 
> tools told me that testfast accumulated to the 22% of the running time 
> and that testslow accumulated to the 77% of the running time.
>    To repeat, I would like a call-graph that says something like this:
> 
> main
>    77% testslow
>        77% test
>    22% testfast
>        22% test
> 
> testslow
>    100% test
> 
> testfast
>    100% test

Sysprof can do this. The important point here is that you want to record
an entire backtrace at each sampling point instead of just the program
counter. I'm not sure whether gprof, qprof, or oprofile support
capturing an entire backtrace, but sysprof certainly does.

However, because you are using X and that is where the majority of the
cpu time is being spent. Sysprof will not be able to associate the time
spent in X with the calling function (testfast or testslow) because the
backtraces stay inside each process.

I worked around this with your example by using an image surface instead
of an X surface. I was able to get the following results:

Elapsed times: fast 8714ms (24%), slow 26677ms (75%), total 35391ms.

and sysprof reports the following totals:
testslow - 72%
testfast - 23%

-Jeff