From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from mp1 ([2001:41d0:2:bcc0::]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits)) by ms11 with LMTPS id SFplFqS8T2DeDQAA0tVLHw (envelope-from ) for ; Mon, 15 Mar 2021 19:59:32 +0000 Received: from aspmx1.migadu.com ([2001:41d0:2:bcc0::]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits)) by mp1 with LMTPS id MKUJEqS8T2AZPgAAbx9fmQ (envelope-from ) for ; Mon, 15 Mar 2021 19:59:32 +0000 Received: from lists.gnu.org (lists.gnu.org [209.51.188.17]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by aspmx1.migadu.com (Postfix) with ESMTPS id A027FA241 for ; Mon, 15 Mar 2021 20:59:31 +0100 (CET) Received: from localhost ([::1]:51158 helo=lists1p.gnu.org) by lists.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1lLtNB-0001dL-J0 for larch@yhetil.org; Mon, 15 Mar 2021 15:59:29 -0400 Received: from eggs.gnu.org ([2001:470:142:3::10]:38910) by lists.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1lLtIs-0004DQ-73 for bug-guix@gnu.org; Mon, 15 Mar 2021 15:55:02 -0400 Received: from debbugs.gnu.org ([209.51.188.43]:53932) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_128_GCM_SHA256:128) (Exim 4.90_1) (envelope-from ) id 1lLtIr-0006Ny-U3 for bug-guix@gnu.org; Mon, 15 Mar 2021 15:55:01 -0400 Received: from Debian-debbugs by debbugs.gnu.org with local (Exim 4.84_2) (envelope-from ) id 1lLtIr-0007lU-S8; Mon, 15 Mar 2021 15:55:01 -0400 X-Loop: help-debbugs@gnu.org Subject: bug#47157: =?UTF-8?Q?=E2=80=9CBad?= Read-Header-Line header: =?UTF-8?Q?#=E2=80=9D?= while substituting Resent-From: Christopher Baines Original-Sender: "Debbugs-submit" Resent-CC: bug-guix@gnu.org Resent-Date: Mon, 15 Mar 2021 19:55:01 +0000 Resent-Message-ID: Resent-Sender: help-debbugs@gnu.org X-GNU-PR-Message: followup 47157 X-GNU-PR-Package: guix X-GNU-PR-Keywords: To: 47157@debbugs.gnu.org Received: via spool by 47157-submit@debbugs.gnu.org id=B47157.161583804229772 (code B ref 47157); Mon, 15 Mar 2021 19:55:01 +0000 Received: (at 47157) by debbugs.gnu.org; 15 Mar 2021 19:54:02 +0000 Received: from localhost ([127.0.0.1]:37245 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1lLtHt-0007jt-Oz for submit@debbugs.gnu.org; Mon, 15 Mar 2021 15:54:02 -0400 Received: from mira.cbaines.net ([212.71.252.8]:36268) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1lLtHr-0007jk-7M for 47157@debbugs.gnu.org; Mon, 15 Mar 2021 15:54:00 -0400 Received: from localhost (unknown [IPv6:2a02:8010:68c1:0:8ac0:b4c7:f5c8:7caa]) by mira.cbaines.net (Postfix) with ESMTPSA id 488A427BC52; Mon, 15 Mar 2021 19:53:58 +0000 (GMT) Received: from capella (localhost [127.0.0.1]) by localhost (OpenSMTPD) with ESMTP id 0b9d6fe2; Mon, 15 Mar 2021 19:53:57 +0000 (UTC) References: <87eeggh4rh.fsf@inria.fr> <871rcgfiz9.fsf@cbaines.net> User-agent: mu4e 1.4.15; emacs 27.1 From: Christopher Baines In-reply-to: <871rcgfiz9.fsf@cbaines.net> Date: Mon, 15 Mar 2021 19:53:54 +0000 Message-ID: <87v99sdwh9.fsf@cbaines.net> MIME-Version: 1.0 Content-Type: multipart/signed; boundary="=-=-="; micalg=pgp-sha512; protocol="application/pgp-signature" X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list X-BeenThere: bug-guix@gnu.org List-Id: Bug reports for GNU Guix List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Cc: Ludovic =?UTF-8?Q?Court=C3=A8s?= Errors-To: bug-guix-bounces+larch=yhetil.org@gnu.org Sender: "bug-Guix" X-Migadu-Flow: FLOW_IN ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=yhetil.org; s=key1; t=1615838371; h=from:from:sender:sender:reply-to:subject:subject:date:date: message-id:message-id:to:to:cc:cc:mime-version:mime-version: content-type:content-type:resent-cc:resent-from:resent-sender: resent-message-id:in-reply-to:in-reply-to:references:references: list-id:list-help:list-unsubscribe:list-subscribe:list-post; bh=iyp3QC8owMg8jRP62C7DBNzoZil88U8g/lZBw8TrF7Q=; b=e3aPQUUg3xA7g/3XqBq5R+JoRrGi0GPxAthapz//GxFwYJ3hRQpUhBfVHDqgIhCosYxOjH 3Qw4BnNTPsIcsAJHjG6N8BzcooLx9u49upIvIy91ndcPueVJGzDeauhrUJ00TkCRMYalyj JVzzatQ4UC5pxeus4PebEQHbd+tI1IV7adXR1MM5qEV27x2Vy2WV1fyA0dVTTdM2yrCmsa 4YyAu25wbZZ0J62s/amJ7caTM6dRT+t8a7AidqVal6n2Cqa5ZNh92vzkWihLek0q99hHmz OGEBi4II2hZI84xunlIhrmsPEY2ixLLTThVMp7SmeOkOVVAgunVSnv01TYdfsA== ARC-Seal: i=1; s=key1; d=yhetil.org; t=1615838371; a=rsa-sha256; cv=none; b=NeBlAr7mEftkYrpNaJfvxpiOAAbdooEsQSg5dPpijNHmNCNaIGejxRfF/EPW2BWp+LFOLk IN1yFE+WKH3Ws3BNMp67HClNNvNRM6rme4BrdiM03f/TTocdfx/LnrXV98QtdUfPn3wCmn Nf0sFu36SXD9UDW8yODmcCWMSEBm0DccQPtGt/zHALVZKsAOuTNefNIO8KyzZB+fCIJzH3 TEHMPG+PuIvKl/n86ennZYaViQTVJretAtMMHdtZ8RA/IZnMMsSG3QA+QZTZmajfBLv+dH m+c1A+svkLnq/LTQRfQNrxw5yo7q6twzJ2TaIkB0amviCQtlVRZIMyxf5IiMLg== ARC-Authentication-Results: i=1; aspmx1.migadu.com; dkim=none; dmarc=none; spf=pass (aspmx1.migadu.com: domain of bug-guix-bounces@gnu.org designates 209.51.188.17 as permitted sender) smtp.mailfrom=bug-guix-bounces@gnu.org X-Migadu-Spam-Score: -4.50 Authentication-Results: aspmx1.migadu.com; dkim=none; dmarc=none; spf=pass (aspmx1.migadu.com: domain of bug-guix-bounces@gnu.org designates 209.51.188.17 as permitted sender) smtp.mailfrom=bug-guix-bounces@gnu.org X-Migadu-Queue-Id: A027FA241 X-Spam-Score: -4.50 X-Migadu-Scanner: scn0.migadu.com X-TUID: pEnjOKXJ5Cul --=-=-= Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable Christopher Baines writes: > Ludovic Court=C3=A8s writes: > >> As reported by a few people on IRC, =E2=80=98guix substitute=E2=80=99 so= metimes fails in >> a way that I just experienced (from >> 8154beffd8c121e953a7c4cd75c3eebfcc073a9a): >> >> --8<---------------cut here---------------start------------->8--- >> downloading from https://ci.guix.gnu.org/nar/gzip/0bji0q5n59595xaqkqrp2g= v52lbz55xz-libpng-1.6.37 . >> libpng-1.6.37 275KiB 11.0MiB/s 00:00 [= ##################] 100.0% >> >> downloading from https://ci.guix.gnu.org/nar/lzip/h3a5ygxxh4gakhnl53mq7z= 9b43l8z05g-python-minimal. >> python-minimal-wrapper-3.8.2 351B 293KiB/s 00:00 [= ##################] 100.0% >> >> downloading from https://ci.guix.gnu.org/nar/lzip/h8j09yb5d8dh3jffvpzawx= slig9bwhdr-freetype-2.10.. >> freetype-2.10.4 600KiB 3.0MiB/s 00:00 [= ##################] 100.0% >> >> building /gnu/store/2wfzazqz9g5xizi4vq4pv75nkh1m24bp-perl-5.30.2.drv... >> Backtrace: >> In guix/ui.scm: >> 2164:12 19 (run-guix-command _ . _) >> In guix/scripts/substitute.scm: >> 691:2 18 (guix-substitute . _) >> In unknown file: >> 17 (with-continuation-barrier #) >> In ice-9/boot-9.scm: >> 1736:10 16 (with-exception-handler _ _ #:unwind? _ #:unwind-for-type _) >> In unknown file: >> 15 (apply-smob/0 #) >> In ice-9/boot-9.scm: >> 1736:10 14 (with-exception-handler _ _ #:unwind? _ #:unwind-for-type _) >> 1736:10 13 (with-exception-handler _ _ #:unwind? _ #:unwind-for-type _) >> 1731:15 12 (with-exception-handler # _) >> In guix/scripts/substitute.scm: >> 740:17 11 (_) >> 434:7 10 (process-substitution _ "/gnu/store/ns00dyapjbq9037dwrxa7hc= 31dvir00n-grub-minimal-2.) >> In ice-9/boot-9.scm: >> 1736:10 9 (with-exception-handler _ _ #:unwind? _ #:unwind-for-type _) >> In guix/scripts/substitute.scm: >> 443:9 8 (_) >> In ice-9/boot-9.scm: >> 1731:15 7 (with-exception-handler # _) >> 1669:16 6 (raise-exception _ #:continuable? _) >> 1667:16 5 (raise-exception _ #:continuable? _) >> 1669:16 4 (raise-exception _ #:continuable? _) >> 1764:13 3 (_ #<&compound-exception components: (#<&error> #<&irritant= s irritants: (read-header) >> 1669:16 2 (raise-exception _ #:continuable? _) >> 1667:16 1 (raise-exception _ #:continuable? _) >> 1669:16 0 (raise-exception _ #:continuable? _) >> >> ice-9/boot-9.scm:1669:16: In procedure raise-exception: >> Bad Read-Header-Line header: # >> --8<---------------cut here---------------end--------------->8--- >> >> This is the kind of issue that =E2=80=98with-cached-connection=E2=80=99 = as it can be >> seen in 9158020d7853b6e7925802e0d0a082801c680e8f avoided: >> >> --8<---------------cut here---------------start------------->8--- >> (define* (call-with-cached-connection uri proc >> #:optional >> (open-connection >> open-connection-for-uri/cached)) >> (let ((port (open-connection uri))) >> (catch #t >> (lambda () >> (proc port)) >> (lambda (key . args) >> ;; If PORT was cached and the server closed the connection in the >> ;; meantime, we get EPIPE. In that case, open a fresh connectio= n and >> ;; retry. We might also get 'bad-response or a similar exceptio= n from >> ;; (web response) later on, once we've sent the request, or a >> ;; ERROR/INVALID-SESSION from GnuTLS. >> (if (or (and (eq? key 'system-error) >> (=3D EPIPE (system-error-errno `(,key ,@args)))) >> (and (eq? key 'gnutls-error) >> (eq? (first args) error/invalid-session)) >> (memq key '(bad-response bad-header bad-header-component= ))) >> (proc (open-connection uri #:fresh? #t)) >> (apply throw key args)))))) >> --8<---------------cut here---------------end--------------->8--- >> >> I think 7b812f7c84c43455cdd68a0e51b6ded018afcc8e and subsequent commits >> may have caused this regression. In particular, in >> 20c08a8a45d0f137ead7c05e720456b2aea44402, >> =E2=80=98call-with-connection-error-handling=E2=80=99 is now used, but t= hat one doesn=E2=80=99t >> catch the exceptions mentioned above, in this case =E2=80=98bad-header= =E2=80=99. > > I think the behaviour changed unintentionally with [1], however, > thinking about the connection reuse in process-substitution compared > with http-multiple-get, there's no attempt here to look at if the server > has specified whether the connection should be closed. > > 1: https://git.savannah.gnu.org/cgit/guix.git/commit/?id=3Df50f5751fff4cf= c6d5abba9681054569694b7a5c > > Just like http-multiple-get, it's probably worth trying to check the > headers of the response, look at whether the server has indicated that > the connection should be closed, and if so, close the connection, > forcing a new one to be established for future requests. > > I haven't tested this theory, but maybe if that happened, then some > occurrences of trying to read a response, and not being able to would be > prevented. I've now actually got around to testing this, I'm no expert at running the substitute script manually without the guix-daemon, but I gave it a go, using a local NGinx instance which just allowed two requests per connection. With these changes [2], connections were closed when appropriate and a new one is established when the next nar is fetched. 2: https://issues.guix.gnu.org/47174 When testing using the same approach with master, I get this exception [3], so either I'm doing something wrong, or this isn't a circumstance under which there can be a bad-header issue. Regardless, I'm not sure what's going on with this exception below. 3: ice-9/boot-9.scm:1669:16: In procedure raise-exception: Wrong number of values returned to continuation (expected 2) --=-=-= Content-Type: application/pgp-signature; name="signature.asc" -----BEGIN PGP SIGNATURE----- iQKlBAEBCgCPFiEEPonu50WOcg2XVOCyXiijOwuE9XcFAmBPu1JfFIAAAAAALgAo aXNzdWVyLWZwckBub3RhdGlvbnMub3BlbnBncC5maWZ0aGhvcnNlbWFuLm5ldDNF ODlFRUU3NDU4RTcyMEQ5NzU0RTBCMjVFMjhBMzNCMEI4NEY1NzcRHG1haWxAY2Jh aW5lcy5uZXQACgkQXiijOwuE9Xfh+w/9EbWSWeht2vYbWh/5lPi5itYR2PABmcKH JTe26bliASrUcDCuYEpL531rahykntPMAwQinJXf7Lx5gfWJquVuw74u+XhWOee9 bOcqxsN+UPLuXXOVa6I+ExN9pdUG4csuRMbJDHM9TGCZsMC/rvFv+olVRUBWO7Ai xMJcsJklo9w6pMhlaI6ar5ytGC7aOxbUZP57EGuwqofcKMt4Yv0MvmpeYdMPupy2 lf/SnCQ4guojZ/4JQqCJtm0164StGKbILdvTAmD0SNSv9P6f1lFwqIiHHHoFuEUC fIxBRt2blDd7LAqbWzvLzK3hUtGGXCKGNVXVOCO8EjDtxU9sUxchSvUb9yhms+dO gfBO07UA7s1AeqpJGzx88K6Rpsk4/esy7IACS1k8RPt38Dxp98VVj+TwAB7pg18u g985OhK/GLSRMz/efpAcRw9g1PCnmodN0Yco0+ekaYnAT0iPWmK+XyNCU3JALFmu aks+qVDWJIuFUtSVLOeoF2H6lZoxkHE0JLFW2Z2WbZipooNZQgIPLhzovOWf0yNv w1zXSnjVqKQb3FxA0k8YygoWVfLVJvxKFam9+S1QbWaGR0MpcjmlzhkYEueMp3Ut kVsOqrA2+TDN589LBVSnmTEfxN2nyHVPb57iz1mVTPWeLY76h7D/Rsf3STEiZCxp fSkzfjyZWhY= =Fb25 -----END PGP SIGNATURE----- --=-=-=--