From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from mp0 ([2001:41d0:2:4a6f::]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits)) by ms11 with LMTPS id ESsFDItVBmBhDwAA0tVLHw (envelope-from ) for ; Tue, 19 Jan 2021 03:44:11 +0000 Received: from aspmx1.migadu.com ([2001:41d0:2:4a6f::]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits)) by mp0 with LMTPS id 2FlTB4tVBmBEEQAA1q6Kng (envelope-from ) for ; Tue, 19 Jan 2021 03:44:11 +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 66C049402B1 for ; Tue, 19 Jan 2021 03:44:10 +0000 (UTC) Received: from localhost ([::1]:45884 helo=lists1p.gnu.org) by lists.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1l1hw9-0008T0-EI for larch@yhetil.org; Mon, 18 Jan 2021 22:44:09 -0500 Received: from eggs.gnu.org ([2001:470:142:3::10]:33846) by lists.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1l1hw2-0008SY-Ox for bug-guix@gnu.org; Mon, 18 Jan 2021 22:44:02 -0500 Received: from debbugs.gnu.org ([209.51.188.43]:37423) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_128_GCM_SHA256:128) (Exim 4.90_1) (envelope-from ) id 1l1hw2-0007Fv-HY for bug-guix@gnu.org; Mon, 18 Jan 2021 22:44:02 -0500 Received: from Debian-debbugs by debbugs.gnu.org with local (Exim 4.84_2) (envelope-from ) id 1l1hw2-0003oQ-Ca for bug-guix@gnu.org; Mon, 18 Jan 2021 22:44:02 -0500 X-Loop: help-debbugs@gnu.org Subject: bug#43518: Guix substitute crash in procedure raise-exception: wrong type agument in position 1: #f Resent-From: Maxim Cournoyer Original-Sender: "Debbugs-submit" Resent-CC: bug-guix@gnu.org Resent-Date: Tue, 19 Jan 2021 03:44:02 +0000 Resent-Message-ID: Resent-Sender: help-debbugs@gnu.org X-GNU-PR-Message: followup 43518 X-GNU-PR-Package: guix X-GNU-PR-Keywords: To: Ludovic =?UTF-8?Q?Court=C3=A8s?= Received: via spool by 43518-submit@debbugs.gnu.org id=B43518.161102779714589 (code B ref 43518); Tue, 19 Jan 2021 03:44:02 +0000 Received: (at 43518) by debbugs.gnu.org; 19 Jan 2021 03:43:17 +0000 Received: from localhost ([127.0.0.1]:48969 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1l1hvI-0003nE-LP for submit@debbugs.gnu.org; Mon, 18 Jan 2021 22:43:17 -0500 Received: from mail-qt1-f180.google.com ([209.85.160.180]:44826) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1l1hvG-0003n0-Jr for 43518@debbugs.gnu.org; Mon, 18 Jan 2021 22:43:15 -0500 Received: by mail-qt1-f180.google.com with SMTP id r9so12833740qtp.11 for <43518@debbugs.gnu.org>; Mon, 18 Jan 2021 19:43:14 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=from:to:cc:subject:in-reply-to:references:user-agent:date :message-id:mime-version:content-transfer-encoding; bh=mujIW3BNA8PxC8iRRP4N+No8R1e4BlmNVbDkdTaTg4o=; b=Tpm8iT33w6p6Crt2ACus3pjaw+ybjlCscM7uX91i5/mJ6o3pfyBBuKDBPadP57964H 9+SanuZ01s42hQMMcIVB1wSmEZUITGpmxHC2wGCtITUDE7pD6qgN647GQd4CMXhC1nO6 knAhyOo875c4lLE4iTcmapgzshSKS8+Iuj1hMeNPyPVBW27lP+d2R8Hj3XJX2icBxPFW h6wgLqBOx2uPHyl5BywczURUmDIxI6YT+S/wKQYoikzY9aZEI7HyQb+JPM574BzHKNU7 65KauC63d4yEBnsI7TXkI8tvWp+CUy2T62giS3dOTXlcDoFy/KnErx3T71dyCwtOGxFl l1fw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:from:to:cc:subject:in-reply-to:references :user-agent:date:message-id:mime-version:content-transfer-encoding; bh=mujIW3BNA8PxC8iRRP4N+No8R1e4BlmNVbDkdTaTg4o=; b=P3BxmJRPLO4X6oX8Fgl9PGhE8kiimFwkqA0tav+qHn9E5uGzlwLoTvTD42iSU2yULi yp6DkcAp8vGOrCOO21UbSRsug1adeFQaOUAHCX18tt6XkxXRvoB1Bi6V5VcVSrAsq7TF /giumAOomfs8lDrw3nSdrF5kVl2dLbbVNBmxEgv7mih1q6aXwH1fXmyzrjIA6n7PYg4N xnm6fM2CBIl3gAp+Qo7N7yJDgrzu/I2H9cgbLpCq2RAdcJ5biyrlb2AJx4y4cCyyTUVY Ymc2B/R+2bF565BHGdYgGh0F+SYDXqN0UQF19LQbMnFrQUDlAW/b8M2EI4KXuNS3iHH5 fiOQ== X-Gm-Message-State: AOAM532rDbTwFoHNz5ihbdNBTQxv/aiKcvW6T4OqPxPA4DKwpRODwJVs 0Krx4jRdu7+FJbCjrFoFcRItYhJKXyM= X-Google-Smtp-Source: ABdhPJzOobwAMx9SyUFnKTfkBk22PYQI+pUXskkZNYIVVQCM/rNj3pDohpU5FZgPYLrpe+ctsw/wUg== X-Received: by 2002:a05:622a:7:: with SMTP id x7mr2549603qtw.257.1611027788639; Mon, 18 Jan 2021 19:43:08 -0800 (PST) Received: from hurd (dsl-149-228.b2b2c.ca. [66.158.149.228]) by smtp.gmail.com with ESMTPSA id n66sm11813864qkn.136.2021.01.18.19.43.07 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Mon, 18 Jan 2021 19:43:07 -0800 (PST) From: Maxim Cournoyer In-Reply-To: <87im9ll9ta.fsf@gmail.com> (Maxim Cournoyer's message of "Tue, 01 Dec 2020 12:23:29 -0500") References: <87imc9y8hq.fsf@gmail.com> <873630plg1.fsf@gmail.com> <87wo0bxjvd.fsf@gnu.org> <87zh54ms9i.fsf@gmail.com> <87eemfhcpg.fsf@gnu.org> <87v9fqlltn.fsf@gmail.com> <87r1qeky0k.fsf@gmail.com> <87im9ll9ta.fsf@gmail.com> User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/27.1 (gnu/linux) Date: Mon, 18 Jan 2021 22:43:06 -0500 Message-ID: <874kjdh9rp.fsf@gmail.com> 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: , Cc: 43518@debbugs.gnu.org Errors-To: bug-guix-bounces+larch=yhetil.org@gnu.org Sender: "bug-Guix" X-Migadu-Flow: FLOW_IN X-Migadu-Spam-Score: -1.25 Authentication-Results: aspmx1.migadu.com; dkim=fail ("headers rsa verify failed") header.d=gmail.com header.s=20161025 header.b=Tpm8iT33; dmarc=fail reason="SPF not aligned (relaxed)" header.from=gmail.com (policy=none); spf=pass (aspmx1.migadu.com: domain of bug-guix-bounces@gnu.org designates 209.51.188.17 as permitted sender) smtp.mailfrom=bug-guix-bounces@gnu.org X-Migadu-Queue-Id: 66C049402B1 X-Spam-Score: -1.25 X-Migadu-Scanner: scn1.migadu.com X-TUID: qGOnLjd0VSwO Hello, Maxim Cournoyer writes: > Hello Ludovic, > > Maxim Cournoyer writes: > >> Hello again! >> >> Maxim Cournoyer writes: >> >>> Hello! >>> >>> Ludovic Court=C3=A8s writes: >>> >>> [...] >>> >>>> The =E2=80=9C@ download-progress=E2=80=9D line is printed by (guix scr= ipts 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 trac= es are 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-to= olchain-10.2.0 /tmp/t.drv >>>> >>>> It shows that traces are printed in a single write(2) call: >>>> >>>> write(2, "@ download-progress /tmp/t.drv http://ci.guix.gnu.org/nar/lz= ip/pknm43xsza6nlc7bn27djip8fis92akd-gcc-toolchain-10.2.0 4843 4843\n", 127)= =3D 127 >>>> >>>> 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. >> >> [...] >> >> I managed to capture two instances of 'transferred=3D #f' from my pk >> output in the attached logs. Curiously, they didn't lead to the crash. >> Attached is a pruned version of the strace log of a command like >> './pre-inst-env guix package -m my-manifest --max-jobs=3D20'. Offloading >> was in use. > > The trace attached is even better, in that it triggered the problem! I > don't have time to take a look now, but I hope it'll be useful in > understanding the issue better. It's rather precious (quite some luck > seems to be needed to reproduce) :-). > [...] > write(1, ";;; (print-build-event:download-progress transferred=3D #f)\n",= 58) =3D 58 > write(1, "\n", 1) =3D 1 > write(1, ";;; (simultaneous-jobs=3D 1)\n", 27) =3D 27 > write(1, "\n", 1) =3D 1 > write(1, ";;; (display-download-progress file=3D \"https:@\" size=3D #f t= ransferred=3D #f)\n", 73) =3D 73 > write(2, "Backtrace:\n", 11) =3D 11 > futex(0x7f81fbe97648, FUTEX_WAKE_PRIVATE, 2147483647) =3D 0 > write(2, "In ice-9/boot-9.scm:\n", 21) =3D 21 > write(2, " 1731:15 19 (with-exception-handler # _ # _ # \342\200\246)\n", 109) =3D 109 > write(2, "In guix/scripts/package.scm:\n", 29) =3D 29 > write(2, " 972:10 18 (_)\n", 17) =3D 17 > write(2, "In guix/status.scm:\n", 20) =3D 20 > write(2, " 777:4 17 (call-with-status-report _ _)\n", 43) =3D 43 > write(2, "In guix/store.scm:\n", 19) =3D 19 > write(2, " 1301:8 16 (call-with-build-handler _ _)\n", 43) =3D 43 > write(2, " 1301:8 15 (call-with-build-handler # \342\200\246)\n", 111) = =3D 111 > write(2, "In guix/scripts/package.scm:\n", 29) =3D 29 > write(2, " 895:2 14 (_)\n", 17) =3D 17 > write(2, "In guix/build/syscalls.scm:\n", 28) =3D 28 > write(2, " 1167:4 13 (call-with-file-lock/no-wait _ _ _)\n", 49) =3D 49 > write(2, "In guix/scripts/package.scm:\n", 29) =3D 29 > write(2, " 144:19 12 (build-and-use-profile # \"/var/guix/profiles/per-u\342\200\246\" \342\200\246)\n", 111= ) =3D 111 > mmap(NULL, 262144, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_ANONYM= OUS, -1, 0) =3D 0x7f81e1d3f000 > write(2, "In guix/store.scm:\n", 19) =3D 19 > write(2, " 2049:24 11 (run-with-store # _ #:guile-for-build _ #:system _ # \342\200\246)\n", 109) =3D 109 > write(2, "In guix/profiles.scm:\n", 22) =3D 22 > write(2, " 1598:2 10 (_ _)\n", 19) =3D 19 > write(2, " 348:2 9 (_ _)\n", 19) =3D 19 > write(2, "In guix/store.scm:\n", 19) =3D 19 > write(2, " 1931:12 8 (_ #)\n", 57= ) =3D 57 > write(2, " 1358:5 7 (map/accumulate-builds # _ _)\n", 81) =3D 81 > write(2, " 1369:15 6 (_ # _ _)\n"= , 61) =3D 61 > write(2, " 741:13 5 (process-stderr _ _)\n", 34) =3D 34 > write(2, "In unknown file:\n", 17) =3D 17 > write(2, " 4 (display \"@ substituter-succeeded /gnu/store/srcp= js17wygd5f7fa251j716n2lvdlrz-gwenhywfar\342\200\246\" \342\200\246)\n", 111= ) =3D 111 > write(2, "In guix/status.scm:\n", 20) =3D 20 > write(2, " 700:16 3 (write! _ _ _)\n", 28) =3D 28 > write(2, " 614:6 2 (_ (download-progress \"/gnu/store/ypz9jjlv4gkfd4m= 2n359d9ixma0sfydz-ghc-8.6.5\" \"https:@\" \342\200\246) \342\200\246)\n", 1= 11) =3D 111 > write(2, "In guix/progress.scm:\n", 22) =3D 22 > write(2, " 214:14 1 (display-download-progress \"https:@\" _ #:start-t= ime _ #:transferred _ #:log-port _)\n", 97) =3D 97 > write(2, "In ice-9/boot-9.scm:\n", 21) =3D 21 > write(2, " 1669:16 0 (raise-exception _ #:continuable? _)\n", 50) =3D 50 > write(2, "\n", 1) =3D 1 > futex(0x7f81fbe97650, FUTEX_WAKE_PRIVATE, 2147483647) =3D 0 > futex(0x7f81fbe97ce8, FUTEX_WAKE_PRIVATE, 2147483647) =3D 0 > write(2, "ice-9/boot-9.scm:1669:16: In procedure raise-exception:\n", 56)= =3D 56 > write(2, "In procedure =3D: Wrong type argument in position 1: #f\n", 54)= =3D 54 > fcntl(18, F_SETLKW, {l_type=3DF_UNLCK, l_whence=3DSEEK_SET, l_start=3D0, = l_len=3D0}) =3D 0 > close(18) =3D 0 > exit_group(1) =3D ? > +++ exited with 1 +++ [...] Today I stumbled upon this issue while building stuff on core-updates, with the failure happening at a different place: --8<---------------cut here---------------start------------->8--- jx934sgqx1qmybvn1yi1yfrgjk-rustc-1.24.1-src.tar.gz 67512512 4259936 Backtrace: In guix/ui.scm: 2154:12 19 (run-guix-command _ . _) In ice-9/boot-9.scm: 1736:10 18 (with-exception-handler _ _ #:unwind? _ #:unwind-for-type _) 1731:15 17 (with-exception-handler # _ # _ # ?) 1736:10 16 (with-exception-handler _ _ #:unwind? _ #:unwind-for-type _) In guix/store.scm: 632:37 15 (thunk) 1301:8 14 (call-with-build-handler _ _) 1301:8 13 (call-with-build-handler # ?) In guix/status.scm: 780:4 12 (call-with-status-report _ _) In guix/scripts/environment.scm: 751:14 11 (_) In guix/store.scm: 2049:24 10 (run-with-store # _ #:gu= ile-for-build _ #:system _ # ?) In guix/scripts/environment.scm: 764:18 9 (_ _) In guix/store.scm: 1918:38 8 (_ #) 1369:15 7 (_ # _ _) 741:13 6 (process-stderr _ _) In unknown file: 5 (display "gz https://ci.guix.gnu.org/nar/9dlfwa8qza8k6jj9m5a6s= w2rkv73nx2m-rustc-1.20.0-s?" ?) In guix/status.scm: 703:16 4 (write! _ _ _) 616:15 3 (_ (download-succeeded "/gnu/store/9dlfwa8qza8k6jj9m5a6sw2rkv7= 3nx2m-rustc-1.20.0-src.?" ?) ?) 273:33 2 (compute-status _ #< building: (#< deriva= tion: "/gnu/store/wmm8ghla?> ?) 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 struct-vtable: Wrong type argument in position 1 (expecting st= ruct): #f --8<---------------cut here---------------end--------------->8--- Maxim