[bug#50384] Optimise search-patch (reducing I/O)

Hi guix!

The attached patch series optimises the G-exp compiler for
local-file, by avoiding interning the file if it's already
in the store, but only if the hash is known in advance.
To take advantage of this, 'search-patch' has been modified
to compute the hash at expansion time.

The cost of this optimisation is a little additional
complexity, and computing derivations theoretically becomes
a little more expensive when the patch isn't already in
the store (1 call to 'stat' per non-yet-interned patch).

If you want to test this patch series for performance,
do _not_ run ./pre-inst-env guix, instead use
"guix pull --url=$PWD --branch=...", because the guix
from the checkout performs more 'lstat' calls than
an ‘user’ guix from "guix pull".

I'll show the patch series decreases the number of syscalls
below, using the 'strace' command.  Use 'strace -c' to gather
some statistics:

# Run it twice for a hot cache.  Ignore the output of the first run.
$ strace -c ./the-optimised-guix/bin/guix build -d pigx --no-grafts
$ strace -c ./the-optimised-guix/bin/guix build -d pigx --no-grafts
#
$ strace -c guix build -d pigx --no-grafts
$ strace -c guix build -d pigx --no-grafts

I've selected some syscalls from the output that seemed relevant
and formatted the call count in a table

              optimised         unoptimised     result of optimisation:
         stat  3865             3712            + 4.1%
         lstat 119              321             -62.9%
         fstat 59               59              unchanged
         read  17303            17688           - 2.2%
        write  6741             6767            - 1.9%
       openat  885              1076            -17.8%
       readlink 14              16              -12.5%
       -------
       total    28886           32539           -11.2%

Almost all syscalls are now called less (-11.2% in total),
which is good.  The exception is 'stat'.

Because 'search-path' is now being called less often
(only when the patch isn't in the store), the number
of 'stat' calls decreases.  However, 'local-file-compiler'
now calls 'stat' more (one or two times per patch).  I think
it's worth it though, because:

   (1) the second 'stat' is on the same file as the first 'stat',
       so presumably the kernel has cached the result, so no need
       to wait for I/O to complete the second time (there's a context
       switch though).  So ignoring the context switch cost,
       there are only ‘effectively’ +2.1% extra calls to 'stat'.

   (2) the total decrease of -11.2% syscalls

Now, what about the actual "time to derivation"?
First, let's time "guix build -d pigx --no-grafts" to get some raw numbers
on guix before the optimisation:

     time guix build -d pigx --no-grafts
     # repeated four times, first output is discarded
     # to eliminate hot/cold cache differences
     /gnu/store/03vmq94ckxfx6c4rc9zh745yy63n5i5m-pigx-0.0.3.drv
     real       0m13,470s
     user       0m13,526s
     sys        0m0,573s
     /gnu/store/03vmq94ckxfx6c4rc9zh745yy63n5i5m-pigx-0.0.3.drv
     real       0m13,582s
     user       0m13,639s
     sys        0m0,568s
     /gnu/store/03vmq94ckxfx6c4rc9zh745yy63n5i5m-pigx-0.0.3.drv
     real       0m13,834s
     user       0m13,901s
     sys        0m0,556s

Average numbers:
     real      0m13,629s
     user      0m13,689s
     sys       0m0,566s

After the optimisation:
      time ./the-optimised-guix/bin/guix build -d pigx --no-grafts
      /gnu/store/fq6x8d2vcm6sbjkimg7g8kcgb4c5xv1b-pigx-0.0.3.drv
      real      0m14,150s
      user      0m13,979s
      sys       0m0,685s
      /gnu/store/fq6x8d2vcm6sbjkimg7g8kcgb4c5xv1b-pigx-0.0.3.drv
      real      0m13,781s
      user      0m13,697s
      sys       0m0,580s
      /gnu/store/fq6x8d2vcm6sbjkimg7g8kcgb4c5xv1b-pigx-0.0.3.drv
      real      0m14,247s
      user      0m14,160s
      sys       0m0,548s

The numbers are higher somehow after the optimisations?
Even the 'sys' time is higher, even though there are less syscalls?
I re-ran the time commands, and got a decrease in 'real' time this time.

  /gnu/store/fq6x8d2vcm6sbjkimg7g8kcgb4c5xv1b-pigx-0.0.3.drv
  real  0m13,304s
  user  0m13,146s
  sys   0m0,609s
  /gnu/store/fq6x8d2vcm6sbjkimg7g8kcgb4c5xv1b-pigx-0.0.3.drv
  real  0m12,132s
  user  0m11,940s
  sys   0m0,589s
  /gnu/store/fq6x8d2vcm6sbjkimg7g8kcgb4c5xv1b-pigx-0.0.3.drv
  real  0m13,716s
  user  0m13,723s
  sys   0m0,529s

The output of "time ..." seems inconclusive
(can possibly be attributed to things like CPU frequency changing?),
but the decrease in syscall counts seems quite nice to me.

Feel free to run your own tests!

Greetings,
Maxime.

Hi!

Some initial comments…

Maxime Devos <maximedevos@telenet.be> skribis:

> +++ b/guix/gexp.scm
> @@ -531,13 +531,37 @@ appears."
>  (define-gexp-compiler (local-file-compiler (file <local-file>) system target)
>    ;; "Compile" FILE by adding it to the store.
>    (match file
> -    (($ <local-file> file (= force absolute) name sha256 recursive? select?)
> -     ;; Canonicalize FILE so that if it's a symlink, it is resolved.  Failing
> -     ;; to do that, when RECURSIVE? is #t, we could end up creating a dangling
> -     ;; symlink in the store, and when RECURSIVE? is #f 'add-to-store' would
> -     ;; just throw an error, both of which are inconvenient.
> -     (interned-file absolute name
> -                    #:recursive? recursive? #:select? select?))))
> +    ;; Delay computing the absolute file name until 'intern', as this
> +    ;; might be a relatively expensive computation (e.g. if search-patch
> +    ;; is used), especially on a spinning disk.
> +    (($ <local-file> file absolute-promise name sha256 recursive? select?)
> +     (let ()
> +       (define (intern)
> +         ;; Canonicalize FILE so that if it's a symlink, it is resolved.
> +         ;; Failing to do that, when RECURSIVE? is #t, we could end up creating
> +         ;; a dangling symlink in the store, and when RECURSIVE? is #f
> +         ;; 'add-to-store' would just throw an error, both of which are
> +         ;; inconvenient.
> +         (interned-file (force absolute-promise) name
> +                        #:recursive? recursive? #:select? select?))
> +       (if sha256
> +           (let ((path (fixed-output-path name sha256 #:recursive? recursive?)))
> +             ;; If the hash is known in advance and the store already has the
> +             ;; item, there is no need to intern the file.
> +             (if (file-exists? path)
> +                 (mbegin %store-monad
> +                   ;; Tell the GC that PATH will be used, such that it won't
> +                   ;; be deleted.
> +                   ((store-lift add-temp-root) path)
> +                   ;; The GC could have deleted the item before add-temp-root
> +                   ;; completed, so check again if PATH exists.
> +                   (if (file-exists? path)
> +                       (return path)
> +                       ;; If it has been removed, fall-back interning.
> +                       (intern)))
> +                 ;; If PATH does not yet exist, fall back to interning.
> +                 (intern)))
> +           (intern))))))

‘file-exists?’ won’t work when talking to a remote store (e.g.,
GUIX_DAEMON_SOCKET=ssh://…).

‘add-temp-root’ doesn’t throw if the given store item does not exist.
So it could be written like this:

  (if sha256
      (mbegin %store-monad
        (add-temp-root* item)
        (if (valid-path?* item)
            (return item)
            (intern)))
      (intern))

But then, we’d add one RPC for every ‘add-to-store’ RPC corresponding to
a patch (you can set “GUIX_PROFILING=rpc” to see the numbers), which is
not great.

Ludo’.

Maxime Devos <maximedevos@telenet.be> skribis:

> +(define-syntax search-patch
> +  (lambda (s)
> +    "Search the patch FILE-NAME and compute its hash at expansion time
> +if possible.  Return #f if not found."
> +    (syntax-case s ()
> +      ((_ file-name)
> +       (string? (syntax->datum #'file-name))
> +       ;; FILE-NAME is a constant string, so the hash can be computed
> +       ;; in advance.
> +       (let ((patch (try-search-patch (syntax->datum #'file-name))))
> +         (if patch
> +             #`(%local-patch-file file-name #,(file-hash* patch #:select? true))
> +             (begin
> +               (warning (source-properties->location
> +                         (syntax-source #'file-name))
> +                        (G_ "~a: patch not found at expansion time")
> +                        (syntax->datum #'ile-name))
> +               #'(%search-patch file-name)))))
> +      ;; FILE-NAME is variable, so the hash cannot be pre-computed.
> +      ((_ file-name) #'(%search-patch file-name))
> +      ;; search-patch is being used used in a construct like
> +      ;; (map search-patch ...).
> +      (id (identifier? #'id) #'%search-patch))))

It’s clever… but also a bit evil, in that it changes the semantics of
package files in a surprising way.  Modifying foo.patch without
recompiling foo.scm would lead you to still use the old foo.patch, which
can be rather off-putting and error-prone IMO.

To address this, ‘local-file’ could store the inode/mtime + computed
store file name (rather than the SHA256).  ‘local-file-compiler’ would
check whether the actual file has matching inode/mtime before returning
the computed store file name.  Problem is that inode/mtime are
guaranteed to differ once you’ve run “make install”.  :-/


Intuitively, I’d have imagined a cache populated at run time; it would
map, say, file name/inode/mtime to a store file name.  ‘add-to-store’
(or some wrapper above it) would check the cache and return the store
file name directly, unless ‘valid-path?’ says it no longer exists.
Downside is that this would be a per-user cache and you’d still pay the
cost until it’s warm.  Advantage is that you could easily tell whether
it’s stale.

Thoughts?

Ludo’.

I split off the base16 and base32 optimisations
to a separate patch series: 50456@debbugs.gnu.org.