Speed up `bst shell` command

[BuildStream-Migration-Bot]

See original issue on GitLab
In GitLab by [Gitlab user @TheRealMichaelCatanzaro] on Mar 10, 2018, 19:13

bst shell is currently much too slow. It would be nice to aggressively attempt to speed things up. I know this is never going to be instantaneous, like jhbuild shell, but I hope we we can do a lot better here.

For instance:

$ bst shell --build core/epiphany.bst
[--:--:--][][] START   Loading pipeline
[00:00:00][][] SUCCESS Loading pipeline
[--:--:--][][] START   Resolving pipeline
[00:00:00][][] SUCCESS Resolving pipeline
[--:--:--][][] START   Resolving cached state
[00:01:35][][] SUCCESS Resolving cached state
[--:--:--][][] START   Staging dependencies
[--:--:--][????????][ main:core/epiphany.bst             ] WARNING Non-whitelisted overlaps detected

    Staged files overwrite existing files in staging area:
    /usr/bin/gtkdoc-check: core-deps/gtk-doc.bst is not permitted to overlap other elements, order core-deps/gtk-doc.bst above base/base-configure.bst 
    /usr/bin/gtkdoc-depscan: core-deps/gtk-doc.bst is not permitted to overlap other elements, order core-deps/gtk-doc.bst above base/base-configure.bst 
    /usr/bin/gtkdoc-fixxref: core-deps/gtk-doc.bst is not permitted to overlap other elements, order core-deps/gtk-doc.bst above base/base-configure.bst 
    /usr/bin/gtkdoc-mkdb: core-deps/gtk-doc.bst is not permitted to overlap other elements, order core-deps/gtk-doc.bst above base/base-configure.bst 
    /usr/bin/gtkdoc-mkhtml: core-deps/gtk-doc.bst is not permitted to overlap other elements, order core-deps/gtk-doc.bst above base/base-configure.bst 
    /usr/bin/gtkdoc-mkman: core-deps/gtk-doc.bst is not permitted to overlap other elements, order core-deps/gtk-doc.bst above base/base-configure.bst 
    /usr/bin/gtkdoc-mkpdf: core-deps/gtk-doc.bst is not permitted to overlap other elements, order core-deps/gtk-doc.bst above base/base-configure.bst 
    /usr/bin/gtkdoc-rebase: core-deps/gtk-doc.bst is not permitted to overlap other elements, order core-deps/gtk-doc.bst above base/base-configure.bst 
    /usr/bin/gtkdoc-scan: core-deps/gtk-doc.bst is not permitted to overlap other elements, order core-deps/gtk-doc.bst above base/base-configure.bst 
    /usr/bin/gtkdoc-scangobj: core-deps/gtk-doc.bst is not permitted to overlap other elements, order core-deps/gtk-doc.bst above base/base-configure.bst 
    /usr/bin/gtkdocize: core-deps/gtk-doc.bst is not permitted to overlap other elements, order core-deps/gtk-doc.bst above base/base-configure.bst 
    /usr/lib/cmake/GtkDoc/GtkDocConfig.cmake: core-deps/gtk-doc.bst is not permitted to overlap other elements, order core-deps/gtk-doc.bst above base/base-configure.bst 
    /usr/lib/cmake/GtkDoc/GtkDocConfigVersion.cmake: core-deps/gtk-doc.bst is not permitted to overlap other elements, order core-deps/gtk-doc.bst above base/base-configure.bst 
    /usr/lib/cmake/GtkDoc/GtkDocScanGObjWrapper.cmake: core-deps/gtk-doc.bst is not permitted to overlap other elements, order core-deps/gtk-doc.bst above base/base-configure.bst 
    /usr/share/aclocal/gtk-doc.m4: core-deps/gtk-doc.bst is not permitted to overlap other elements, order core-deps/gtk-doc.bst above base/base-configure.bst 
    /usr/share/gtk-doc/data/devhelp2.xsd: core-deps/gtk-doc.bst is not permitted to overlap other elements, order core-deps/gtk-doc.bst above base/base-configure.bst 
    /usr/share/gtk-doc/data/devhelp2.xsl: core-deps/gtk-doc.bst is not permitted to overlap other elements, order core-deps/gtk-doc.bst above base/base-configure.bst 
    /usr/share/gtk-doc/data/gtk-doc.flat.make: core-deps/gtk-doc.bst is not permitted to overlap other elements, order core-deps/gtk-doc.bst above base/base-configure.bst 
    /usr/share/gtk-doc/data/gtk-doc.make: core-deps/gtk-doc.bst is not permitted to overlap other elements, order core-deps/gtk-doc.bst above base/base-configure.bst 
    Message contains 6766 additional lines

