GNU bug report logs - #38411
HTTP pipelining of narinfo requests broken for https://ci.guix.gnu.org

Please note: This is a static page, with minimal formatting, updated once a day.
Click here to see this page with the latest information and nicer formatting.

Package: guix; Severity: serious; Reported by: Ludovic Courtès <ludo@HIDDEN>; dated Thu, 28 Nov 2019 09:23:01 UTC; Maintainer for guix is bug-guix@HIDDEN.

Message received at 38411 <at> debbugs.gnu.org:


Received: (at 38411) by debbugs.gnu.org; 28 Nov 2019 09:59:24 +0000
From debbugs-submit-bounces <at> debbugs.gnu.org Thu Nov 28 04:59:24 2019
Received: from localhost ([127.0.0.1]:56664 helo=debbugs.gnu.org)
	by debbugs.gnu.org with esmtp (Exim 4.84_2)
	(envelope-from <debbugs-submit-bounces <at> debbugs.gnu.org>)
	id 1iaGa4-0006oS-6s
	for submit <at> debbugs.gnu.org; Thu, 28 Nov 2019 04:59:24 -0500
Received: from eggs.gnu.org ([209.51.188.92]:40713)
 by debbugs.gnu.org with esmtp (Exim 4.84_2)
 (envelope-from <ludo@HIDDEN>) id 1iaGa0-0006oD-SR
 for 38411 <at> debbugs.gnu.org; Thu, 28 Nov 2019 04:59:23 -0500
Received: from fencepost.gnu.org ([2001:470:142:3::e]:39693)
 by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from <ludo@HIDDEN>)
 id 1iaGZv-0007Ie-JE
 for 38411 <at> debbugs.gnu.org; Thu, 28 Nov 2019 04:59:15 -0500
Received: from [2001:660:6102:320:e120:2c8f:8909:cdfe] (port=37064 helo=ribbon)
 by fencepost.gnu.org with esmtpsa (TLS1.2:RSA_AES_256_CBC_SHA1:256)
 (Exim 4.82) (envelope-from <ludo@HIDDEN>) id 1iaGZu-00028I-CD
 for 38411 <at> debbugs.gnu.org; Thu, 28 Nov 2019 04:59:14 -0500
From: =?utf-8?Q?Ludovic_Court=C3=A8s?= <ludo@HIDDEN>
To: 38411 <at> debbugs.gnu.org
Subject: Re: bug#38411: HTTP pipelining of narinfo requests broken for
 https://ci.guix.gnu.org
References: <871rtsz77q.fsf@HIDDEN>
Date: Thu, 28 Nov 2019 10:59:12 +0100
In-Reply-To: <871rtsz77q.fsf@HIDDEN> ("Ludovic
 \=\?utf-8\?Q\?Court\=C3\=A8s\=22'\?\=
 \=\?utf-8\?Q\?s\?\= message of "Thu, 28 Nov 2019 10:22:01 +0100")
Message-ID: <87r21sxqxb.fsf@HIDDEN>
User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/26.3 (gnu/linux)
MIME-Version: 1.0
Content-Type: text/plain; charset=utf-8
Content-Transfer-Encoding: quoted-printable
X-detected-operating-system: by eggs.gnu.org: GNU/Linux 2.2.x-3.x [generic]
X-Spam-Score: 0.7 (/)
X-Debbugs-Envelope-To: 38411
X-BeenThere: debbugs-submit <at> debbugs.gnu.org
X-Mailman-Version: 2.1.18
Precedence: list
List-Id: <debbugs-submit.debbugs.gnu.org>
List-Unsubscribe: <https://debbugs.gnu.org/cgi-bin/mailman/options/debbugs-submit>, 
 <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=unsubscribe>
List-Archive: <https://debbugs.gnu.org/cgi-bin/mailman/private/debbugs-submit/>
List-Post: <mailto:debbugs-submit <at> debbugs.gnu.org>
List-Help: <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=help>
List-Subscribe: <https://debbugs.gnu.org/cgi-bin/mailman/listinfo/debbugs-submit>, 
 <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=subscribe>
Errors-To: debbugs-submit-bounces <at> debbugs.gnu.org
Sender: "Debbugs-submit" <debbugs-submit-bounces <at> debbugs.gnu.org>
X-Spam-Score: -0.3 (/)

> The weird thing is that we haven=E2=80=99t change the config of berlin in=
 recent
> days.  Berlin runs nginx 1.17.5 on openssl 1.1.1d, while bayfront runs
> nginx 1.17.0 on openssl 1.0.2p.

A new data point: nginx 1.17.4 from a month ago works fine:

