Re: Possible useful guix package performance data

[Efraim Flashner <efraim@flashner.co.il>]

[-- Attachment #1: Type: text/plain, Size: 4379 bytes --]

On Mon, Nov 04, 2024 at 11:22:01PM +0100, Ludovic Courtès wrote:
> Hi,
> 
> "Thompson, David" <dthompson2@worcester.edu> skribis:
> 
> > What are you trying to measure, exactly? The data collected is about a
> > single thread of a Guile process, but `guix package -i` involves
> > interaction with the Guix build daemon, waiting for downloads, etc.
> > These things are outside the scope of what statprof is tracing.
> > Anything that involves reaching out to the internet is going to make
> > for an unreliable benchmark. I'm not actively working on Guix tools
> > but I don't see anything immediately actionable from the collected
> > data. I think getting some more clarity around the goal is necessary
> > in order to know what to profile and how.
> 
> Unless you’re specifically looking at performance of substitutes, I
> recommend looking at profiles when using ‘--no-substitutes’; I would
> also pass ‘--no-grafts’, to make sure you’re really looking at the core
> of the whole package-to-derivation mechanism.
> 
> You may also want to check the ‘GUIX_PROFILING’ environment variable,
> from the (guix profiling) module.  That can give a useful overview such
> as the number of remote procedure calls (RPCs) made to guix-daemon and
> the hit rate of the “object cache”:
> 
> --8<---------------cut here---------------start------------->8---
> $ GUIX_PROFILING="gc rpc object-cache" guix build hello -d --no-grafts --no-substitutes
> /gnu/store/79dhya6sngg4rf53m1cyxlhn8y4pnw2n-hello-2.12.1.drv
> Object Cache:
>   fresh caches:    16
>   lookups:       5042
>   hits:          4596 (91.2%)
>   cache size:     445 entries
> Remote procedure call summary: 382 RPCs
>   built-in-builders              ...     1
>   add-to-store/tree              ...     3
>   add-to-store                   ...    48
>   add-text-to-store              ...   330
> Garbage collection statistics:
>   heap size:        72.27 MiB
>   allocated:        100.29 MiB
>   GC times:         13
>   time spent in GC: 0.42 seconds (45% of user time)
> --8<---------------cut here---------------end--------------->8---
> 
> Keep in mind that the figures we’re looking at here are largely
> dependent of the package graph being processed (that of ‘hello’ here).
> So it also makes sense to look at the size of the package graph in
> question first (in the case of ‘hello’, it’s probably fine, but let’s
> say when Rust packages are in the loop, the graph might be much bigger
> than needed/expected).

Did someone say rust?

I made a manifest of the packages that use the cargo-build-system and
aren't rust-* packages, or which have rust as an input. 102 packages:

$ GUIX_PROFILING="gc rpc object-cache" ./pre-inst-env guix build \
        --no-grafts -m ./etc/teams/rust/rusty-packages.scm \
        --no-substitutes -d

Object Cache:
  fresh caches:    20
  lookups:      361239
  hits:         351403 (97.3%)
  cache size:    9835 entries
Remote procedure call summary: 11780 RPCs
  built-in-builders              ...     1
  add-to-store/tree              ...    33
  add-to-store                   ...   329
  add-text-to-store              ... 11417
Garbage collection statistics:
  heap size:        223.68 MiB
  allocated:        1332.86 MiB
  GC times:         34
  time spent in GC: 7.10 seconds (33% of user time)

I also did a run with hello to get a comparison on the same machine:

$ GUIX_PROFILING="gc rpc object-cache" ./pre-inst-env guix build hello -d --no-grafts --no-substitutes
/gnu/store/1y2k2jkb8w67mcwj42b8bxjv3yshk5kf-hello-2.12.1.drv
Object Cache:
  fresh caches:    16
  lookups:       5042
  hits:          4596 (91.2%)
  cache size:     445 entries
Remote procedure call summary: 382 RPCs
  built-in-builders              ...     1
  add-to-store/tree              ...     3
  add-to-store                   ...    48
  add-text-to-store              ...   330
Garbage collection statistics:
  heap size:        79.57 MiB
  allocated:        122.75 MiB
  GC times:         14
  time spent in GC: 0.94 seconds (69% of user time)

-- 
Efraim Flashner   <efraim@flashner.co.il>   אפרים פלשנר
GPG key = A28B F40C 3E55 1372 662D  14F7 41AA E7DC CA3D 8351
Confidentiality cannot be guaranteed on emails sent or received unencrypted

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]