[00:00:12][][] SUCCESS Staging dependencies
[--:--:--][][] START   Integrating sandbox
[--:--:--][593e35e8][ main:base.bst                      ] STATUS  Running integration command

    ldconfig

[--:--:--][593e35e8][ main:base.bst                      ] STATUS  Running integration command

    PKGSYSTEM_ENABLE_FSYNC=0 update-mime-database /usr/share/mime

[--:--:--][593e35e8][ main:base.bst                      ] STATUS  Running integration command

    update-desktop-database -v

Search path is now: [/usr/local/share/applications, /usr/share/applications]
Could not create cache file in "/usr/local/share/applications": Error opening directory ?/usr/local/share/applications?: No such file or directory
File "/usr/share/applications/gtk3-widget-factory.desktop" lacks MimeType key
File "/usr/share/applications/gcr-prompter.desktop" lacks MimeType key
File "/usr/share/applications/python3.6.desktop" lacks MimeType key
File "/usr/share/applications/geoclue-where-am-i.desktop" lacks MimeType key
File "/usr/share/applications/geoclue-demo-agent.desktop" lacks MimeType key
File "/usr/share/applications/gtk3-demo.desktop" lacks MimeType key
File "/usr/share/applications/texdoctk.desktop" lacks MimeType key
File "/usr/share/applications/gtk3-icon-browser.desktop" lacks MimeType key
File "/usr/share/applications/python2.7.desktop" lacks MimeType key
[--:--:--][ec9dc658][ main:core-deps/glib.bst            ] STATUS  Running integration command

    glib-compile-schemas /usr/share/glib-2.0/schemas

Warning: Schema “org.gnome.crypto.pgp” has path “/desktop/gnome/crypto/pgp/”.  Paths starting with “/apps/”, “/desktop/” or “/system/” are deprecated.
Warning: Schema “org.gnome.system.locale” has path “/system/locale/”.  Paths starting with “/apps/”, “/desktop/” or “/system/” are deprecated.
Warning: Schema “org.gnome.system.proxy” has path “/system/proxy/”.  Paths starting with “/apps/”, “/desktop/” or “/system/” are deprecated.
Warning: Schema “org.gnome.system.proxy.http” has path “/system/proxy/http/”.  Paths starting with “/apps/”, “/desktop/” or “/system/” are deprecated.
Warning: Schema “org.gnome.system.proxy.https” has path “/system/proxy/https/”.  Paths starting with “/apps/”, “/desktop/” or “/system/” are deprecated.
Warning: Schema “org.gnome.system.proxy.ftp” has path “/system/proxy/ftp/”.  Paths starting with “/apps/”, “/desktop/” or “/system/” are deprecated.
Warning: Schema “org.gnome.system.proxy.socks” has path “/system/proxy/socks/”.  Paths starting with “/apps/”, “/desktop/” or “/system/” are deprecated.
[--:--:--][81d1654d][ main:core-deps/gdk-pixbuf.bst      ] STATUS  Running integration command

    gdk-pixbuf-query-loaders --update-cache

