Re: Build profiling, now in pictures

[Darren Hart <dvhart@linux.intel.com>]

On 02/15/2011 09:32 AM, Richard Purdie wrote:
> We have just merged Beth's initial buildstats logging work. I was
> sitting wondering how to actually evaluate the numbers as I wanted to
> know "where are we spending the time?".
>
> It occurred to me that I wanted a graph very similar to that generated
> by bootchart. I looked around and found pyboootchartgui and then hacked
> it around a bit and coerced it to start producing charts like:
>
> http://tim.rpsys.net/bootchart.png
>
> which is the initial "pseudo-native" part of the build. This was simple
> enough to test with.
>
> I then tried graphing a poky-image-sato. To get a graph I could actually
> read, I stripped out any task taking less than 8 seconds and scaled the
> x axis from 25 units per second to one unit per second. The result was:
>
> http://tim.rpsys.net/bootchart2.png
> (warning this is a 2.7MB png)
>
> I also added in a little bit of colour coding for the second chart.
> Interestingly it looks like there is more yellow than green meaning
> configure is a bigger drain on the build time not that its
> unexpected :/.
>
> I quite enjoyed playing with this and on a serious note, the gradient of
> the task graph makes me a little suspicious of whether the overhead of
> launching tasks in bitbake itself is having some effect on build time.
> Certainly on the first graph there are some interesting latencies
> showing up.
>
> Anyhow, I think this is the first time bitbake's task execution has been
> visualised and there are some interesting things we can learn from it.
> I'm hoping this is a start of a much more detailed understanding of the
> build process with respect to performance.
>

Per Richard's request, I ran this on a large Westmere machine with 40 
physical cores (10 per socket).

BB_NUMBER_THREADS = "40"
PARALLEL_MAKE = "-j 40"
MACHINE=qemux86

Here's the poky-image-sato "buildchart" (1.6M):

http://dvhart.com/darren/yocto/buildchart-sato.png

For reference, total build time:

real    68m57.268s
user    424m23.566s
sys     211m30.272s

The higher core count results in a steeper gradient and makes the 
serialized build sections a bit more prominent. The two obvious 
serialization points being "eglibc" and the 
"openssl,ncurses,gettext,readline,sqlite,augeas,python,boost,perl" sequence.

--
Darren

> Cheers,
>
> Richard
>
>
>
> _______________________________________________
> poky mailing list
> poky@yoctoproject.org
> https://lists.yoctoproject.org/listinfo/poky


-- 
Darren Hart
Intel Open Source Technology Center
Yocto Project - Linux Kernel