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 ms0.migadu.com with LMTPS id kNTpFjH+IWGgIQEAgWs5BA (envelope-from ) for ; Sun, 22 Aug 2021 09:35:13 +0200 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 ICDvETH+IWGAKwAAbx9fmQ (envelope-from ) for ; Sun, 22 Aug 2021 07:35:13 +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 432B3FBF8 for ; Sun, 22 Aug 2021 09:35:12 +0200 (CEST) Received: from localhost ([::1]:44792 helo=lists1p.gnu.org) by lists.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1mHi0d-0002tD-6Q for larch@yhetil.org; Sun, 22 Aug 2021 03:35:11 -0400 Received: from eggs.gnu.org ([2001:470:142:3::10]:59046) by lists.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1mHi0V-0002s3-48 for guix-patches@gnu.org; Sun, 22 Aug 2021 03:35:03 -0400 Received: from debbugs.gnu.org ([209.51.188.43]:54789) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_128_GCM_SHA256:128) (Exim 4.90_1) (envelope-from ) id 1mHi0U-0007GU-Rq for guix-patches@gnu.org; Sun, 22 Aug 2021 03:35:02 -0400 Received: from Debian-debbugs by debbugs.gnu.org with local (Exim 4.84_2) (envelope-from ) id 1mHi0U-0007Hh-DU for guix-patches@gnu.org; Sun, 22 Aug 2021 03:35:02 -0400 X-Loop: help-debbugs@gnu.org Subject: [bug#50040] [PATCH 0/2] publish: Always render nar/narinfo during backing. Resent-From: Mathieu Othacehe Original-Sender: "Debbugs-submit" Resent-CC: guix-patches@gnu.org Resent-Date: Sun, 22 Aug 2021 07:35:02 +0000 Resent-Message-ID: Resent-Sender: help-debbugs@gnu.org X-GNU-PR-Message: followup 50040 X-GNU-PR-Package: guix-patches X-GNU-PR-Keywords: patch To: 50040@debbugs.gnu.org Received: via spool by 50040-submit@debbugs.gnu.org id=B50040.162961764827901 (code B ref 50040); Sun, 22 Aug 2021 07:35:02 +0000 Received: (at 50040) by debbugs.gnu.org; 22 Aug 2021 07:34:08 +0000 Received: from localhost ([127.0.0.1]:38102 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1mHhzY-0007Fs-Lg for submit@debbugs.gnu.org; Sun, 22 Aug 2021 03:34:08 -0400 Received: from eggs.gnu.org ([209.51.188.92]:42862) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1mHhzT-0007F9-4T for 50040@debbugs.gnu.org; Sun, 22 Aug 2021 03:34:02 -0400 Received: from fencepost.gnu.org ([2001:470:142:3::e]:41374) by eggs.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1mHhzN-0006Jk-QP for 50040@debbugs.gnu.org; Sun, 22 Aug 2021 03:33:53 -0400 Received: from [2a01:cb18:832e:5f00:3563:417e:2a38:86d8] (port=58406 helo=meije) by fencepost.gnu.org with esmtpsa (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1mHhzN-0003Kc-FE for 50040@debbugs.gnu.org; Sun, 22 Aug 2021 03:33:53 -0400 From: Mathieu Othacehe In-Reply-To: <20210813102800.805-1-othacehe@gnu.org> (Mathieu Othacehe's message of "Fri, 13 Aug 2021 12:28:00 +0200") References: <20210813102800.805-1-othacehe@gnu.org> User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/27.2 (gnu/linux) Date: Sun, 22 Aug 2021 09:33:51 +0200 Message-ID: <87sfz2j5ls.fsf@gnu.org> MIME-Version: 1.0 Content-Type: text/plain X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list X-BeenThere: guix-patches@gnu.org List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: guix-patches-bounces+larch=yhetil.org@gnu.org Sender: "Guix-patches" X-Migadu-Flow: FLOW_IN ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=yhetil.org; s=key1; t=1629617712; h=from:from:sender:sender:reply-to:subject:subject:date:date: message-id:message-id:to:to: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=iedjyVHMFyjjKEY2KlsZwWXmd8wXQ63RJxs0pc3sesM=; b=d4bQaWzYr6GblrQtj6AzjXLcdeDAUsX4OCzDrd4oP1rLoqNGecqwDf5ErWRSiTKtsZ8mej 4vqWIT0mVx0lJA52kaUauzmenkaIO7DduyL9kA3t3KU/tZ7pox11Vzjoh836k9eKr5sosY oTuBGq9/oG0t98M1MriHk/WxB2j+mXoPQQOy+aLiTPp7cXh1MHL3kFiDNA+doBRnGvtZk0 SErHlienBasJWkZMpaJNbnb/TzhsQjAnxYOIDEGN+WhH3+GU/wEC6o5c3fJl+OtTYa8+3u XCbHfiaLyHCTUl9XzWnF/YjrdER8DFGLiepGx/1hQjk+RnxgigUxRVONOth8rw== ARC-Seal: i=1; s=key1; d=yhetil.org; t=1629617712; a=rsa-sha256; cv=none; b=T+51njrWgV2KXYFeenR76LiKzdgxkR5eMkGrrgijfHjbAYfLgMHpc8l+KJQ35eWoEXBROJ N5T0HymyuYnQwrYQGtvGrEFLsCNvvc3AOvvBGNyJ9ahvbY1lpd6zYeVA3ERyBS4Q9ucFzo tfOjZ/fuO0J/7Re0RB0geEMOXvivMQ5kN+jBGTA7HuHc+CNWSIf9L0RRTxSYv4vuGxyHzR pidZChXP8irFzvzMDlSdQfXNNKtRKSiIlX//rELI97uZJrbosCRahfk7JJHVyJxl92CS8M 26YMg4E4+fe78NdCP6Yh4bnpW6Fc9S4FbJZXRsDn0Cl30fn2opfWogzzEQYLmg== 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-patches-bounces@gnu.org designates 209.51.188.17 as permitted sender) smtp.mailfrom=guix-patches-bounces@gnu.org X-Migadu-Spam-Score: -2.92 Authentication-Results: aspmx1.migadu.com; dkim=none; dmarc=pass (policy=none) header.from=gnu.org; spf=pass (aspmx1.migadu.com: domain of guix-patches-bounces@gnu.org designates 209.51.188.17 as permitted sender) smtp.mailfrom=guix-patches-bounces@gnu.org X-Migadu-Queue-Id: 432B3FBF8 X-Spam-Score: -2.92 X-Migadu-Scanner: scn0.migadu.com X-TUID: ETHSvQVBqRQx Hey, I increased the bypass cache value on the Berlin publish server from 50 to 500 MiB to confirm that this patch will help. Turns out, there are still some Cuirass errors. Running this command: --8<---------------cut here---------------start------------->8--- sudo strace -f -s 10000 -e write -p 124867 -p 124868 -p 124869 -p 124870 -p 124871 -p 124872 -p 124873 -p 124874 -p 124875 -p 124876 -p 124877 -p 124878 -p 124879 -p 124880 -p 124881 -p 124882 -p 124883 2>&1 |grep narinfo --8<---------------cut here---------------end--------------->8--- (The processes are all the Nginx workers) Shows those errors: --8<---------------cut here---------------start------------->8--- [pid 124867] write(4, "2021/08/21 22:17:40 [error] 124867#0: *16550606 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 141.80.167.167, server: ci.guix.gnu.org, request: \"GET /s03ydmlv5p7v206hvj5z1d4hn9nzsv2s.narinfo HTTP/1.1\", upstream: \"http://127.0.0.1:3000/s03ydmlv5p7v206hvj5z1d4hn9nzsv2s.narinfo\", host: \"141.80.167.131\"\n", 355) = 355 [pid 124869] write(4, "2021/08/21 22:17:40 [error] 124869#0: *16550621 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 141.80.167.175, server: ci.guix.gnu.org, request: \"GET /kfzipc676in0ff2im8zprbsgv9idrc9j.narinfo HTTP/1.1\", upstream: \"http://127.0.0.1:3000/kfzipc676in0ff2im8zprbsgv9idrc9j.narinfo\", host: \"141.80.167.131\"\n", 355 [pid 124867] write(4, "2021/08/21 22:17:41 [error] 124867#0: *16550771 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 141.80.167.158, server: ci.guix.gnu.org, request: \"GET /0mpspvh9h208vhrd3wxhw1165rz8mslb.narinfo HTTP/1.1\", upstream: \"http://127.0.0.1:3000/0mpspvh9h208vhrd3wxhw1165rz8mslb.narinfo\", host: \"141.80.167.131\"\n", 355) = 355 [pid 124867] write(4, "2021/08/21 22:17:41 [error] 124867#0: *16550774 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 141.80.167.163, server: ci.guix.gnu.org, request: \"GET /4hy6nms1lzgbdrwslw5dlilvvjlrz95g.narinfo HTTP/1.1\", upstream: \"http://127.0.0.1:3000/4hy6nms1lzgbdrwslw5dlilvvjlrz95g.narinfo\", host: \"141.80.167.131\"\n", 355) = 355 [pid 124867] write(4, "2021/08/21 22:17:42 [error] 124867#0: *16550628 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 141.80.167.173, server: ci.guix.gnu.org, request: \"GET /y9adqfkz8h3if17q3w801wfr0r91xdds.narinfo HTTP/1.1\", upstream: \"http://127.0.0.1:3000/y9adqfkz8h3if17q3w801wfr0r91xdds.narinfo\", host: \"141.80.167.131\"\n", 355) = 355 [pid 124867] write(4, "2021/08/21 22:17:42 [error] 124867#0: *16550471 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 141.80.167.178, server: ci.guix.gnu.org, request: \"GET /d6vvg1rsqya8cnhi2mzqqvin55qax3xy.narinfo HTTP/1.1\", upstream: \"http://127.0.0.1:3000/d6vvg1rsqya8cnhi2mzqqvin55qax3xy.narinfo\", host: \"141.80.167.131\"\n", 355) = 355 [pid 124867] write(4, "2021/08/21 22:17:42 [error] 124867#0: *16550606 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 141.80.167.167, server: ci.guix.gnu.org, request: \"GET /h3bd6psd2ijj5d9a8q46w2ldqsi135j0.narinfo HTTP/1.1\", upstream: \"http://127.0.0.1:3000/h3bd6psd2ijj5d9a8q46w2ldqsi135j0.narinfo\", host: \"141.80.167.131\"\n", 355) = 355 [pid 124867] write(4, "2021/08/21 22:17:42 [error] 124867#0: *16550780 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 141.80.167.184, server: ci.guix.gnu.org, request: \"GET /8jvzhavq2zkychyjhs0ywnz2mpgp73qz.narinfo HTTP/1.1\", upstream: \"http://127.0.0.1:3000/8jvzhavq2zkychyjhs0ywnz2mpgp73qz.narinfo\", host: \"141.80.167.131\"\n", 355) = 355 [pid 124868] write(4, "2021/08/21 22:17:43 [error] 124868#0: *16550782 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 127.0.0.1, server: ci.guix.gnu.org, request: \"GET /3wl6j74i18wgcyqwrvfjjcyag4w3ip3d.narinfo HTTP/1.1\", upstream: \"http://127.0.0.1:3000/3wl6j74i18wgcyqwrvfjjcyag4w3ip3d.narinfo\", host: \"127.0.0.1\"\n", 345) = 345 [pid 124868] write(4, "2021/08/21 22:17:43 [error] 124868#0: *16550784 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 141.80.167.161, server: ci.guix.gnu.org, request: \"GET /lf8lczjd7k55x2byql0rn5qpgibvl6kh.narinfo HTTP/1.1\", upstream: \"http://127.0.0.1:3000/lf8lczjd7k55x2byql0rn5qpgibvl6kh.narinfo\", host: \"141.80.167.131\"\n", 355) = 355 [pid 124867] write(4, "2021/08/21 22:17:43 [error] 124867#0: *16550786 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 141.80.167.177, server: ci.guix.gnu.org, request: \"GET /fvddmn01gx8amxlh6kvv8j7pcm6dxddn.narinfo HTTP/1.1\", upstream: \"http://127.0.0.1:3000/fvddmn01gx8amxlh6kvv8j7pcm6dxddn.narinfo\", host: \"141.80.167.131\"\n", 355) = 355 [pid 124867] write(4, "2021/08/21 22:17:44 [error] 124867#0: *16550788 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 141.80.167.183, server: ci.guix.gnu.org, request: \"GET /wcl4mlxpnn20q2f2mgc2hj7w21jf03iz.narinfo HTTP/1.1\", upstream: \"http://127.0.0.1:3000/wcl4mlxpnn20q2f2mgc2hj7w21jf03iz.narinfo\", host: \"141.80.167.131\"\n", 355) = 355 [pid 124867] write(4, "2021/08/21 22:17:44 [error] 124867#0: *16550471 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 141.80.167.178, server: ci.guix.gnu.org, request: \"GET /hakhzv36jl50mas5am4pwk89p428wnrl.narinfo HTTP/1.1\", upstream: \"http://127.0.0.1:3000/hakhzv36jl50mas5am4pwk89p428wnrl.narinfo\", host: \"141.80.167.131\"\n", 355) = 355 [pid 124867] write(4, "2021/08/21 22:17:44 [error] 124867#0: *16550606 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 141.80.167.167, server: ci.guix.gnu.org, request: \"GET /64fsv1vjf1mxkv6wv2wh3vkffzrgalyq.narinfo HTTP/1.1\", upstream: \"http://127.0.0.1:3000/64fsv1vjf1mxkv6wv2wh3vkffzrgalyq.narinfo\", host: \"141.80.167.131\"\n", 355) = 355 [pid 124867] write(4, "2021/08/21 22:17:44 [error] 124867#0: *16550796 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 141.80.167.159, server: ci.guix.gnu.org, request: \"GET /skbvrqdl64lph6k1ba5gay31spdbkm04.narinfo HTTP/1.1\", upstream: \"http://127.0.0.1:3000/skbvrqdl64lph6k1ba5gay31spdbkm04.narinfo\", host: \"141.80.167.131\"\n", 355) = 355 [pid 124867] write(4, "2021/08/21 22:17:45 [error] 124867#0: *16550799 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 141.80.167.164, server: ci.guix.gnu.org, request: \"GET /b9lrrh5zj7wjhgs93m1aaz0chbp7awzk.narinfo HTTP/1.1\", upstream: \"http://127.0.0.1:3000/b9lrrh5zj7wjhgs93m1aaz0chbp7awzk.narinfo\", host: \"141.80.167.131\"\n", 355) = 355 [pid 124867] write(4, "2021/08/21 22:17:45 [error] 124867#0: *16550802 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 127.0.0.1, server: ci.guix.gnu.org, request: \"GET /3sqsphfshnkpxk91zi38hh11ifq144n3.narinfo HTTP/1.1\", upstream: \"http://127.0.0.1:3000/3sqsphfshnkpxk91zi38hh11ifq144n3.narinfo\", host: \"127.0.0.1\"\n", 345) = 345 [pid 124867] write(4, "2021/08/21 22:17:45 [error] 124867#0: *16550804 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 141.80.167.185, server: ci.guix.gnu.org, request: \"GET /f8ld4yvmsp5z1850gppy6sv0g59yamh8.narinfo HTTP/1.1\", upstream: \"http://127.0.0.1:3000/f8ld4yvmsp5z1850gppy6sv0g59yamh8.narinfo\", host: \"141.80.167.131\"\n", 355) = 355 --8<---------------cut here---------------end--------------->8--- I think this is caused by the following lines in the Berlin Nginx configuration: --8<---------------cut here---------------start------------->8--- ;; Do not tolerate slowness of hydra.gnu.org when fetching ;; narinfos: better return 504 quickly than wait forever. "proxy_connect_timeout 2s;" "proxy_read_timeout 2s;" "proxy_send_timeout 2s;" --8<---------------cut here---------------end--------------->8--- The narinfos that are not in cache yet are computed in the main thread, slowing down the publish process. Under pressure, computing those narinfo can exceed the 2s timeout resulting in the failures above. Our best course of action here could be to merge the proposed patches, extend the Nginx timeout to 10s and see if all the requests can be handled quickly enough. Thanks, Mathieu