Hello!

As reported on guix-devel, ‘guix weather’ has become extremely slow.
Specifically, in the narinfo-fetching phase, it runs at 100% CPU, even
though that part should be network-bound (pipelined HTTP GETs).

A profile of the ‘report-server-coverage’ call would show this:

--8<---------------cut here---------------start------------->8---
%     cumulative   self             
time   seconds     seconds  procedure
 62.50      1.06      1.06  fluid-ref*
  6.25      0.11      0.11  regexp-exec
  3.13      0.05      0.05  ice-9/boot-9.scm:1738:4:throw
  2.08      0.04      0.04  string-index
  2.08      0.04      0.04  write
  1.04    568.08      0.02  ice-9/boot-9.scm:1673:4:with-exception-handler
  1.04      0.02      0.02  %read-line
  1.04      0.02      0.02  guix/ci.scm:78:0:json->build
  1.04      0.02      0.02  string-append
--8<---------------cut here---------------end--------------->8---

More than half of the time spent in ‘fluid-ref*’—sounds fishy.

Where does that that call come from?  There seems to be a single caller,
in boot-9.scm:

    (define* (raise-exception exn #:key (continuable? #f))
      (define (capture-current-exception-handlers)
        ;; FIXME: This is quadratic.
        (let lp ((depth 0))
          (let ((h (fluid-ref* %exception-handler depth)))
            (if h
                (cons h (lp (1+ depth)))
                (list fallback-exception-handler)))))
      ;; …
      )

We must be abusing exceptions somewhere…

Indeed, there’s one place on the hot path where we install exception
handlers: in ‘http-multiple-get’ (from commit
205833b72c5517915a47a50dbe28e7024dc74e57).  I don’t think it’s needed,
is it?  (But if it is, let’s find another approach, this one is
prohibitively expensive.)

A simple performance test is:

  rm -rf ~/.cache/guix/substitute/
  time ./pre-inst-env guix weather $(guix package -A|head -500| cut -f1)

After removing this ‘catch’ in ‘http-multiple-get’, the profile is
flatter:

--8<---------------cut here---------------start------------->8---
%     cumulative   self             
time   seconds     seconds  procedure
  8.33      0.07      0.07  string-index
  8.33      0.07      0.07  regexp-exec
  5.56      0.05      0.05  anon #x154af88
  5.56      0.05      0.05  write
  5.56      0.05      0.05  string-tokenize
  5.56      0.05      0.05  read-char
  5.56      0.05      0.05  set-certificate-credentials-x509-trust-data!
  5.56      0.05      0.05  %read-line
--8<---------------cut here---------------end--------------->8---

There’s also this ‘call-with-connection-error-handling’ call in (guix
substitute), around an ‘http-multiple-get’ call, that may not be
justified.

Attached is a diff of the tweaks I made to test this.

WDYT, Chris?

Ludo’.