Update on build time performance - not good
We've merged a number of things which should have helped performance recently. Changes in my test included:
* Splitting out the locale generation [not merged yet]
* Not building tar-replacement-native when we don't need it
* Cleaned up dependencies for native/nativesdk
* Cleaned up dependencies for all-arch packages
* Reduced dbus-native dependencies
The time for the benchmark timing test against master with the locale split patch applied was:
real 105m5.813s
user 386m39.170s
sys 59m40.250s
so not that much different from where we have been :(.
I did observe things through the build process:
* The first part of the build was *fast* getting through the first 2000 of 4295 tasks in about 10 minutes.
* The CPU usage was pretty much full for that time
* The next 5 minutes covered the next 150 tasks
* gettext-native didn't seem to get built until surprisingly late in the process
* There was a highly serialised chain of gettext-native, libelf-native, binutils-native, binutils-cross etc.
* Once eglibc/libgcc completed, processor usage was high again for the rest of the build
I'm hoping my BB_NUMBER_THREADS (12 on a quad core machine) was too high causing too much context switching and as the build process might now be more efficient, lowering it might help. I am a bit disappointed in those numbers though.
Cheers,
Richard
Op 10 jun 2011, om 10:44 heeft Richard Purdie het volgende geschreven:
Quoted 31 lines
We've merged a number of things which should have helped performance recently. Changes in my test included:
* Splitting out the locale generation [not merged yet]
* Not building tar-replacement-native when we don't need it
* Cleaned up dependencies for native/nativesdk
* Cleaned up dependencies for all-arch packages
* Reduced dbus-native dependenciesThe time for the benchmark timing test against master with the locale split patch applied was:
real 105m5.813s
user 386m39.170s
sys 59m40.250sso not that much different from where we have been :(.
I did observe things through the build process:
* The first part of the build was *fast* getting through the first 2000 of 4295 tasks in about 10 minutes.
* The CPU usage was pretty much full for that time
* The next 5 minutes covered the next 150 tasks
* gettext-native didn't seem to get built until surprisingly late in the process
* There was a highly serialised chain of gettext-native, libelf-native, binutils-native, binutils-cross etc.
* Once eglibc/libgcc completed, processor usage was high again for the rest of the build
Quoted 4 lines
I'm hoping my
BB_NUMBER_THREADS(12 on a quad core machine) was too high causing too much context switching and as the build process might now be more efficient, lowering it might help. I am a bit disappointed in those numbers though.
Do you have pretty bootchart graphs for that?
regards,
Koen
Just for interest, for the first time ever I did a dump out of profile information on the python side of bitbake's task execution for all tasks of a core-image-sato build.
I enabled profiling of each forked off task with this patch:
and then combined the results together in the attached profile report. Most of it isn't a big surprise but there are some interesting numbers such as the 278 million calls to _keys() in data_smart. For that specific issue I have a patch which I'm considering:
as experience shows that function calls have overhead in python at that number of iterations and reworking the code likely will reduce overhead. I've yet to profile the result on this scale though.
Overall, a build makes over 10 billion python function calls. We access data store variable flags 150 million times.
Not shown here but interestingly, early in the build process, the number of calls to time.sleep() was low, at the end of this build its rather significantly higher showing bitbake was hitting its idle handler a lot more. Time spend there is an illusion as the system should have yielded to other processes.
There are probably some other interesting things to be noticed somewhere in that data :)
Cheers,
Richard