From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from mp12.migadu.com ([2001:41d0:8:6d80::]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits)) by ms5.migadu.com with LMTPS id OJmuBwOkuGNhhgEAbAwnHQ (envelope-from ) for ; Fri, 06 Jan 2023 23:43:15 +0100 Received: from aspmx1.migadu.com ([2001:41d0:8:6d80::]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits)) by mp12.migadu.com with LMTPS id yBGXBwOkuGPyfwEAauVa8A (envelope-from ) for ; Fri, 06 Jan 2023 23:43:15 +0100 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 90A471E337 for ; Fri, 6 Jan 2023 23:43:13 +0100 (CET) Received: from localhost ([::1] helo=lists1p.gnu.org) by lists.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1pDvQW-00074h-Bs; Fri, 06 Jan 2023 17:43:04 -0500 Received: from eggs.gnu.org ([2001:470:142:3::10]) by lists.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1pDvQU-00074X-UP for bug-guix@gnu.org; Fri, 06 Jan 2023 17:43:02 -0500 Received: from debbugs.gnu.org ([209.51.188.43]) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_128_GCM_SHA256:128) (Exim 4.90_1) (envelope-from ) id 1pDvQU-0004NE-MN for bug-guix@gnu.org; Fri, 06 Jan 2023 17:43:02 -0500 Received: from Debian-debbugs by debbugs.gnu.org with local (Exim 4.84_2) (envelope-from ) id 1pDvQU-00066O-FO for bug-guix@gnu.org; Fri, 06 Jan 2023 17:43:02 -0500 X-Loop: help-debbugs@gnu.org Subject: bug#48468: substitute server connection timeout Resent-From: Ludovic =?UTF-8?Q?Court=C3=A8s?= Original-Sender: "Debbugs-submit" Resent-CC: bug-guix@gnu.org Resent-Date: Fri, 06 Jan 2023 22:43:02 +0000 Resent-Message-ID: Resent-Sender: help-debbugs@gnu.org X-GNU-PR-Message: followup 48468 X-GNU-PR-Package: guix X-GNU-PR-Keywords: To: Mathieu Othacehe Cc: 48468@debbugs.gnu.org Received: via spool by 48468-submit@debbugs.gnu.org id=B48468.167304497823447 (code B ref 48468); Fri, 06 Jan 2023 22:43:02 +0000 Received: (at 48468) by debbugs.gnu.org; 6 Jan 2023 22:42:58 +0000 Received: from localhost ([127.0.0.1]:56000 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1pDvQQ-000665-BQ for submit@debbugs.gnu.org; Fri, 06 Jan 2023 17:42:58 -0500 Received: from eggs.gnu.org ([209.51.188.92]:48656) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1pDvQO-00065t-KE for 48468@debbugs.gnu.org; Fri, 06 Jan 2023 17:42:57 -0500 Received: from fencepost.gnu.org ([2001:470:142:3::e]) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1pDvQI-0004M3-VE for 48468@debbugs.gnu.org; Fri, 06 Jan 2023 17:42:51 -0500 DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=gnu.org; s=fencepost-gnu-org; h=MIME-Version:In-Reply-To:Date:References:Subject:To: From; bh=whBnKolx2dU774Oks/UTuIWS1dsEoVXfJ5gnW8ZPumw=; b=R/PzVWCZHbk0BOI6Kcjs EhM1V4SFSb/Zpm5ByaG2B042Ws90AjF4rwq5FPUMau0QLrPqrxH1q9N6dP84JrL6FWDvL9fmSKzgw ZzqSY7ds40OgPz8RT5CEO6XSNuLndRbQg0D6QNCgDnqHSpzGT1R+Ez9yXSWf1EjGhn/hJPqt5Udf6 Z/i0vlBf9JCxQ5RlgLT99cytTLItbTaf5vyASilpLlnzY9tV6pfpzqlXgTK/JgEDvOfEItS4eXYw/ bcNaBfldJ8DsB8BsLIo8ISHDmskqqOIoQ/y9e6nhrBdukmqU9MwP3JO1zAv55+h5yGLbM2aSoBVlt fcJzq4AzUOxciA==; Received: from [2a01:e0a:1d:7270:af76:b9b:ca24:c465] (helo=ribbon) by fencepost.gnu.org with esmtpsa (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1pDvQH-0007ra-Kf; Fri, 06 Jan 2023 17:42:50 -0500 From: Ludovic =?UTF-8?Q?Court=C3=A8s?= References: <87lf8e4l42.fsf@gnu.org> <87im2bfj3i.fsf@gnu.org> <87sg108vl5.fsf@gnu.org> <87lenmrnos.fsf@gnu.org> <87cz8v8s66.fsf@gnu.org> <87cz8vjpv2.fsf@gnu.org> <878rjj8eun.fsf@gnu.org> <87wn72fay3.fsf@gnu.org> <87v8lvsj3a.fsf@gnu.org> X-URL: http://www.fdn.fr/~lcourtes/ X-Revolutionary-Date: Septidi 17 =?UTF-8?Q?Niv=C3=B4se?= an 231 de la =?UTF-8?Q?R=C3=A9volution,?= jour de la Marne 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: Fri, 06 Jan 2023 23:42:47 +0100 In-Reply-To: <87v8lvsj3a.fsf@gnu.org> (Mathieu Othacehe's message of "Wed, 28 Dec 2022 15:23:21 +0100") Message-ID: <87mt6vxp20.fsf@gnu.org> User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/28.2 (gnu/linux) MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable 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: , Errors-To: bug-guix-bounces+larch=yhetil.org@gnu.org Sender: bug-guix-bounces+larch=yhetil.org@gnu.org X-Migadu-Country: US X-Migadu-Flow: FLOW_IN ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=yhetil.org; s=key1; t=1673044994; 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: content-transfer-encoding:content-transfer-encoding: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:dkim-signature; bh=whBnKolx2dU774Oks/UTuIWS1dsEoVXfJ5gnW8ZPumw=; b=D/phNLRjFP/uVa5RmOW7uBPF6n1HQcJ0KguNBCoxCda7mkS8H7+Yjne/RqEj5v6eH2eySg J1sGIqC60812g61Jy+698GDPob4CTRYozZkGzBM7UvZt6+y9oyr/E1bxiJFxX70P6doPu9 cJ4ygVqvE3qsQSEyI0dDf4z2lEEUMKctcGjP6ieMVY31kFhiAMWLILkrQnWBrBq2WL1H2J cerPzGPiL+e2yyJc5/mbBrh2OvYFaPK6Sc6196v1u7JR+O13l97aBbKxYIexIafNXyR6Xn N61CZ4h/4cu65SW/ATaWXWKxyE9371K7awAtIxf2Anm47JRISh/V25NCAYWMLQ== ARC-Authentication-Results: i=1; aspmx1.migadu.com; dkim=fail ("headers rsa verify failed") header.d=gnu.org header.s=fencepost-gnu-org header.b="R/PzVWCZ"; spf=pass (aspmx1.migadu.com: domain of "bug-guix-bounces+larch=yhetil.org@gnu.org" designates 209.51.188.17 as permitted sender) smtp.mailfrom="bug-guix-bounces+larch=yhetil.org@gnu.org"; dmarc=pass (policy=none) header.from=gnu.org ARC-Seal: i=1; s=key1; d=yhetil.org; t=1673044994; a=rsa-sha256; cv=none; b=cIkIQ3+v9gCL59kgUQaMn27vDKhEwA65rEkzIWOSNbEPPBwSlC1D2ODNcWe2Nxs9FUB3ec mzh2oD3jjXXh45AJDJLdktWRIOchaItvW8TltC6ZbUckXPwnn6b7Usj4sRHQcsrjOTHxOa t8gBVUui4l5Gcequ/qdFK1DCTnzIWFjEbArE7NS4AwEUrBzRV9PsWqpPHu3FUS6oJIwxT8 Abc6H378xBk4CMQzGadm6bPtxTngNxwGx2OFWkKzpjpq5iPmwlzI7vqWLLk0pEYZM5W1v4 dx2nMlPRVTcVH0JnsRkmT1WpsY1bJQaur72ZjaO2OKE/cvDp10+RCMXaCDV1Pg== X-Spam-Score: -3.96 X-Migadu-Queue-Id: 90A471E337 Authentication-Results: aspmx1.migadu.com; dkim=fail ("headers rsa verify failed") header.d=gnu.org header.s=fencepost-gnu-org header.b="R/PzVWCZ"; spf=pass (aspmx1.migadu.com: domain of "bug-guix-bounces+larch=yhetil.org@gnu.org" designates 209.51.188.17 as permitted sender) smtp.mailfrom="bug-guix-bounces+larch=yhetil.org@gnu.org"; dmarc=pass (policy=none) header.from=gnu.org X-Migadu-Scanner: scn1.migadu.com X-Migadu-Spam-Score: -3.96 X-TUID: 4vLJkwFSKs9u Hi Mathieu! Mathieu Othacehe skribis: >> (From .) >> >> Plausible explanations that come to mind: >> >> 1. =E2=80=98guix publish=E2=80=99 returning 404, but not due to baking= . Instead the >> .drv is simply not in store, hence 404. >> >> 2. Client timeout (=E2=80=98guix publish=E2=80=99 fails to reply on ti= me). >> >> 3. Cached 404 in nginx (though we=E2=80=99re not supposed to cache tho= se I >> think?), or timeout in nginx (again due to =E2=80=98guix publish=E2= =80=99 being too >> slow and =E2=80=98proxy_read_timeout=E2=80=99 is reached, currently= 10s). > > I focused on https://ci.guix.gnu.org/build/308493/details which is > similar to the one linked above. Some derivations are successfully > substituted then, one is not and it aborts. > > This build stopped at 2022/12/24 00:25:38 CET. At that time the nginx err= or > log on Berlin looks like: > > 2022/12/24 00:25:23 [info] 128755#0: *178076209 recv() failed (104: Conne= ction reset by peer) while sending to client, client: 78.X.Y.Z, server: ci.= guix.gnu.org, request: "GET /x3c2f9zzxhk0ci81nrdsxzglp4b1h3di.narinfo HTTP/= 1.1", upstream: "http://127.0.0.1:3000/x3c2f9zzxhk0ci81nrdsxzglp4b1h3di.nar= info", host: "ci.guix.gnu.org" It means that upstream (i.e., =E2=80=98guix publish=E2=80=99) closed the co= nnection, right? And it means that it closed it prematurely I guess? > However, like suggested in your hypothesis number 1, it seems instead > that we are replying 404 to the worker which resets the connection. As > we have put aside the baking thing, the question is now why are those > derivations not available? In that case we=E2=80=99re not replying at all, are we? > From 9f9c839937ac2edd1b5901b2262c4be0954fa20c Mon Sep 17 00:00:00 2001 > From: Mathieu Othacehe > Date: Wed, 28 Dec 2022 15:12:46 +0100 > Subject: [PATCH 1/2] scripts: publish: Add a custom baking header. > > Log the not-found responses and their reason (baking or not) to stdout. A= lso > send the X-Baking custom header so that the client can be informed of the > cause of the failure. > > * guix/scripts/publish.scm (not-found): Add a baking? argument to add the > X-Baking HTTP header to the response if baking is in progress. Also, log= the > 404 responses to stdout, indicating if it is due to baking or not. > (render-narinfo/cached): Pass the baking? argument. [...] > (define* (not-found request > - #:key (phrase "Resource not found") > + #:key > + baking? > + (phrase "Resource not found") > ttl) > "Render 404 response for REQUEST." > + (format #t (G_ "=E2=86=B3 ~a ~a: 404~a~%") Drop =E2=80=98G_=E2=80=99 (we don=E2=80=99t translate debugging messages) a= nd use ASCII, to be on the safe side=E2=80=A6 > From 25ffc57864dbf34ca58741f89c1f790dbde6702f Mon Sep 17 00:00:00 2001 > From: Mathieu Othacehe > Date: Wed, 28 Dec 2022 15:19:29 +0100 > Subject: [PATCH 2/2] substitutes: Log the failing queries. > > * guix/substitutes.scm (%debug?): New variable. > (handle-narinfo-response): Log the failing queries if the %debug? paramet= er is > set. [...] > +(define %debug? > + ;; Enable debug mode by setting the GUIX_SUBSTITUTE_DEBUG environmnent > + ;; variable. > + (make-parameter > + (getenv "GUIX_SUBSTITUTE_DEBUG"))) Instead of an env. var., maybe add a =E2=80=98--debug=E2=80=99 command-line= option and parameterize =E2=80=98%debug?=E2=80=99 accordingly? You can also have something like: (define-syntax (debug fmt args ...) (when (%debug?) (format #t fmt args ...))) LGTM with changes along these lines! Thanks, Ludo=E2=80=99.