Re: [bitbake-devel] regression of 'world' performance?

[Richard Purdie <richard.purdie@linuxfoundation.org>]

On Fri, 2024-02-09 at 16:23 +0100, Alexander Kanavin wrote:
> > I have observed something similar and brought it up in last dev call as well
> > one suggestion was to disable hash equivalence, which I did, it does not change
> > a lot which could be attributed to hash equivalence or otherwise, I have also
> > tried different python versions on the host but that did not change
> > anything either.
> > I am still looking for more ways to narrow it down.
> 
> I finally got to look at this, and yes I think there is a nasty
> quadratic growth in bitbake. Details:
> 
> 1. How to reproduce: set up a plain build with empty sstate and
> default config, enabling meta-oe layers:
> 
> BBLAYERS ?= " \
>   /srv/work/alex/poky/meta \
>   /srv/work/alex/poky/meta-poky \
>   /srv/work/alex/poky/meta-yocto-bsp \
>   /srv/work/alex/meta-openembedded/meta-oe \
>   /srv/work/alex/meta-openembedded/meta-python \
>   /srv/work/alex/meta-openembedded/meta-networking \
>   /srv/work/alex/meta-openembedded/meta-filesystems \
>   /srv/work/alex/meta-openembedded/meta-gnome \
>   /srv/work/alex/meta-openembedded/meta-xfce \
>   /srv/work/alex/meta-openembedded/meta-multimedia \
>   "
> 
> Then run 'bitbake world'. No tasks are going to start for minutes and
> minutes and minutes: it will seemingly remain stuck at
> NOTE: Executing Tasks
> 
> 2. What is happening? After adding some debugging to
> bitbake/lib/bb/runqueue.py, I found:
> 
> RunQueueExecute's execute() is being called over and over and over,
> thousands of times. Each new call into it is slower than the next. No
> tasks are actually run.
> 
> execute() contains this loop:
> 
>             for nexttask in self.sorted_setscene_tids:
> 
> self.sorted_setscene_tids contains about 28000 entries in each
> execution of the loop.
> 
> Every time the loop is executed, it iterates over those 28000 entries,
> stopping one item further along in that list, in this block of code:
> 
>                     if nexttask in self.sqdata.outrightfail:
>                         logger.debug2('No package found, so skipping
> setscene task %s', nexttask)
>                         self.sq_task_failoutright(nexttask)
>                         return True
> 
> Then the loop restarts from the beginning, etc. Until it reaches the
> end of self.sorted_setscene_tids. In the process, items in the list
> are checked 28000^2-ish times (1+2+...+28000), before anything even
> starts.
> 
> 3. What to do?
> 
> Of course I have no idea what I'm doing; this code is extremely
> delicate :) Nevertheless, I replaced 'return True' in that block with
> 'continue', with massive improvement to when tasks actually start
> running (after printing 'NOTE: Executing Tasks') and no obvious
> immediate fails.
> 
> Before the change it was still stuck in that loop after 60 minutes
> (!), and after the change it proceeded to the tasks after just two
> minutes (!).
> 
> There are other 'return True's inside that loop that could also be
> contributing to quadratic behaviour, I didn't check those.
> 
> Hopefully this helps.

There is effectively a "main loop" within bitbake, so execute() is
meant to do one thing, then return, on the assumption it will get
called straight back.

Since the "continue" makes it faster, it suggests something else
somewhere is being slow and as you mention, there are a load of other
code paths which could also have a similar issue.

Could you find out where the actual delay is, since it should just hget
a call straight back. Or is it the loop iteration itself which is slow?
Even with 20k entries, you'd think python would handle that.

Finally, I'd also mention the -P option to bitbake, then having a look
at the various profile*.log files. One of them should be for cooker and
should clearly show where it is spending the time.

Cheers,

Richard