GNU bug report logs - #26705
'guix publish' does not handle guix-daemon disconnections

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: important; Reported by: Mark H Weaver <mhw@HIDDEN>; dated Fri, 28 Apr 2017 22:35:01 UTC; Maintainer for guix is bug-guix@HIDDEN.
Severity set to 'important' from 'serious' Request was from ludo@HIDDEN (Ludovic Courtès) to control <at> debbugs.gnu.org. Full text available.
Changed bug title to ''guix publish' does not handle guix-daemon disconnections' from 'guix publish daemon on Hydra became dysfunctional; needed restart' Request was from ludo@HIDDEN (Ludovic Courtès) to control <at> debbugs.gnu.org. Full text available.

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


Received: (at 26705) by debbugs.gnu.org; 2 May 2017 09:14:48 +0000
From debbugs-submit-bounces <at> debbugs.gnu.org Tue May 02 05:14:48 2017
Received: from localhost ([127.0.0.1]:50296 helo=debbugs.gnu.org)
	by debbugs.gnu.org with esmtp (Exim 4.84_2)
	(envelope-from <debbugs-submit-bounces <at> debbugs.gnu.org>)
	id 1d5TtQ-0007e5-I0
	for submit <at> debbugs.gnu.org; Tue, 02 May 2017 05:14:48 -0400
Received: from eggs.gnu.org ([208.118.235.92]:46434)
 by debbugs.gnu.org with esmtp (Exim 4.84_2)
 (envelope-from <ludo@HIDDEN>) id 1d5TtO-0007dr-QA
 for 26705 <at> debbugs.gnu.org; Tue, 02 May 2017 05:14:47 -0400
Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71)
 (envelope-from <ludo@HIDDEN>) id 1d5TtE-0002Ms-Km
 for 26705 <at> debbugs.gnu.org; Tue, 02 May 2017 05:14:41 -0400
X-Spam-Checker-Version: SpamAssassin 3.3.2 (2011-06-06) on eggs.gnu.org
X-Spam-Level: 
X-Spam-Status: No, score=0.8 required=5.0 tests=BAYES_50,RP_MATCHES_RCVD
 autolearn=disabled version=3.3.2
Received: from fencepost.gnu.org ([2001:4830:134:3::e]:55332)
 by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from <ludo@HIDDEN>)
 id 1d5TtE-0002Mg-Gd; Tue, 02 May 2017 05:14:36 -0400
Received: from [193.50.110.185] (port=43586 helo=ribbon)
 by fencepost.gnu.org with esmtpsa (TLS1.2:RSA_AES_256_CBC_SHA1:256)
 (Exim 4.82) (envelope-from <ludo@HIDDEN>)
 id 1d5TtD-0000xq-QS; Tue, 02 May 2017 05:14:36 -0400
From: ludo@HIDDEN (Ludovic =?utf-8?Q?Court=C3=A8s?=)
To: Mark H Weaver <mhw@HIDDEN>
Subject: Re: bug#26705: guix publish daemon on Hydra became dysfunctional;
 needed restart