--8<---------------cut here---------------start------------->8---
root@berlin ~/maintenance/hydra# guix system list-generations 2m=20=20=20=
=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=
=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20
[=E2=80=A6]
Generation 238  Oct 23 2019 18:02:22
  file name: /var/guix/profiles/system-238-link
  canonical file name: /gnu/store/28xk8ny9qslyqgi7pjyz4d2x0xrxpw07-system
  label: GNU with Linux-Libre 5.3.7
  bootloader: grub
  root device: label: "my-root"
  kernel: /gnu/store/qpasq1pkzb47w5pjzs80pvslv1n7ja1m-linux-libre-5.3.7/bzI=
mage
[=E2=80=A6]
root@berlin ~/maintenance/hydra# guix gc -R /gnu/store/28xk8ny9qslyqgi7pjyz=
4d2x0xrxpw07-system|grep nginx
/gnu/store/4gbpgcr4zc4qf59yq2a008maycfwra4n-shepherd-nginx.scm
/gnu/store/3gqi5cahcwjfvv0bbfqv8ifir2vrqirh-nginx.conf
/gnu/store/s9fm4d5ii8bnh9zv5k78mzjvcl3dipbh-shepherd-nginx.go
/gnu/store/zj3mxk3r2dka56favm357kmgywnv5imk-nginx-1.17.4
root@berlin ~/maintenance/hydra# guix gc --references /gnu/store/zj3mxk3r2d=
ka56favm357kmgywnv5imk-nginx-1.17.4/sbin/nginx |grep ssl
/gnu/store/1dvkm6b97667qd36rsnw4g6isnsmpym7-openssl-1.1.1d
--8<---------------cut here---------------end--------------->8---

So for now berlin is running this nginx.  I=E2=80=99ll try with 1.17.6 and
1.17.4 on top of current master.

Ludo=E2=80=99.




Information forwarded to bug-guix@HIDDEN:
bug#38411; Package guix. Full text available.
Severity set to 'serious' from 'normal' Request was from Ludovic Courtès <ludo@HIDDEN> to control <at> debbugs.gnu.org. Full text available.

Message received at submit <at> debbugs.gnu.org:


Received: (at submit) by debbugs.gnu.org; 28 Nov 2019 09:22:12 +0000
From debbugs-submit-bounces <at> debbugs.gnu.org Thu Nov 28 04:22:12 2019
Received: from localhost ([127.0.0.1]:56630 helo=debbugs.gnu.org)
	by debbugs.gnu.org with esmtp (Exim 4.84_2)
	(envelope-from <debbugs-submit-bounces <at> debbugs.gnu.org>)
	id 1iaG03-0003yN-2T
	for submit <at> debbugs.gnu.org; Thu, 28 Nov 2019 04:22:12 -0500
Received: from lists.gnu.org ([209.51.188.17]:50991)
 by debbugs.gnu.org with esmtp (Exim 4.84_2)
 (envelope-from <ludo@HIDDEN>) id 1iaG01-0003yE-Hm
 for submit <at> debbugs.gnu.org; Thu, 28 Nov 2019 04:22:09 -0500
Received: from eggs.gnu.org ([2001:470:142:3::10]:41244)
 by lists.gnu.org with esmtp (Exim 4.90_1)
 (envelope-from <ludo@HIDDEN>) id 1iaFzy-0002QS-4f
 for bug-Guix@HIDDEN; Thu, 28 Nov 2019 04:22:08 -0500
X-Spam-Checker-Version: SpamAssassin 3.3.2 (2011-06-06) on eggs.gnu.org
X-Spam-Level: 
X-Spam-Status: No, score=-0.2 required=5.0 tests=ALL_TRUSTED,BAYES_50,
 URIBL_BLOCKED autolearn=disabled version=3.3.2
Received: from fencepost.gnu.org ([2001:470:142:3::e]:39444)
 by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from <ludo@HIDDEN>)
 id 1iaFzx-0004KF-OE
 for bug-Guix@HIDDEN; Thu, 28 Nov 2019 04:22:05 -0500
Received: from [2001:660:6102:320:e120:2c8f:8909:cdfe] (port=37000 helo=ribbon)
 by fencepost.gnu.org with esmtpsa (TLS1.2:RSA_AES_256_CBC_SHA1:256)
 (Exim 4.82) (envelope-from <ludo@HIDDEN>) id 1iaFzw-0004eF-8C
 for bug-Guix@HIDDEN; Thu, 28 Nov 2019 04:22:04 -0500
