[yocto] Why can diffsigs take sometimes really looooong?

[Uwe Geuder]

Thanks for your reply!

On Sun, Jul 15, 2018 at 1:38 PM, Richard Purdie  wrote:
> On Fri, 2018-07-13 at 19:18 +0300, Uwe Geuder wrote:
>> At times I find the diffsigs command useful/educational to understand
>> what is going on in my build.
>>
>> $ bitbake-diffsigs -t myimage do_image
>>
>> Often the result is shown in no time. However, recently I got some
>> cases were it takes 150 (!) minutes to show a simple difference (1
>> line
>> changed in do_install of systemd).
>>
>> In comparision building after that change (with sstate) takes some 10
>> minutes. And building everything from scratch (no sstate) takes just
>> a
>> bit over 50 minutes on the same machine.
>>
>> Of course the build can make good use of my 8 cores / 16 threads,
>> whereas diffsigs seems to run in only 1 core. Still, shouldn't every
>> build calculate all the dependencies, so running diffsigs should only
>> be
>> a small fraction of that work?
>>
>> Is there a natural explanation why diffsigs can sometimes be so slow?
>> Just curious to understand what is going on there.
>>
>> I am on Rocko 2.4.3 if that makes a difference.
>
> Is your sstate directory on something slow like NFS?
>

No, it is on the same ext4 as the rest of my build area. Backed by an
Intel NVMe flash drive, so hopefully that is of reasonable quality...

Here is the output of the time command from a new "record" diffsigs run
shortly after my first posting

> real    244m8.594s
> user    137m21.897s
> sys     8m17.606s

So there is already more than 2 hours of CPU usage. Because diffsigs
seems to be single threaded, that is a lower bound even with the best
filesystem/disk.

This build environment has been in use in development work for a couple
of days. So there are many different signatures. But that should not
make any significant difference if I compare just the 2 last ones,
should it?

When I had such a long run for the first time I first thought I had run
in an endless loop. strace showed that the same files were opened again
and again. However, in the end the command completed. I haven't made an
effort yet to understand the pattern how it opens these files.

For clean builds with no previous sstate I need "only" something like

> real	54m53.939s
> user 3268446 - 103936 = 3164510 = 527m25.10s
> system 820431 - 1345 = 136m30.86s

(These numbers are from overlayfs over ext4 on the same disk. Don't have
any numbers without the additional overlayfs handy right now. According
to experience the additional overlayfs leads to very similar wall times,
just significant extra system CPU time)


Regards,

Uwe Geuder
Neuro Event Labs Oy
Tampere, Finland
uwe.gexder at neuroeventlabs.com (Bot check: fix one obvious typo)