References: <877f24xiv9.fsf@HIDDEN>
Date: Tue, 02 May 2017 11:14:33 +0200
In-Reply-To: <877f24xiv9.fsf@HIDDEN> (Mark H. Weaver's message of "Fri, 28
 Apr 2017 18:33:30 -0400")
Message-ID: <878tmflix2.fsf@HIDDEN>
User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/25.2 (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-Received-From: 2001:4830:134:3::e
X-Spam-Score: -5.0 (-----)
X-Debbugs-Envelope-To: 26705
Cc: 26705 <at> debbugs.gnu.org
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: -5.0 (-----)

Hello,

Mark H Weaver <mhw@HIDDEN> skribis:

> While trying to update my GuixSD system in the last hour, I found that
> every attempt by the substituter to download NARs resulted in a 500
> "Internal Server Error":

[...]

> Bypassing the mirror didn't help:

Did you try talking directly to =E2=80=98guix publish=E2=80=99 (localhost:9=
999 on
hydra.gnu.org)?

> Here's what I found in the recent output of the 'guix publish' server on
> Hydra (running in root's screen session):
>
> GET /74ch6nvjfkj3i56nygwijnaghlpi01d4.narinfo
> In guix/scripts/publish.scm:
>     393:2  2 (render-narinfo/cached #<build-daemon 256.96 211f7c0> ...)
> In guix/store.scm:
>     663:9  1 (query-path-from-hash-part #<build-daemon 256.96 2...> #)
> In unknown file:
>            0 (put-bytevector #<input-output: socket 12> #vu8(# ...) ...)
> ERROR: In procedure fport_write: Broken pipe
> GET /guix/nar/qz4mg7sid6avdav158lhr6wziqswpjmx-gnome-calendar-3.22.2.tar.=
xz
> In guix/scripts/publish.scm:
>     491:8  2 (render-nar #<build-daemon 256.96 211f7c0> #<<requ...> ...)
> In guix/store.scm:
>     648:0  1 (valid-path? #<build-daemon 256.96 211f7c0> "/gnu/sto...")
> In unknown file:
>            0 (put-bytevector #<input-output: socket 12> #vu8(1 ...) ...)
> ERROR: In procedure fport_write: Broken pipe

Ooh, the connection to the daemon was broken, hence this error.

Currently =E2=80=98guix publish=E2=80=99 assumes the connection opened in t=
he
=E2=80=98guix-publish=E2=80=99 procedure remains valid all along.  That=E2=
=80=99s normally the
case unless (1) the daemon is restarted, or (2) there=E2=80=99s a protocol =
error
somewhere that leads the daemon to close the connection.

#2 is not supposed to happen, but could happen if, for instance, an
exception is thrown before we have read the RPC reply sent by the
daemon.

Perhaps =E2=80=98guix publish=E2=80=99 could catch EPIPE when talking to th=
e daemon?
(Currently EPIPEs are swallowed by =E2=80=98handle-request=E2=80=99 in (web=
 server) and
converted to 500.)

That said, if there really is a situation where =E2=80=98guix publish=E2=80=
=99 can
violate the daemon protocol, that=E2=80=99s what should be fixed.

Thoughts?

Thanks for handling this quickly!

Ludo=E2=80=99.




Information forwarded to bug-guix@HIDDEN:
bug#26705; Package guix. Full text available.
Severity set to 'serious' from 'normal' Request was from ludo@HIDDEN (Ludovic Courtès) 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 Apr 2017 22:34:08 +0000
From debbugs-submit-bounces <at> debbugs.gnu.org Fri Apr 28 18:34:08 2017
Received: from localhost ([127.0.0.1]:45212 helo=debbugs.gnu.org)
	by debbugs.gnu.org with esmtp (Exim 4.84_2)
	(envelope-from <debbugs-submit-bounces <at> debbugs.gnu.org>)
	id 1d4ESm-00084b-8N
	for submit <at> debbugs.gnu.org; Fri, 28 Apr 2017 18:34:08 -0400
Received: from eggs.gnu.org ([208.118.235.92]:36147)
 by debbugs.gnu.org with esmtp (Exim 4.84_2)
 (envelope-from <mhw@HIDDEN>) id 1d4ESj-000847-M8
 for submit <at> debbugs.gnu.org; Fri, 28 Apr 2017 18:34:06 -0400
Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71)
 (envelope-from <mhw@HIDDEN>) id 1d4ESd-0006kl-6f
 for submit <at> debbugs.gnu.org; Fri, 28 Apr 2017 18:34:00 -0400
X-Spam-Checker-Version: SpamAssassin 3.3.2 (2011-06-06) on eggs.gnu.org
X-Spam-Level: 
X-Spam-Status: No, score=0.8 required=5.0 tests=BAYES_50 autolearn=disabled
 version=3.3.2
Received: from lists.gnu.org ([2001:4830:134:3::11]:44213)
 by eggs.gnu.org with esmtps (TLS1.0:RSA_AES_256_CBC_SHA1:32)
 (Exim 4.71) (envelope-from <mhw@HIDDEN>) id 1d4ESd-0006ka-3V
 for submit <at> debbugs.gnu.org; Fri, 28 Apr 2017 18:33:59 -0400
Received: from eggs.gnu.org ([2001:4830:134:3::10]:55334)
 by lists.gnu.org with esmtp (Exim 4.71)
 (envelope-from <mhw@HIDDEN>) id 1d4ESb-0004X5-FC
 for bug-guix@HIDDEN; Fri, 28 Apr 2017 18:33:58 -0400
Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71)
 (envelope-from <mhw@HIDDEN>) id 1d4ESW-0006a3-DC
 for bug-guix@HIDDEN; Fri, 28 Apr 2017 18:33:57 -0400
Received: from world.peace.net ([50.252.239.5]:38201)
 by eggs.gnu.org with esmtps (TLS1.0:RSA_AES_128_CBC_SHA1:16)
 (Exim 4.71) (envelope-from <mhw@HIDDEN>) id 1d4ESW-0006NL-9Q
 for bug-guix@HIDDEN; Fri, 28 Apr 2017 18:33:52 -0400
Received: from turntable.mit.edu ([18.160.0.29] helo=jojen)
 by world.peace.net with esmtpsa (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256)
 (Exim 4.84_2) (envelope-from <mhw@HIDDEN>)
 id 1d4ESL-0001oF-0R; Fri, 28 Apr 2017 18:33:41 -0400
From: Mark H Weaver <mhw@HIDDEN>
To: bug-guix@HIDDEN
Subject: guix publish daemon on Hydra became dysfunctional; needed restart
Date: Fri, 28 Apr 2017 18:33:30 -0400
Message-ID: <877f24xiv9.fsf@HIDDEN>
MIME-Version: 1.0
Content-Type: text/plain
X-detected-operating-system: by eggs.gnu.org: GNU/Linux 2.2.x-3.x [generic]
 [fuzzy]
X-detected-operating-system: by eggs.gnu.org: GNU/Linux 2.6.x
X-Received-From: 2001:4830:134:3::11
X-Spam-Score: -5.0 (-----)
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: -5.0 (-----)

While trying to update my GuixSD system in the last hour, I found that
every attempt by the substituter to download NARs resulted in a 500
"Internal Server Error":

--8<---------------cut here---------------start------------->8---
mhw@jojen ~$ guix package -u
substitute: ^Msubstitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'...   0.0%^Msubstitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
Downloading https://mirror.hydra.gnu.org/guix/nar/qz4mg7sid6avdav158lhr6wziqswpjmx-gnome-calendar-3.22.2.tar.xz (2.3MiB installed)...
guix substitute: error: download from 'https://mirror.hydra.gnu.org/guix/nar/qz4mg7sid6avdav158lhr6wziqswpjmx-gnome-calendar-3.22.2.tar.xz' failed: 500, "Internal Server Error"
guix package: error: build failed: some substitutes for the outputs of derivation `/gnu/store/l58cq0l2j2ikyimjvxyv1dakha2ai6rx-gnome-calendar-3.22.2.tar.xz.drv' failed (usually happens due to networking issues); try `--fallback' to build derivation from source
mhw@jojen ~$ guix package -u
Downloading https://mirror.hydra.gnu.org/guix/nar/qz4mg7sid6avdav158lhr6wziqswpjmx-gnome-calendar-3.22.2.tar.xz (2.3MiB installed)...
guix substitute: error: download from 'https://mirror.hydra.gnu.org/guix/nar/qz4mg7sid6avdav158lhr6wziqswpjmx-gnome-calendar-3.22.2.tar.xz' failed: 500, "Internal Server Error"
guix package: error: build failed: some substitutes for the outputs of derivation `/gnu/store/l58cq0l2j2ikyimjvxyv1dakha2ai6rx-gnome-calendar-3.22.2.tar.xz.drv' failed (usually happens due to networking issues); try `--fallback' to build derivation from source
--8<---------------cut here---------------end--------------->8---

Bypassing the mirror didn't help:

--8<---------------cut here---------------start------------->8---
mhw@jojen ~$ guix package -u . --substitute-urls=https://hydra.gnu.org
substitute: ^Msubstitute: updating list of substitutes from 'https://hydra.gnu.org'...   0.0%^Msubstitute: updating list of substitutes from 'https://hydra.gnu.org'... 100.0%
substitute: ^Msubstitute: updating list of substitutes from 'https://hydra.gnu.org'...   0.0%^Msubstitute: updating list of substitutes from 'https://hydra.gnu.org'... 100.0%
Downloading https://hydra.gnu.org/guix/nar/qz4mg7sid6avdav158lhr6wziqswpjmx-gnome-calendar-3.22.2.tar.xz (2.3MiB installed)...
guix substitute: error: download from 'https://hydra.gnu.org/guix/nar/qz4mg7sid6avdav158lhr6wziqswpjmx-gnome-calendar-3.22.2.tar.xz' failed: 500, "Internal Server Error"
guix package: error: build failed: some substitutes for the outputs of derivation `/gnu/store/l58cq0l2j2ikyimjvxyv1dakha2ai6rx-gnome-calendar-3.22.2.tar.xz.drv' failed (usually happens due to networking issues); try `--fallback' to build derivation from source
--8<---------------cut here---------------end--------------->8---

Here's what I found in the recent output of the 'guix publish' server on
Hydra (running in root's screen session):

--8<---------------cut here---------------start------------->8---
GET /74ch6nvjfkj3i56nygwijnaghlpi01d4.narinfo
In guix/scripts/publish.scm:
    393:2  2 (render-narinfo/cached #<build-daemon 256.96 211f7c0> ...)
In guix/store.scm:
    663:9  1 (query-path-from-hash-part #<build-daemon 256.96 2...> #)
In unknown file:
           0 (put-bytevector #<input-output: socket 12> #vu8(# ...) ...)
ERROR: In procedure fport_write: Broken pipe
GET /guix/nar/qz4mg7sid6avdav158lhr6wziqswpjmx-gnome-calendar-3.22.2.tar.xz
In guix/scripts/publish.scm:
    491:8  2 (render-nar #<build-daemon 256.96 211f7c0> #<<requ...> ...)
In guix/store.scm:
    648:0  1 (valid-path? #<build-daemon 256.96 211f7c0> "/gnu/sto...")
In unknown file:
           0 (put-bytevector #<input-output: socket 12> #vu8(1 ...) ...)
ERROR: In procedure fport_write: Broken pipe
GET /zhxab8rkbbalgrlhg86q8pzpqi3s6q36.narinfo
In guix/scripts/publish.scm:
    393:2  2 (render-narinfo/cached #<build-daemon 256.96 211f7c0> ...)
In guix/store.scm:
    663:9  1 (query-path-from-hash-part #<build-daemon 256.96 2...> #)
In unknown file:
           0 (put-bytevector #<input-output: socket 12> #vu8(# ...) ...)
ERROR: In procedure fport_write: Broken pipe
GET /z2rygpahxbpkwx8k164bi5lr5lann357.narinfo
In guix/scripts/publish.scm:
    393:2  2 (render-narinfo/cached #<build-daemon 256.96 211f7c0> ...)
In guix/store.scm:
    663:9  1 (query-path-from-hash-part #<build-daemon 256.96 2...> #)
In unknown file:
           0 (put-bytevector #<input-output: socket 12> #vu8(# ...) ...)
ERROR: In procedure fport_write: Broken pipe
GET /yw635wxpm4ac40khzd9w6j9v3n72a708.narinfo
In guix/scripts/publish.scm:
    393:2  2 (render-narinfo/cached #<build-daemon 256.96 211f7c0> ...)
In guix/store.scm:
    663:9  1 (query-path-from-hash-part #<build-daemon 256.96 2...> #)
In unknown file:
           0 (put-bytevector #<input-output: socket 12> #vu8(# ...) ...)
ERROR: In procedure fport_write: Broken pipe
--8<---------------cut here---------------end--------------->8---

I killed the process, restarted it, and now things seem to be working
again, but it would be good to know what went wrong here.

      Mark




Acknowledgement sent to Mark H Weaver <mhw@HIDDEN>:
New bug report received and forwarded. Copy sent to bug-guix@HIDDEN. Full text available.
Report forwarded to bug-guix@HIDDEN:
bug#26705; 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, 27 Jul 2017 12:45:02 UTC

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