<div dir="ltr">> Will try to bump BB_NUMBER_THREADS from 8 to 72.<div><br></div><div>I've tried to remove icecc.bbclass inherit (because it does things while parsing and RP probably doesn't have it inherited), but that didn't save much time.</div><div><br></div><div>All 3 tests were with bitbake 18d4a31fdcec1f0e5d2199d6142f0ce833fca1a7</div><div>94m19.081s 8 BB_NUMBER_THREADS and icecc</div><div>82m59.574s 8 BB_NUMBER_THREADS no icecc<br></div><div>68m3.556s 72 BB_NUMBER_THREADS no icecc<br></div><div><br></div><div>Still don't know how to get to sub 10min world runs RP was seeing, but at least it's as slow as it was before runqeueu changes (or even a bit faster in lastest master).</div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Fri, Aug 16, 2019 at 12:24 PM Martin Jansa <<a href="mailto:martin.jansa@gmail.com">martin.jansa@gmail.com</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">On Thu, Aug 15, 2019 at 05:05:48PM +0200, Martin Jansa wrote:<br>
> On Tue, Aug 13, 2019 at 10:04:08AM +0100, Richard Purdie wrote:<br>
> > On Mon, 2019-08-12 at 20:26 +0000, Peter Kjellerstedt wrote:<br>
> > > Comparing that build to a corresponding do-nothing build with Thud,<br>
> > > the time difference matches those three minutes where I have no idea<br>
> > > what bitbake is doing now that it didn’t need to do before…<br>
> > > <br>
> > > Hopefully these time degradations can be solved, because the current<br>
> > > state of bitbake is barely usable. We also need to look into possible<br>
> > > ways to improve the cooker output when it is running the setscene<br>
> > > tasks so it makes some kind of sense again.<br>
> > <br>
> > We talked on irc and you pointed at the commit things started to go<br>
> > wrong. Just to summarise things for the benefit of the list, this is<br>
> > some quick testing I did:<br>
> > <br>
> > "bitbake -p; time bitbake core-image-minimal -n"<br>
> > <br>
> > 30.0s 6c7c0cefd34067311144a1d4c01986fe0a4aef26<br>
> > 30.6s a0d941c787cf3ef030d190903279d311bc05d752<br>
> > 40.3s 7df31ff36892c2f9c65326b06b4c70 <br>
> > 42.2s a0542ed3ff700eca35f9195f743c9e28bcd50f3e <br>
> > 45.4s 9983b07fffd19082abded7c3f15cc77d306dd69c <br>
> > 76.9s master-next<br>
> <br>
> I know I'm late to the party, but it took really long for the test to finish..<br>
> <br>
> I'm not using poky, so reproduce this testing on our builds I've used<br>
> bitbake revisions matching with poky revision RP was testing:<br>
> <br>
> + oe-core 18cdc087fd5da30e2b31f3d4e81b153cd36ca844 for older bitbake, because current master isn't compatible with old bitbake (bb.data_smart.ExpansionError: Failure expanding variable OE_IMPORTED[:=], expression was ${@oe_import(d)} which triggered exception AttributeError: module 'bb.siggen' has no attribute 'SignatureGeneratorUniHashMixIn')<br>
> and oe-core 23db236a054ee7a989cdbbcb42ad5c6eefd4a6ae for newer bitbake (to possibly eliminate impact of metadata changes)<br>
> <br>
> tested on 72core (Intel(R) Xeon(R) CPU E5-2699 v3 @ 2.30GHz) with 380GB RAM<br>
> <br>
> nothing in TMPDIR/SSTATE_DIR, no SSTATE_MIRRO, no Hash Equivalence Server configured<br>
> <br>
> on a build with few more layers:<br>
> Parsing of 3238 .bb files complete (0 cached, 3238 parsed). 7632 targets, 1927 skipped, 54 masked, 0 errors.<br>
> <br>
> but first doing just core-image-minimal like RP did:<br>
> <br>
> time poky bitbake oe-core<br>
> 2m8.191s 6c7c0cefd34067311144a1d4c01986fe0a4aef26 18d4a31fdcec1f0e5d2199d6142f0ce833fca1a7 18cdc087fd5da30e2b31f3d4e81b153cd36ca844<br>
> N/A a0d941c787cf3ef030d190903279d311bc05d752 doesn't exist in poky/poky-contrib 18cdc087fd5da30e2b31f3d4e81b153cd36ca844<br>
> 2m17.053s 7df31ff36892c2f9c65326b06b4c70 1f630fdf0260db08541d3ca9f25f852931c19905 18cdc087fd5da30e2b31f3d4e81b153cd36ca844<br>
> 2m18.515s a0542ed3ff700eca35f9195f743c9e28bcd50f3e f43778c2d19e70d4befd483b06aaf247fc65c799 23db236a054ee7a989cdbbcb42ad5c6eefd4a6ae<br>
> 2m22.220s 9983b07fffd19082abded7c3f15cc77d306dd69c 8c26b451f22193ef1c544e2017cc84515566c1b8<br>
> 2m38.185s master-next fbcb89dc3dbabfc80310e9a4ebe72d919300a32e<br>
> cache.py:446: ResourceWarning: unclosed <socket.socket fd=10, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=0, laddr=('127.0.0.1', 41117)><br>
> value = pickled.load()<br>
> started showing with this revision<br>
> 2m17.991s master-next + fixups f7cd14f90463957b3e4be6d3876def98b78f1424<br>
> 2m9.651s master-next + "Holding off tasks %s" out<br>
> <br>
> now world<br>
> 253m36.637s 7df31ff36892c2f9c65326b06b4c70 1f630fdf0260db08541d3ca9f25f852931c19905 18cdc087fd5da30e2b31f3d4e81b153cd36ca844<br>
> 174m13.324s a0542ed3ff700eca35f9195f743c9e28bcd50f3e f43778c2d19e70d4befd483b06aaf247fc65c799 23db236a054ee7a989cdbbcb42ad5c6eefd4a6ae<br>
> this is time when killed at "NOTE: Executing Tasks" without showing any progress on the tasks (unlike other tests) and only one bitbake process is running<br>
> 633m27.475s master-next fbcb89dc3dbabfc80310e9a4ebe72d919300a32e<br>
> this is time when killed at (1417 from 71749) - running very slowly unlike other bitbake revisions where the task number changes relatively quickly - about 10 tasks per second<br>
> 89m13.992s master-next + "Holding off tasks %s" out<br>
> 89m59.201s master-next updated today 85fe627fdb6510f0942917964386fad9d8c479c8<br>
> <br>
> Interestingly old 1f630fdf0260db08541d3ca9f25f852931c19905 is 3 times<br>
> slower than recent master-next.<br>
> <br>
> I'll send -P output next.<br>
<br>
<br>
So 1f630fdf0260db08541d3ca9f25f852931c19905 was already "bad", because<br>
this commit introduced that<br>
logger.debug(2, "Holding off tasks %s" % pprint.pformat(self.holdoff_tasks))<br>
<br>
Here is -P output from it:<br>
<br>
5min (til "Executing Tasks" message):<br>
profile.log.processed.1f630fdf0260db08541d3ca9f25f85<a href="http://2931c19905.return.at" target="_blank">2931c19905.return.at</a>.Executing.Tasks<br>
<a href="http://paste.ubuntu.com/p/Nw6n5hTPmF/" rel="noreferrer" target="_blank">http://paste.ubuntu.com/p/Nw6n5hTPmF/</a><br>
<br>
5hours (whole dry run):<br>
profile.log.processed.1f630fdf0260db08541d3ca9f25f852931c19905.whole.dry.run<br>
<a href="http://paste.ubuntu.com/p/sydFGvYTxQ/" rel="noreferrer" target="_blank">http://paste.ubuntu.com/p/sydFGvYTxQ/</a><br>
profile.log.processed.1f630fdf0260db08541d3ca9f25f852931c19905.worker.log.processed<br>
<a href="http://paste.ubuntu.com/p/RMGbm9DyZz/" rel="noreferrer" target="_blank">http://paste.ubuntu.com/p/RMGbm9DyZz/</a><br>
<br>
So for good old baseline I need to go few commits back, to e.g. 18d4a31f RP was testing before:<br>
<br>
1f630fdf runqueue: Enable dynamic task adjustment to hash equivalency<br>
a0d941c7 siggen: Convert to use self.unitaskhashes<br>
1f326f2c siggen: Add new unitaskhashes data variable which is cached<br>
b707d0cb runqueue: Improve scenequeue processing logic<br>
19a6e356 cache: Add SimpleCache class<br>
7bb79099 siggen: Import unihash code from OE-Core<br>
7aec8632 hashserv: SQL Optimizations<br>
18d4a31f fetch2/wget: avoid 'maximum recursion depth' RuntimeErrors when handling 403 codes<br>
<br>
94m19.081s<br>
profile.log.processed.18d4a31fdcec1f0e5d2199d6142f0ce833fca1a7.whole.dry.run<br>
<a href="http://paste.ubuntu.com/p/Jnvv8GJNKB/" rel="noreferrer" target="_blank">http://paste.ubuntu.com/p/Jnvv8GJNKB/</a><br>
<br>
And here is profile with latest master from yesterday:<br>
90mins:<br>
profile.log.processed.a5e084a266f63c2fd370122327615e49beaeb94e.whole.dry.run<br>
<a href="http://paste.ubuntu.com/p/YhMCHPmg56/" rel="noreferrer" target="_blank">http://paste.ubuntu.com/p/YhMCHPmg56/</a><br>
<br>
So good news is that current master is a bit faster than "good old" 18d4a31fdcec1f0e5d2199d6142f0ce833fca1a7.<br>
<br>
But still significantly slower on my fast builder compared to world tests on poky + meta-oe,<br>
not sure if it's all just because the size of metadata in my builds (with 71K tasks).<br>
<br>
Even the dry running the tasks was about 10 tasks/second while RP was seeing around 200 tasks/second.<br>
<br>
Will try to bump BB_NUMBER_THREADS from 8 to 72.<br>
<br>
I've already disabled rm_work and PRserv, but that doesn't seem to have any significant impact on performance here. Other than resolving the PRserv terminating and then warnings about lost connection.<br>
<br>
Cheers,<br>
> <br>
> > <br>
> > So basically the original changes showed a 25% hit but the performance<br>
> > of -next is dire.<br>
> > <br>
> > This is with no hash equiv server configured.<br>
> > <br>
> > It will vary depending on the target used (numbers with -sato for the<br>
> > above would be interesting for comparision) and how much was or is in<br>
> > sstate, they type of sstate mirror configured and so on.<br>
> > <br>
> > I really need to focus on getting the new code functioning correctly<br>
> > before we attempt to optimise but if nobody tests the new code due to<br>
> > performance problems we have a different issue. We also have a scaling<br>
> > problem with the hash server itself I need to fix to stop the<br>
> > autobuilder throwing weird errors. I'm therefore a bit challenged on<br>
> > where to start with it all :/.<br>
> > <br>
> > Cheers,<br>
> > <br>
> > Richard<br>
> > <br>
> > <br>
> > <br>
> > -- <br>
> > _______________________________________________<br>
> > Openembedded-core mailing list<br>
> > <a href="mailto:Openembedded-core@lists.openembedded.org" target="_blank">Openembedded-core@lists.openembedded.org</a><br>
> > <a href="http://lists.openembedded.org/mailman/listinfo/openembedded-core" rel="noreferrer" target="_blank">http://lists.openembedded.org/mailman/listinfo/openembedded-core</a><br>
> <br>
> -- <br>
> Martin 'JaMa' Jansa jabber: <a href="mailto:Martin.Jansa@gmail.com" target="_blank">Martin.Jansa@gmail.com</a><br>
<br>
<br>
<br>
-- <br>
Martin 'JaMa' Jansa jabber: <a href="mailto:Martin.Jansa@gmail.com" target="_blank">Martin.Jansa@gmail.com</a><br>
</blockquote></div>