Hi,

This is amazingly helpful!! Thank you!

On Tue, Nov 5, 2024, 9:34 AM Efraim Flashner <efraim@flashner.co.il> wrote:

> 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
>