From: =?utf-8?Q?Ludovic_Court=C3=A8s?= <ludo@HIDDEN>
To: bug-Guix@HIDDEN
Subject: HTTP pipelining of narinfo requests broken for https://ci.guix.gnu.org
X-URL: http://www.fdn.fr/~lcourtes/
X-Revolutionary-Date: 8 Frimaire an 228 de la =?utf-8?Q?R=C3=A9volution?=
X-PGP-Key-ID: 0x090B11993D9AEBB5
X-PGP-Key: http://www.fdn.fr/~lcourtes/ludovic.asc
X-PGP-Fingerprint: 3CE4 6455 8A84 FDC6 9DB4  0CFB 090B 1199 3D9A EBB5
X-OS: x86_64-pc-linux-gnu
Date: Thu, 28 Nov 2019 10:22:01 +0100
Message-ID: <871rtsz77q.fsf@HIDDEN>
User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/26.3 (gnu/linux)
MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="=-=-="
X-detected-operating-system: by eggs.gnu.org: GNU/Linux 2.2.x-3.x [generic]
X-Spam-Score: -0.8 (/)
X-Debbugs-Envelope-To: submit
X-BeenThere: debbugs-submit <at> debbugs.gnu.org
X-Mailman-Version: 2.1.18
Precedence: list
List-Id: <debbugs-submit.debbugs.gnu.org>
List-Unsubscribe: <https://debbugs.gnu.org/cgi-bin/mailman/options/debbugs-submit>, 
 <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=unsubscribe>
List-Archive: <https://debbugs.gnu.org/cgi-bin/mailman/private/debbugs-submit/>
List-Post: <mailto:debbugs-submit <at> debbugs.gnu.org>
List-Help: <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=help>
List-Subscribe: <https://debbugs.gnu.org/cgi-bin/mailman/listinfo/debbugs-submit>, 
 <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=subscribe>
Errors-To: debbugs-submit-bounces <at> debbugs.gnu.org
Sender: "Debbugs-submit" <debbugs-submit-bounces <at> debbugs.gnu.org>
X-Spam-Score: -1.8 (-)

--=-=-=
Content-Type: text/plain; charset=utf-8
Content-Transfer-Encoding: quoted-printable

Starting from a couple of days ago (it seems; roughly around the same
time berlin hit ENOSPC), people have been experiencing issues during the
=E2=80=9Cupdating list of substitutes=E2=80=9D phase from https://ci.guix.g=
nu.org, where
they=E2=80=99d get an ugly backtrace when they=E2=80=99re at 80% or so.

Here=E2=80=99s a small reproducer:


--=-=-=
Content-Type: text/plain
Content-Disposition: inline; filename=http-pipelining.scm
Content-Description: the reproducer

(use-modules (guix scripts substitute)
             (srfi srfi-1)
             (srfi srfi-26)
             (web uri)
             (web request)
             (web response)
             (rnrs io ports))

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

(define %base-url
  "https://berlin.guix.gnu.org")

(define %request-count
  ;; Number of requests to send.  Starts failing at 85 (that is, we don't
  ;; receive the 85th response).
  200)

(http-multiple-get (string->uri %base-url)
                   (lambda (request response port result)
                     (let ((len (or (response-content-length response)
                                    0)))
                       (pk 'resp (length result)
                           (uri-path (request-uri request)))
                       (get-bytevector-n port len)
                       (cons result result)))
                   '()
                   (unfold (cut >= <> %request-count)
                           (lambda (n)
                             (build-request
                              (string->uri
                               (string-append
                                %base-url
                                "/"
                                (string-pad (number->string n) 32 #\a)
                                ".narinfo"))
                              #:method 'GET
                              #:headers '((User-Agent . "GNU Guile"))))
                           1+
                           0)
                   #:verify-certificate? #f)

--=-=-=
Content-Type: text/plain; charset=utf-8
Content-Transfer-Encoding: quoted-printable


You=E2=80=99ll see that it hangs waiting for a response as soon as you pipe=
line
85 requests or more.

Note that:

  1. https://bayfront.guix.gnu.org doesn=E2=80=99t have that problem;

  2. http://ci.guix.gnu.org doesn=E2=80=99t have that problem;

  3. when you send 85 requests, it hangs waiting for the 85th response;
     but when you send 200 requests, it hangs waiting for the 160th
     response; so it seems it=E2=80=99s not just a matter of TLS record siz=
e.

I suspected something having to do with TLS record size limits, but item
#3 above may invalidate that hypothesis.

The weird thing is that we haven=E2=80=99t change the config of berlin in r=
ecent
days.  Berlin runs nginx 1.17.5 on openssl 1.1.1d, while bayfront runs
nginx 1.17.0 on openssl 1.0.2p.

I very much welcome any ideas you may have!

Thanks,
Ludo=E2=80=99.

--=-=-=--




Acknowledgement sent to Ludovic Courtès <ludo@HIDDEN>:
New bug report received and forwarded. Copy sent to bug-guix@HIDDEN. Full text available.
Report forwarded to bug-guix@HIDDEN:
bug#38411; Package guix. Full text available.
Please note: This is a static page, with minimal formatting, updated once a day.
Click here to see this page with the latest information and nicer formatting.
Last modified: Thu, 28 Nov 2019 10:00:01 UTC

GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997 nCipher Corporation Ltd, 1994-97 Ian Jackson.