Subject: Re: bug#28731: guix weather backtrace on https://mirror.guixsd.org
From: [email-masked] (Ludovic Courtès)
To: Jan Nieuwenhuizen <[email-masked]>
Cc: [email-masked]
Date: Thu, 26 Oct 2017 00:29:15 -0700
List-Id: <debbugs-submit.debbugs.gnu.org>

Hi,

Jan Nieuwenhuizen <[email-masked]> skribis:

> Running guix weather on latest master* gives me
>
> computing 6,224 package derivations for x86_64-linux...
> looking for 6,486 store items on https://mirror.hydra.gnu.org...
> updating list of substitutes from 'https://mirror.hydra.gnu.org'...   0.0%Backtrace:
>           10 (primitive-load "/home/janneke/bin/guix")
> In guix/ui.scm:
>   1375:12  9 (run-guix-command _ . _)
> In ice-9/boot-9.scm:
>     837:9  8 (catch _ _ #<procedure 7fecbd7209d8 at guix/ui.scm:451:2 (key c)> _)
>     837:9  7 (catch _ _ #<procedure 7fecbd7209f0 at guix/ui.scm:539:6 (key proc format-string format-args . r…> …)
> In srfi/srfi-1.scm:
>     640:9  6 (for-each #<procedure 109b57c0 at guix/scripts/weather.scm:228:16 (server)> ("https://mirror.hyd…"))
> In guix/scripts/weather.scm:
>     99:17  5 (call-with-time _ #<procedure c734780 at guix/scripts/weather.scm:113:2 (time narinfos)>)
> In unknown file:
>            4 (_ #<procedure 109b5580 at guix/scripts/weather.scm:113:2 ()> #<procedure list _> #<undefined>)
> In guix/scripts/substitute.scm:
>    711:23  3 (lookup-narinfos _ _)
>    664:23  2 (fetch-narinfos _ _)
>     567:8  1 (http-multiple-get #<<uri> scheme: https userinfo: #f host: "mirror.hydra.gnu.org" port: #f path…> …)
> In unknown file:
>            0 (put-bytevector #<input-output: string ae694d0> #vu8(71 69 84 32 47 57 48 100 104 50 114 54 107 …) …)
>
> ERROR: In procedure put-bytevector:
> ERROR: Throw to key `gnutls-error' with args `(#<gnutls-error-enum Resource temporarily unavailable, try again.> write_to_session_record_port)'.

I believe this is fixed by this commit:

  http://git.savannah.gnu.org/cgit/guix.git/commit/?id=d213cc8c7f085428e3c64243b0d163423e4bb5f6

The crux of the problem was that we were sending too many requests at
once, and for some reason the server would close the connection
prematurely (in HTTPS, not HTTP).  It didn’t make sense to send too many
connections at once anyway, because the server won’t accept that many
(see ‘keepalive_requests’ in nginx), so the commit above sets a maximum.

The problem could be reproduced with:

--8<---------------cut here---------------start------------->8---
(use-modules (guix scripts substitute)
             (guix build utils)
             (web request)
             (web uri)
             (srfi srfi-1)
             (gnutls))

(define base-url
  (or (getenv "URL")
      "https://mirror.hydra.gnu.org"))

(define base-uri
  (string->uri base-url))

(define index.html
  (build-request
   (string->uri (string-append base-url
                               "/nix-cache-info"
                               ;; "/eeeeeeeeeeeeeeeeeeeeeeeeeeeeeeee.narinfo"
                               ;; "/yihvhxv3xyyvl1m2cy1lnf1lyi9h76fk.narinfo"
                               ))))

(define http-multiple-get
  (@@ (guix scripts substitute) http-multiple-get))

;; (set-log-level! 5)
;; (set-log-procedure! (lambda (level message)
;;                       (display message)))

(let ((requests (make-list 100000 index.html)))
  (http-multiple-get base-uri
                     (lambda (req resp port result)
                       (dump-port port (%make-void-port "w"))
                       (cons 'x result))
                     '()
                     requests))
--8<---------------cut here---------------end--------------->8---

Thanks,
Ludo’.