Skip to contentSkip to conversation

Some notes on speeding up do_package_write_rpm

DISCUSSION Richard Purdie 2 participants 2 messages Feb 8, 2012

lore
Share & tools
lore
#0 lore raw

I had a look at why do_package_write_rpm seems slow. It's clear most of the time is being spent in rpmbuild. Taking the BUILDSPEC script, it was interesting to run it standalone with "strace -f". The result with libxfont was a 13.5MB log file showing lots of execs of grep, wc, cut and other shell utils.

This confirmed suspicion I had that the X.provides and X.requires scripts that are written out and called by rpmbuild were causing some performance issues since those scripts are where the grep/wc/cut calls are coming from.

Rewriting dump_filterdeps() in package_rpm.bbclass to write out a python script instead of a shell script (doing the same work), resulted in an strace logfile of 1.5MB, much smaller. The big win is that python has internal functions for these things so we don't have all the exec() overhead and don't hit the kernel anywhere near as much.

This showed small improvements in times for some simple package writing tasks. I then ran "time bitbake eglibc-locale -c package_write_rpm -f" which I've noticed is one of the last tasks to complete on my standard build time benchmark atm. The results with shell script (i.e. before):

real 7m15.207s
user 2m31.320s
sys 0m27.720s

and after, with the python script:

real 5m23.727s
user 3m25.540s
sys 1m4.530s

So in real terms its much faster but it claims to be using more user and sys resources. So it looks to be a performance speedup (and everything I've done would agree with that) but those user/sys numbers don't make sense.

I find the first set of numbers odd anyway as how can something spending 2.5 minutes in user and 0.5 minutes in sys making a total of 3 minutes, take 7.25 minutes to run on a multicore system that is otherwise idle. I suspect somewhere, the accounting in the kernel is screwing up maybe in the handling of the many short lived processes we were triggering. The real numbers correspond with my stopwatch so I'm happy to proceed with changes in this direction but if anyone does understand why those numbers would differ like that, I'd be interested to know about it.

Tests to see how much overall this helps our build time are still in progress.

Cheers,

Richard

#1 lore raw
Quoted 15 lines · Richard Purdie

real    7m15.207s
user    2m31.320s
sys     0m27.720s

and after, with the python script:

real    5m23.727s
user    3m25.540s
sys     1m4.530s

So in real terms its much faster but it claims to be using more user and sys resources. So it looks to be a performance speedup (and everything I've done would agree with that) but those user/sys numbers don't make sense.

Quoted 5 lines

I find the first set of numbers odd anyway as how can something spending 2.5 minutes in user and 0.5 minutes in sys making a total of 3 minutes, take 7.25 minutes to run on a multicore system that is otherwise idle. I suspect somewhere, the accounting in the kernel is screwing up maybe in the handling of the many short lived processes we were triggering.

yeah could be its so small that it gets rounded off.

The

Quoted 3 lines

real numbers correspond with my stopwatch so I'm happy to proceed with changes in this direction but if anyone does understand why those numbers would differ like that, I'd be interested to know about it.

I think it could be that there is more parallel threads now. since user+sys is across all cpus so you see more user+sys but overall real time is improved so its good.