[--:--:--][0566cf06][ main:core-deps/gtk+-3.bst          ] STATUS  Running integration command

    for dir in /usr/share/icons/*; do
      if test -f $dir/index.theme; then
        gtk-update-icon-cache --quiet $dir
      fi
    done

[--:--:--][0566cf06][ main:core-deps/gtk+-3.bst          ] STATUS  Running integration command

    gtk-query-immodules-3.0 --update-cache

[00:00:14][][] SUCCESS Integrating sandbox
[--:--:--][][] START   Staging sources
[00:00:00][][] SUCCESS Staging sources
[--:--:--][????????][ main:core/epiphany.bst             ] STATUS  Running command

    bash --noprofile --norc -i

Here we spent:

• 1m35s resolving cached state
• 12s staging dependencies
• 14s integrating sandbox

Looks like "resolving cached state" is clearly the first thing to focus on.

[BuildStream-Migration-Bot]

In GitLab by [Gitlab user @tristanvb] on Mar 11, 2018, 09:36

bst shell is currently much too slow. It would be nice to aggressively attempt to speed things up. I know this is never going to be instantaneous, like jhbuild shell, but I hope we we can do a lot better here.

Very much agreed that we need to speed things up here.

At first reading this I thought this might be a regression of #140 coming back, but that is not the case.

The problem with workspaces here is that, when considering incremental builds of them we had to choose between:

• Rebuild the workspace every single time, and calculate the cache key at the end
• Calculate the cache key first; and consider that it is only valid if it is indeed cached

The latter was the less of two evils.

Workspace cache key calculation is an aggressive checksum, so the more open workspaces you have, the more directories you will be checksumming recursively at startup.

Other than this; I would like to split up integration commands into multiple domains, we just haven't gotten around to this yet:

• Some integration commands need to be run before a build, this is the case for querying pixbuf loaders, or running ldconfig
• Some integration commands dont really need to be run until something needs to run

Unfortunately, while the above separation would significantly speed up the build; it will not solve bst shell, because we would have to assume that you want, say, the icon cache to be updated (which is only untrue for a build).

[BuildStream-Migration-Bot]

In GitLab by [Gitlab user @tristanvb] on Mar 11, 2018, 10:06

The problem with workspaces here is that, when considering incremental builds of them we had to choose between:

• Rebuild the workspace every single time, and calculate the cache key at the end
• Calculate the cache key first; and consider that it is only valid if it is indeed cached

The above is not entirely accurate, or rather leaves something important out which I missed in my previous comment.

The bottleneck in calculating a cache key for a workspace build is checksumming the sources particularly.

There has been some discussion about allowing Source implementations participate in the process of calculating a cache key for the sources in a workspace.

This is a little difficult to implement, and unfortunately cannot be done reliably.

For instance, if we were to rely on git diff for git sources; then we would only be able to catch differences for source files which are under revision control.

The UX would be:

• I want to hack on foo
• I open a workspace for foo
• Build
  • it builds
• I start hacking on a new source file
• Build
  • it builds, because I had to modify Makefile.am
• Now I modify the file I added
• Build
  • The workspaced element is not rebuilt, because nothing has changed

Possibly the tradeoff of dealing with "This does not work as expected" by constantly informing people "You need to git add something to the repo if you want the change to be noticed" vs "Faster workspace builds" is worthwhile, though, and we should look into doing this.

[BuildStream-Migration-Bot]

In GitLab by [Gitlab user @juergbi] on Mar 11, 2018, 10:42

I see slow 'resolving cached state' here even without open workspaces. The profile tells me that the vast majority of time is spent in loading meta/artifact.yaml to retrieve the strong cache key. This is with --no-strict where it takes 1min 19s. With --strict it only takes 2s (no loading of meta/artifact.yaml).

We could probably improve this significantly by splitting the metadata file to avoid having to load the keys of the dependencies just for resolving the cached state. This would be simple but require an artifact version bump. While we're at it we could drop the useless foo.bst: false entries for non-workspaced dependencies.

[BuildStream-Migration-Bot]

In GitLab by [Gitlab user @juergbi] on Mar 11, 2018, 11:00

For instance, if we were to rely on git diff for git sources; then we would only be able to catch differences for source files which are under revision control.

One option would be to also take unversioned files into account but only those that are not in .gitignore or equivalent. With a well-maintained .gitignore file this should allow almost the same performance advantage without the issue you've described.

[BuildStream-Migration-Bot]

In GitLab by [Gitlab user @TheRealMichaelCatanzaro] on Mar 11, 2018, 16:15

Some considerations, in the specific case of WebKit:

• We don't have a .gitignore, because the git repo is just a mirror of our SVN project.
• The project is configured to build from a tarball by default (although here I do have it pointing to a local workspace).
• Buildstream performs an out-of-tree build in a separate build directory, so it's guaranteed that no generated files will exist in the source tree.

[BuildStream-Migration-Bot]

In GitLab by [Gitlab user @TheRealMichaelCatanzaro] on Apr 10, 2018, 09:13

$ bst shell --build core/epiphany.bst
[--:--:--][][] START   Loading pipeline
[00:00:02][][] SUCCESS Loading pipeline
[--:--:--][][] START   Resolving pipeline
[00:00:01][][] SUCCESS Resolving pipeline
[--:--:--][][] START   Resolving cached state
[00:05:21][][] SUCCESS Resolving cached state

Missing elements for staging an environment for a shell:
   core/glib-networking.bst

Try building them first

5m21s to enter the shell today (and fail at that, but that's my fault)... it's probably slower because we're using the Freedesktop SDK junction now.

[BuildStream-Migration-Bot]

In GitLab by [Gitlab user @tristanvb] on Apr 10, 2018, 14:27

This Resolving cached state step seems to be ridiculously long indeed.

[BuildStream-Migration-Bot]

In GitLab by [Gitlab user @TheRealMichaelCatanzaro] on Apr 10, 2018, 20:40

I can reproduce this whenever I want:

$ bst shell --build core/epiphany.bst
[--:--:--][][] START   Loading pipeline
[00:00:02][][] SUCCESS Loading pipeline
[--:--:--][][] START   Resolving pipeline
[00:00:01][][] SUCCESS Resolving pipeline
[--:--:--][][] START   Resolving cached state
[00:05:27][][] SUCCESS Resolving cached state

Missing elements for staging an environment for a shell:
   core-deps/WebKitGTK+.bst

Try building them first

In combination with #295 it makes development with Buildstream totally impractical for me. :(

[BuildStream-Migration-Bot]

In GitLab by [Gitlab user @tristanvb] on Apr 11, 2018, 14:16

mentioned in commit f7a4b594531ed37b4157757b5530ddeb1ded565f

[BuildStream-Migration-Bot]

In GitLab by [Gitlab user @tristanvb] on Apr 11, 2018, 15:10

mentioned in commit 6ad88ec

[BuildStream-Migration-Bot]

In GitLab by [Gitlab user @tristanvb] on Apr 11, 2018, 15:35

With !381 merged, I've changed how metadata is structured in artifacts such that it should dramatically improve the load time, as suggested by [Gitlab user @juergbi] in https://gitlab.com/BuildStream/buildstream/issues/294#note_62585246.

A side effect of changing metadata structure in artifacts is that it will cause everything to rebuild once, due to a necessary artifact revision bump.

[Gitlab user @TheRealMichaelCatanzaro], can you please try this again with master and let me know how long it's taking for this Resolving cached state step ?

Sorry it will take a while as everything will need an initial rebuild.

[BuildStream-Migration-Bot]

In GitLab by [Gitlab user @tristanvb] on Apr 12, 2018, 07:28

I think this is improved, after my build; I have:

• Strong keys for the whole freedesktop-sdk project
• Almost all keys for gnome-build-meta's core.bst cached in non-strict mode (weak keys available)

bst --strict show core.bst

[--:--:--][][] START   Loading pipeline
[00:00:02][][] SUCCESS Loading pipeline
[--:--:--][][] START   Resolving pipeline
[00:00:02][][] SUCCESS Resolving pipeline
[--:--:--][][] START   Resolving cached state
[00:00:02][][] SUCCESS Resolving cached state

This still takes 2 seconds, for a pretty large pipeline (inclusive of the junctioned freedesktop-sdk project).

bst --no-strict show core.bst

[--:--:--][][] START   Loading pipeline
[00:00:02][][] SUCCESS Loading pipeline
[--:--:--][][] START   Resolving pipeline
[00:00:02][][] SUCCESS Resolving pipeline
[--:--:--][][] START   Resolving cached state
[00:00:07][][] SUCCESS Resolving cached state

Now resolving the cached state takes 7 seconds, it's a lot more than I would like, and it's absurdly annoying, but it should not be 5 minutes.

We're not quite there yet, we need to optimize this load time a lot more I think in order to not lose the attention of users; maybe some local state caching can help, I'm not sure.

[Gitlab user @TheRealMichaelCatanzaro] Can you confirm the performance improvement ?

[BuildStream-Migration-Bot]

In GitLab by [Gitlab user @TheRealMichaelCatanzaro] on Apr 12, 2018, 21:30

[Gitlab user @tristanvb] can you help me bypass this error:

[00:00:01] FAILURE [core/glib-networking.bst]: Artifact missing for gnome/core-glib-networking/f6f2673507e8ff445b488ca2990d2d18b2b43fffb97adafe34b9ff6252839e3f

I cleaned my ~/.cache/buildstream trying to get a fresh start, and now I'm stuck. I don't see any way to build glib-networking again. I have the same problem for WebKitGTK+ as well. Workspaces all closed already.

[BuildStream-Migration-Bot]

In GitLab by [Gitlab user @tristanvb] on Apr 13, 2018, 06:12

Hmmm, I have no idea how this happened, the above message is coming from bst --no-strict build code/glib-networking.bst ?

This seems very strange, and you have BuildStream master ?

Currently I have a built core/glib-networking.bst which I can shell into...

As a side note, I would recommend only clearing ~/.cache/buildstream/artifacts rather than redownloading all the source code as well (but seems too late for this).