From debbugs-submit-bounces@debbugs.gnu.org Sat Oct 03 05:38:06 2020 Received: (at 43518) by debbugs.gnu.org; 3 Oct 2020 09:38:06 +0000 Received: from localhost ([127.0.0.1]:42994 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1kOdzS-0002xt-Hj for submit@debbugs.gnu.org; Sat, 03 Oct 2020 05:38:06 -0400 Received: from eggs.gnu.org ([209.51.188.92]:59692) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1kOdzP-0002xN-Ov for 43518@debbugs.gnu.org; Sat, 03 Oct 2020 05:38:04 -0400 Received: from fencepost.gnu.org ([2001:470:142:3::e]:52188) by eggs.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1kOdzK-0000in-Gd; Sat, 03 Oct 2020 05:37:58 -0400 Received: from [2a01:e0a:1d:7270:af76:b9b:ca24:c465] (port=43774 helo=ribbon) by fencepost.gnu.org with esmtpsa (TLS1.2:RSA_AES_256_CBC_SHA1:256) (Exim 4.82) (envelope-from ) id 1kOdzA-00009E-O6; Sat, 03 Oct 2020 05:37:58 -0400 From: =?utf-8?Q?Ludovic_Court=C3=A8s?= To: Maxim Cournoyer Subject: Re: bug#43518: Guix substitute crash in procedure raise-exception: wrong type agument in position 1: #f References: <87imc9y8hq.fsf@gmail.com> <873630plg1.fsf@gmail.com> <87wo0bxjvd.fsf@gnu.org> <87zh54ms9i.fsf@gmail.com> X-URL: http://www.fdn.fr/~lcourtes/ X-Revolutionary-Date: 12 =?utf-8?Q?Vend=C3=A9miaire?= an 229 de la =?utf-8?Q?R=C3=A9volution?= 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: Sat, 03 Oct 2020 11:37:47 +0200 In-Reply-To: <87zh54ms9i.fsf@gmail.com> (Maxim Cournoyer's message of "Fri, 02 Oct 2020 13:50:33 -0400") Message-ID: <87eemfhcpg.fsf@gnu.org> User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/27.1 (gnu/linux) MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-Spam-Score: -2.3 (--) X-Debbugs-Envelope-To: 43518 Cc: 43518@debbugs.gnu.org X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -3.3 (---) Hi, Maxim Cournoyer skribis: > Ludovic Court=C3=A8s writes: > >> Hi, >> >> Maxim Cournoyer skribis: >> >>> downloading from https://ci.guix.gnu.org/nar/6m9zimmw8p6gbc1yfbg454c1r5= 87b7h4-gcc-10.2.0.tar.xz ... >> [=E2=80=A6] >>> gcc-10.2.0.tar.xz 74.3MiB 1.1MiB/= s 00:25 [####### ] 39.1%Backtrace: >> [=E2=80=A6] >>> In unknown file: >>> 5 (display "@ substituter-succeeded /gnu/store/r06j3ms57z4mz= fpdzfclsi3i9hr4184g-module-imp=E2=80=A6" =E2=80=A6) >>> In guix/status.scm: >>> 699:16 4 (write! _ _ _) >>> 613:6 3 (_ (download-progress "/gnu/store/6m9zimmw8p6gbc1yfbg454c1= r587b7h4-gcc-10.2.0.tar.xz" # =E2=80=A6) =E2=80=A6) >>> In guix/progress.scm: >>> 213:14 2 (display-download-progress "6m9zimmw8p6gbc1yfbg454c1r58@" = _ #:start-time _ #:transferred _ =E2=80=A6) >>> In ice-9/boot-9.scm: >>> 1669:16 1 (raise-exception _ #:continuable? _) >>> 1669:16 0 (raise-exception _ #:continuable? _) >>> >>> ice-9/boot-9.scm:1669:16: In procedure raise-exception: >>> In procedure =3D: Wrong type argument in position 1: #f >> >> If you have a case that=E2=80=99s reproducible, please take advantage of= it and >> add =E2=80=98pk=E2=80=99 calls in (guix progress) to see what happens. = Here it seems >> that =E2=80=98transferred=E2=80=99 (in =E2=80=98display-download-progres= s=E2=80=99) is #f. >> >> The #f would come from this clause in (guix status): >> >> ('download-progress item uri >> (=3D string->number size) >> (=3D string->number transferred)) ;<- here >> >> That in turn comes from =E2=80=98progress-reporter/trace=E2=80=99, calle= d from (guix >> scripts substitute). > > It's a bit difficult for me to follow the calls here :-). I thought > it'd have to be in 'progress-reporter/file' because that's the only one > that ends up calling display-download-progress. The line 213 of (guix > progress) is: > > (unless (zero? transferred) > > and if transferred is #f that would indeed fail with the error message > shown in the backtrace, so it seems you are correct in your analysis. That=E2=80=99s correct. The =E2=80=9C@ download-progress=E2=80=9D line is printed by (guix scripts = substitute) and later consumed by (guix status) in the client, which is why I mentioned =E2=80=98progress-reporter/trace=E2=80=99 above. I think the problem we=E2=80=99re looking at could occur if those traces ar= e not printed in an atomic way, and thus (guix status) gets to see truncated/mixed up traces. So I tried this: _NIX_OPTIONS=3Dprint-extended-build-trace=3D1 sudo -E \ ./pre-inst-env strace -s 200 -o ,,s guix substitute \ --substitute /gnu/store/pknm43xsza6nlc7bn27djip8fis92akd-gcc-toolcha= in-10.2.0 /tmp/t.drv It shows that traces are printed in a single write(2) call: --8<---------------cut here---------------start------------->8--- write(2, "@ download-progress /tmp/t.drv http://ci.guix.gnu.org/nar/lzip/pk= nm43xsza6nlc7bn27djip8fis92akd-gcc-toolchain-10.2.0 4843 4843\n", 127) =3D = 127 --8<---------------cut here---------------end--------------->8--- So this side of things seems to be good. But then traces could be mangled/truncated by the daemon maybe. An strace log of the failing case would be very helpful. Thanks, Ludo=E2=80=99.