From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from mp2 ([2001:41d0:2:4a6f::]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) by ms0.migadu.com with LMTPS id yC1iFjCRgmAu3wAAgWs5BA (envelope-from ) for ; Fri, 23 Apr 2021 11:19:44 +0200 Received: from aspmx1.migadu.com ([2001:41d0:2:4a6f::]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits)) by mp2 with LMTPS id 8AceEjCRgmAcJAAAB5/wlQ (envelope-from ) for ; Fri, 23 Apr 2021 09:19:44 +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 E91E325AA5 for ; Fri, 23 Apr 2021 11:19:43 +0200 (CEST) Received: from localhost ([::1]:51440 helo=lists1p.gnu.org) by lists.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1lZryR-0001PE-6I for larch@yhetil.org; Fri, 23 Apr 2021 05:19:43 -0400 Received: from eggs.gnu.org ([2001:470:142:3::10]:38104) by lists.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1lZryG-0001Ot-Mu for guix-devel@gnu.org; Fri, 23 Apr 2021 05:19:33 -0400 Received: from fencepost.gnu.org ([2001:470:142:3::e]:38338) by eggs.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1lZryF-0002TT-Nx; Fri, 23 Apr 2021 05:19:31 -0400 Received: from [2a01:e0a:1d:7270:af76:b9b:ca24:c465] (port=40550 helo=ribbon) by fencepost.gnu.org with esmtpsa (TLS1.2:RSA_AES_256_CBC_SHA1:256) (Exim 4.82) (envelope-from ) id 1lZryE-0002ZY-96; Fri, 23 Apr 2021 05:19:31 -0400 From: =?utf-8?Q?Ludovic_Court=C3=A8s?= To: "pelzflorian (Florian Pelz)" Subject: Re: bug#47867: [1.2.1 pre-release testing] substitute downloading and TLS errors References: <87lf9hsh9t.fsf@gmail.com> <20210418093856.a6r2zqw2gks56dg5@pelzflorian.localdomain> <87a6pvnbjg.fsf@gnu.org> <20210418113337.z3afnp4lmt55cjvw@pelzflorian.localdomain> <20210418121006.4ihop3umb2oyofum@pelzflorian.localdomain> <20210419080516.piqb52s32h3fe5ag@pelzflorian.localdomain> <20210420012113.jcwuzfx6k3by5nvo@pelzflorian.localdomain> <20210420152754.a3ucylrdugrmxu57@pelzflorian.localdomain> <8735vk8ttp.fsf@gnu.org> <20210421201751.3mygidtwio2yz7j4@pelzflorian.localdomain> Date: Fri, 23 Apr 2021 11:19:28 +0200 In-Reply-To: <20210421201751.3mygidtwio2yz7j4@pelzflorian.localdomain> (pelzflorian@pelzflorian.de's message of "Wed, 21 Apr 2021 22:17:56 +0200") Message-ID: <874kfxtl27.fsf@gnu.org> User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/27.2 (gnu/linux) MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="=-=-=" X-BeenThere: guix-devel@gnu.org X-Mailman-Version: 2.1.23 Precedence: list List-Id: "Development of GNU Guix and the GNU System distribution." List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Cc: guix-devel@gnu.org, jcguu95 , 47867@debbugs.gnu.org Errors-To: guix-devel-bounces+larch=yhetil.org@gnu.org Sender: "Guix-devel" X-Migadu-Flow: FLOW_IN ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=yhetil.org; s=key1; t=1619169584; 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:in-reply-to:in-reply-to: references:references:list-id:list-help:list-unsubscribe: list-subscribe:list-post; bh=/VasIfJv4161LntRaDZFXY9Vac+Q6VB1qfl1nNU2GzQ=; b=WTP7wMfz/vFuPZkIxOaZ3UWo3tyZoDAKHZ6gA6wbmrRmb7tXtGMXgFCpm8rMx8yQjqu1HS Az6el1fKPhuQsYK4VxqR0Igl46tf3AEh+TpQ/20SVR4WS8CWWX+Wr+rCM0o9beuETVlhex 9L/0kI6659vypKu83XvVqrge+1OLbhYigxJwAKtFpD/8tKuIDEVXWiFLAjpZe8Nli3i4mm RuDxsKRuIad09A8O8nKbv8vYJAE0/4VS6gN/nASzV5C8GULrCuhyETjm+FwqvqiO7KZuSs eTQKKHpsJm//gx/Bf34hHWUFKQTwbxbT5xl0GX9ZhungwggywO5AyBLzT78tjg== ARC-Seal: i=1; s=key1; d=yhetil.org; t=1619169584; a=rsa-sha256; cv=none; b=EVkalYFdVibZKvMF8aoDWzW0VWi2/Bs5m3DrgVz0X8vNTkcoNLYz15pDBcZUBOXHFPHVxT cUrotHIr6hD3C2vgpM7w49EfYbow/0niXFkeE9j/wP8bDWIhc7lRiFCbJUHpm3wTwOJA6b G6QtuegNd6kGQ/kJmUlVd6Nux/lFJFxKRUduOMsvu/XoyaKcQzeGQb8bTl0NlNw7Arl+aF lWsopVRkyXLHr36znUz+/wpieO0GRmKCHaH2FHwsRTQ9BrM9r2ZgqaXYbj2I03rYSanroJ KI+5kHp5PNP5fIVih2DD8LWn8R1GG9P8rnqXXDXUC6FCq6mF3/sSvuVvm8FE0g== ARC-Authentication-Results: i=1; aspmx1.migadu.com; dkim=none; dmarc=pass (policy=none) header.from=gnu.org; spf=pass (aspmx1.migadu.com: domain of guix-devel-bounces@gnu.org designates 209.51.188.17 as permitted sender) smtp.mailfrom=guix-devel-bounces@gnu.org X-Migadu-Spam-Score: -1.45 Authentication-Results: aspmx1.migadu.com; dkim=none; dmarc=pass (policy=none) header.from=gnu.org; spf=pass (aspmx1.migadu.com: domain of guix-devel-bounces@gnu.org designates 209.51.188.17 as permitted sender) smtp.mailfrom=guix-devel-bounces@gnu.org X-Migadu-Queue-Id: E91E325AA5 X-Spam-Score: -1.45 X-Migadu-Scanner: scn0.migadu.com X-TUID: bhJo3XS9q7Zw --=-=-= Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable Hi Florian, (Cc: Chris who=E2=80=99s also familiar with (guix http-client).) "pelzflorian (Florian Pelz)" skribis: > It still gets stuck (sometimes with enlightenment, one time with > udisks, restarting the install fixed it once). After getting stuck, > this different error message is shown now; no TLS error (copied by > manual typing, there may be typos): > > gtk-doc-1.28 653KiB 2.4MiB/s 00:00 [####################]= 100.0% > udisks-2.8.4 842KiB 1.6MiB/s 00:00 [####################]= 100.0% > > substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%= Backtrace: > substitute: In ice-9/boot-9.scm: > substitute: 1736:10 17 (with-exception-handler _ _ #:unwind? _ # _) > substitute: In unknown file: > substitute: 16 (apply-smob/0 #) > substitute: In ice-9/boot-9.scm: > substitute: 718:2 15 (call-with-prompt _ _ #) > substitute: In ice-9/eval.scm: > substitute: 619:8 14 (_ #(#(#))) > substitute: In guix/ui.scm: > substitute: 2164:12 13 (run-guix-command _ . _) > substitute: In ice-9/boot-9.scm: > substitute: 1736:10 12 (with-exception-handler _ _ #:unwind? _ # _) > substitute: 1736:10 11 (with-exception-handler _ _ #:unwind? _ # _) > substitute: 1731:15 10 (with-exception-handler _ _ #:unwind? _ # _) > substitute: In guix/scripts/substitute.scm: > substitute: 745:18 9 (_) > substitute: 346:26 8 (process-query # _ #:cache-urls = _ #:acl _) > substitute: In guix/substitutes.scm: > substitute: 358:27 7 (lookup-narinfos/diverse _ _ # > substitute: 315:31 6 (lookup-narinfos _ _ #:open-connection _ # _) > substitute: 238:26 5 (fetch-narinfos _ _ #:open-connection _ # _) > substitute: In ice-9/boot-9.scm: > substitute: 1669:16 4 (raise-exception _ #:continuable? _) > substitute: 1669:16 3 (raise-exception _ #:continuable? _) > substitute: 1764:13 2 (_ #<&compound-exception _ components: assertion= -fail=E2=80=A6>) > substitute: 1669:16 1 (raise-exception _ #:continuable? _) > substitute: 1669:16 0 (raise-exception _ #:continuable? _) > substitute: > substitute: In ice-9/boot-9.scm:1669:16 In procedure raise-exception: > substitute: In procedure %read-line: Wrong type argument in position 1 (e= xpecting open input port): # > guix system: error: `/gnu/store/k3n98i1fk9awd5ydv4ry4k4rlpp7i13m7-guix-1.= 2.0-22.c467718/bin/guix substitute' died unexpectedly I think I got it: commit 205833b72c5517915a47a50dbe28e7024dc74e57 (then carried over in 45fce38fb0b6c6796906149ade145b8d3594c1c6) introduced a call to =E2=80=98connect=E2=80=99 in non-tail position. Once that recursiv= e call to =E2=80=98connect=E2=80=99 had completed, =E2=80=98http-multiple-get=E2=80= =99 would go on in =E2=80=98loop=E2=80=99 trying to re-process responses, but at that point there aren=E2=80=99t any responses left to process. This problem could only happen if a networking exception would occur while sending HTTP requests for narinfos. Thus, it was most likely to occur when interleaving substitutions and queries, as in the snippet you provided above, because then =E2=80=98http-multiple-get=E2=80=99 was more l= ikely to be passed a stale reused connection. Florian, could you try again with the attached patch? If you have the courage, it would be awesome if you could also try the patch without the =E2=80=98error/again=E2=80=99 bits. It=E2=80=99s possibl= e that they aren=E2=80=99t needed now. I double-checked and the GnuTLS Guile bindings already handle GNUTLS_E_AGAIN and GNUTLS_E_INTERRUPTED, so my guess is that this was just a side effect of dealing with stale TLS sessions: https://gitlab.com/gnutls/gnutls/-/blob/master/guile/src/core.c#L1042 Thanks a lot for your help! Ludo=E2=80=99. --=-=-= Content-Type: text/x-patch Content-Disposition: inline diff --git a/guix/http-client.scm b/guix/http-client.scm index a2e11a1b73..b9cf0b1a4b 100644 --- a/guix/http-client.scm +++ b/guix/http-client.scm @@ -38,7 +38,7 @@ #:use-module (guix utils) #:use-module (guix base64) #:autoload (gcrypt hash) (sha256) - #:autoload (gnutls) (error/invalid-session) + #:autoload (gnutls) (error/invalid-session error/again) #:use-module ((guix build utils) #:select (mkdir-p dump-port)) #:use-module ((guix build download) @@ -163,7 +163,8 @@ reusing stale cached connections." (if (or (and (eq? key 'system-error) (= EPIPE (system-error-errno `(,key ,@args)))) (and (eq? key 'gnutls-error) - (eq? (first args) error/invalid-session)) + (memq (first args) + (list error/again error/invalid-session))) (memq key '(bad-response bad-header bad-header-component))) #f @@ -207,15 +208,14 @@ returning." ;; Inherit the HTTP proxying property from P. (set-http-proxy-port?! buffer (http-proxy-port? p)) - (unless (false-if-networking-error - (begin - (for-each (cut write-request <> buffer) batch) - (put-bytevector p (get)) - (force-output p) - #t)) - ;; If PORT becomes unusable, open a fresh connection and retry. - (close-port p) ; close the broken port - (connect #f requests result))) + ;; Swallow networking errors that could occur due to connection reuse + ;; and the like; they will be handled down the road when trying to + ;; read responses. + (false-if-networking-error + (begin + (for-each (cut write-request <> buffer) batch) + (put-bytevector p (get)) + (force-output p)))) ;; Now start processing responses. (let loop ((sent batch) diff --git a/guix/scripts/substitute.scm b/guix/scripts/substitute.scm index 48309f9b3a..65940591a9 100755 --- a/guix/scripts/substitute.scm +++ b/guix/scripts/substitute.scm @@ -45,7 +45,7 @@ #:select (uri-abbreviation nar-uri-abbreviation (open-connection-for-uri . guix:open-connection-for-uri))) - #:autoload (gnutls) (error/invalid-session) + #:autoload (gnutls) (error/invalid-session error/again) #:use-module (guix progress) #:use-module ((guix build syscalls) #:select (set-thread-name)) @@ -417,7 +417,8 @@ server certificates." (if (or (and (eq? key 'system-error) (= EPIPE (system-error-errno `(,key ,@args)))) (and (eq? key 'gnutls-error) - (eq? (first args) error/invalid-session)) + (memq (first args) + (list error/again error/invalid-session))) (memq key '(bad-response bad-header bad-header-component))) (proc (open-connection-for-uri/cached uri #:verify-certificate? #f --=-=-=--