bug#38050: Guix fails during downloading a substitute of google-brotli, throws an ugly backtrace

bug#38050: Guix fails during downloading a substitute of google-brotli, throws an ugly backtrace

[Jan Wielkiewicz]

Guix fails during downloading a substitute of google-brotli, throws an
ugly backtrace. That's basically it:

 ad-progress
/gnu/store/brvizic3qv469j8fd2xgsgx9p8s5s1j7-google-brotli-1.0.7-checkout
https://ci.guix.gnu.org/nar/gzip/brvizic3qv469j8fd2xgsgx9p8s5s1j7-google-brotli-1.0.7-checkout
23583063 7880704 google-brotli-1.0.7-checkout  22.5MiB
           663.5MiB/s 00:00 [##########        ]  58.7%substituting
/gnu/store/m18k3ba7ywzk06005a0504yp4b6dczlf-graphite2-1.3.13.tgz...
14172160 google-brotli-1.0.7-checkout  22.5MiB
   119.8MiB/s 00:00 [###############   ]  86.4%Backtrace: In
guix/store.scm: 623:10 19 (call-with-store _) In
guix/scripts/build.scm: 927:26 18 (_ #<store-connection 256.99
7f26acf88ea0>) In ice-9/boot-9.scm: 829:9 17 (catch _ _ #<procedure
7f26acf88ea0>7f269fcbab60 at ice-9/boot-9.sc…> …) In guix/ui.scm:
    420:6 16 (_)
In guix/scripts/build.scm:
    892:5 15 (_)
In srfi/srfi-1.scm:
   679:15 14 (append-map _ _ . _)
   592:17 13 (map1 ("x86_64-linux"))
   679:15 12 (append-map _ _ . _)
   592:17 11 (map1 (#<package jami@20191101.3.67671e7 gnu/packages/…>))
In guix/scripts/build.scm:
   853:18 10 (_ _)
In guix/packages.scm:
   948:16  9 (cache! #<weak-table 701/883> #<package jami@20191101.…> …)
In guix/grafts.scm:
    323:4  8 (graft-derivation #<store-connection 256.99 7f26acf88e…> …)
    172:4  7 (references-oracle #<store-connection 256.99 7f26acf88…> …)
   182:20  6 (_ _ _)
In guix/store.scm:
  1215:15  5 (_ #<store-connection 256.99 7f26acf88ea0> _ _)
   718:13  4 (process-stderr _ _)
In unknown file:
           3 (display "@ substituter-succeeded /gnu/store/9hblvli1z…" …)
In guix/status.scm:
   691:16  2 (write! _ _ _)
    605:6  1 (_ (download-progress "/gnu/store/brvizic3qv469j8fd…" …) …)
In guix/progress.scm:
   219:14  0 (display-download-progress "google-brotli-@" #f # _ # _ …)

guix/progress.scm:219:14: In procedure display-download-progress:
In procedure =: Wrong type: #f


Jan Wielkiewicz

bug#38050: Guix fails during downloading a substitute of google-brotli, throws an ugly backtrace

[Ludovic Courtès]

Hi Jan,

Jan Wielkiewicz <tona_kosmicznego_smiecia@interia.pl> skribis:

> Guix fails during downloading a substitute of google-brotli, throws an
> ugly backtrace. That's basically it:
>
>  ad-progress
> /gnu/store/brvizic3qv469j8fd2xgsgx9p8s5s1j7-google-brotli-1.0.7-checkout
> https://ci.guix.gnu.org/nar/gzip/brvizic3qv469j8fd2xgsgx9p8s5s1j7-google-brotli-1.0.7-checkout
> 23583063 7880704 google-brotli-1.0.7-checkout  22.5MiB
>            663.5MiB/s 00:00 [##########        ]  58.7%substituting
> /gnu/store/m18k3ba7ywzk06005a0504yp4b6dczlf-graphite2-1.3.13.tgz...
> 14172160 google-brotli-1.0.7-checkout  22.5MiB
>    119.8MiB/s 00:00 [###############   ]  86.4%Backtrace: In
> guix/store.scm: 623:10 19 (call-with-store _) In
> guix/scripts/build.scm: 927:26 18 (_ #<store-connection 256.99
> 7f26acf88ea0>) In ice-9/boot-9.scm: 829:9 17 (catch _ _ #<procedure
> 7f26acf88ea0>7f269fcbab60 at ice-9/boot-9.sc…> …) In guix/ui.scm:
>     420:6 16 (_)
> In guix/scripts/build.scm:
>     892:5 15 (_)
> In srfi/srfi-1.scm:
>    679:15 14 (append-map _ _ . _)
>    592:17 13 (map1 ("x86_64-linux"))
>    679:15 12 (append-map _ _ . _)
>    592:17 11 (map1 (#<package jami@20191101.3.67671e7 gnu/packages/…>))
> In guix/scripts/build.scm:
>    853:18 10 (_ _)
> In guix/packages.scm:
>    948:16  9 (cache! #<weak-table 701/883> #<package jami@20191101.…> …)
> In guix/grafts.scm:
>     323:4  8 (graft-derivation #<store-connection 256.99 7f26acf88e…> …)
>     172:4  7 (references-oracle #<store-connection 256.99 7f26acf88…> …)
>    182:20  6 (_ _ _)
> In guix/store.scm:
>   1215:15  5 (_ #<store-connection 256.99 7f26acf88ea0> _ _)
>    718:13  4 (process-stderr _ _)
> In unknown file:
>            3 (display "@ substituter-succeeded /gnu/store/9hblvli1z…" …)
> In guix/status.scm:
>    691:16  2 (write! _ _ _)
>     605:6  1 (_ (download-progress "/gnu/store/brvizic3qv469j8fd…" …) …)
> In guix/progress.scm:
>    219:14  0 (display-download-progress "google-brotli-@" #f # _ # _ …)
>
> guix/progress.scm:219:14: In procedure display-download-progress:
> In procedure =: Wrong type: #f

Could you send the log returned by:

  guix build --log-file /gnu/store/brvizic3qv469j8fd2xgsgx9p8s5s1j7-google-brotli-1.0.7-checkout

?

It looks like the download code provided invalid data, which led (guix
status) to pass transferred = #false to ‘display-download-progress’.  I
can’t reproduce it, though.

Thanks,
Ludo’.

bug#38050: Guix fails during downloading a substitute of google-brotli, throws an ugly backtrace

[Jan Wielkiewicz]

Dnia 2019-11-06, o godz. 10:35:25
Ludovic Courtès <ludo@gnu.org> napisał(a):

> Hi Jan,
> 
> 
> Could you send the log returned by:
> 
>   guix build --log-file
> /gnu/store/brvizic3qv469j8fd2xgsgx9p8s5s1j7-google-brotli-1.0.7-checkout
> 
> ?

https://ci.guix.gnu.org/log/brvizic3qv469j8fd2xgsgx9p8s5s1j7-google-brotli-1.0.7-checkout

environment variable `PATH' set to
`/gnu/store/q09sy224qnxrp982z4xfaxi19721mjx8-gzip-1.9/bin:/gnu/store/ipx79bfj2mrc8npj7s3qi3zri11jfhaw-tar-1.30/bin'
Initialized empty Git repository in
/gnu/store/brvizic3qv469j8fd2xgsgx9p8s5s1j7-google-brotli-1.0.7-checkout/.git/
From https://github.com/google/brotli
 * tag               v1.0.7     -> FETCH_HEAD
Note: checking out 'FETCH_HEAD'.

You are in 'detached HEAD' state. You can look around, make experimental
changes and commit them, and you can discard any commits you make in
this state without impacting any branches by performing another
checkout.

If you want to create a new branch to retain commits you create, you may
do so (now or later) by using -b with the checkout command again.
Example:

  git checkout -b <new-branch-name>

HEAD is now at d6d9895 Ramp up version to 1.0.7

> 
> It looks like the download code provided invalid data, which led (guix
> status) to pass transferred = #false to ‘display-download-progress’.
> I can’t reproduce it, though.

It occured during doing something for Jami, don't remember exactly what
now.
I probably ran "./pre-inst-env guix build jami" in my private git repo,
but I did nothing with google-brotli.

> Thanks,
> Ludo’.


Jan Wielkiewicz

bug#38050: Guix fails during downloading a substitute of google-brotli, throws an ugly backtrace

[Ludovic Courtès]

Hello,

Jan Wielkiewicz <tona_kosmicznego_smiecia@interia.pl> skribis:

> Dnia 2019-11-06, o godz. 10:35:25
> Ludovic Courtès <ludo@gnu.org> napisał(a):
>
>> Hi Jan,
>> 
>> 
>> Could you send the log returned by:
>> 
>>   guix build --log-file
>> /gnu/store/brvizic3qv469j8fd2xgsgx9p8s5s1j7-google-brotli-1.0.7-checkout
>> 
>> ?
>
> https://ci.guix.gnu.org/log/brvizic3qv469j8fd2xgsgx9p8s5s1j7-google-brotli-1.0.7-checkout

Oh actually that’s not helpful, my bad.  What we would have need is the
output of ‘guix substitute’ (invoked by the daemon), but that is not
logged as-is.  :-/

I’ll take another look at the relevant code (and invite everyone to give
it a shot :-)), and in the meantime we can leave this bug open.  Do
reply if that happens again!

Thanks,
Ludo’.

bug#38050: Guix fails during downloading a substitute of google-brotli, throws an ugly backtrace

[Jan Wielkiewicz]

[-- Attachment #1: Type: text/plain, Size: 2250 bytes --]

Hi,

Dnia 2019-11-07, o godz. 21:16:44
Ludovic Courtès <ludo@gnu.org> napisał(a):

> Hello,
> 
> 
> Oh actually that’s not helpful, my bad.  What we would have need is
> the output of ‘guix substitute’ (invoked by the daemon), but that is
> not logged as-is.  :-/
> 
> I’ll take another look at the relevant code (and invite everyone to
> give it a shot :-)), and in the meantime we can leave this bug open.
> Do reply if that happens again!
Okay, this have happened again. Maybe it's caused by something I
changed in Jami.  I'm attaching the most recent changes.

Running "./pre-inst-env guix build jami" causes this:

3583063 14106624
 google-brotli-1.0.7-checkout  22.5MiB
                             770KiB/s 00:26 [###############   ]
86.1%Backtrace: In guix/store.scm: 623:10 19 (call-with-store _)
In guix/scripts/build.scm:
   927:26 18 (_ #<store-connection 256.99 7f5a10fcbea0>)
In ice-9/boot-9.scm:
    829:9 17 (catch _ _ #<procedure 7f5a1204baa0 at ice-9/boot-9.sc…> …)
In guix/ui.scm:
    425:6 16 (_)
In guix/scripts/build.scm:
    892:5 15 (_)
In srfi/srfi-1.scm:
   679:15 14 (append-map _ _ . _)
   592:17 13 (map1 ("x86_64-linux"))
   679:15 12 (append-map _ _ . _)
   592:17 11 (map1 (#<package jami@20191101.3.67671e7 gnu/packages/…>))
In guix/scripts/build.scm:
   853:18 10 (_ _)
In guix/packages.scm:
   948:16  9 (cache! #<weak-table 705/883> #<package jami@20191101.…> …)
In guix/grafts.scm:
    323:4  8 (graft-derivation #<store-connection 256.99 7f5a10fcbe…> …)
    172:4  7 (references-oracle #<store-connection 256.99 7f5a10fcb…> …)
   182:20  6 (_ _ _)
In guix/store.scm:
  1215:15  5 (_ #<store-connection 256.99 7f5a10fcbea0> _ _)
   718:13  4 (process-stderr _ _)
In unknown file:
           3 (display "@ substituter-succeeded /gnu/store/m18k3ba7y…" …)
In guix/status.scm:
   691:16  2 (write! _ _ _)
    605:6  1 (_ (download-progress "/gnu/store/brvizic3qv469j8fd…" …) …)
In guix/progress.scm:
   219:14  0 (display-download-progress "google@" #f #:start-time _ # …)

guix/progress.scm:219:14: In procedure display-download-progress:
In procedure =: Wrong type: #f


> Thanks,
> Ludo’.


Jan Wielkiewicz

[-- Attachment #2: jami-wip-09-11-2019.tar.bz2 --]
[-- Type: application/x-bzip, Size: 9989 bytes --]

bug#38050: Guix fails during downloading a substitute of google-brotli, throws an ugly backtrace

[Ludovic Courtès]

Hi Jan,

Jan Wielkiewicz <tona_kosmicznego_smiecia@interia.pl> skribis:

> Dnia 2019-11-07, o godz. 21:16:44
> Ludovic Courtès <ludo@gnu.org> napisał(a):
>
>> Hello,
>> 
>> 
>> Oh actually that’s not helpful, my bad.  What we would have need is
>> the output of ‘guix substitute’ (invoked by the daemon), but that is
>> not logged as-is.  :-/
>> 
>> I’ll take another look at the relevant code (and invite everyone to
>> give it a shot :-)), and in the meantime we can leave this bug open.
>> Do reply if that happens again!
> Okay, this have happened again. Maybe it's caused by something I
> changed in Jami.  I'm attaching the most recent changes.

How reproducible is it?  100%?

> Running "./pre-inst-env guix build jami" causes this:
>
> 3583063 14106624
>  google-brotli-1.0.7-checkout  22.5MiB
>                              770KiB/s 00:26 [###############   ]
> 86.1%Backtrace: In guix/store.scm: 623:10 19 (call-with-store _)
> In guix/scripts/build.scm:
>    927:26 18 (_ #<store-connection 256.99 7f5a10fcbea0>)
> In ice-9/boot-9.scm:
>     829:9 17 (catch _ _ #<procedure 7f5a1204baa0 at ice-9/boot-9.sc…> …)
> In guix/ui.scm:
>     425:6 16 (_)
> In guix/scripts/build.scm:
>     892:5 15 (_)
> In srfi/srfi-1.scm:
>    679:15 14 (append-map _ _ . _)
>    592:17 13 (map1 ("x86_64-linux"))
>    679:15 12 (append-map _ _ . _)
>    592:17 11 (map1 (#<package jami@20191101.3.67671e7 gnu/packages/…>))
> In guix/scripts/build.scm:
>    853:18 10 (_ _)
> In guix/packages.scm:
>    948:16  9 (cache! #<weak-table 705/883> #<package jami@20191101.…> …)
> In guix/grafts.scm:
>     323:4  8 (graft-derivation #<store-connection 256.99 7f5a10fcbe…> …)
>     172:4  7 (references-oracle #<store-connection 256.99 7f5a10fcb…> …)
>    182:20  6 (_ _ _)
> In guix/store.scm:
>   1215:15  5 (_ #<store-connection 256.99 7f5a10fcbea0> _ _)
>    718:13  4 (process-stderr _ _)
> In unknown file:
>            3 (display "@ substituter-succeeded /gnu/store/m18k3ba7y…" …)
> In guix/status.scm:
>    691:16  2 (write! _ _ _)
>     605:6  1 (_ (download-progress "/gnu/store/brvizic3qv469j8fd…" …) …)
> In guix/progress.scm:
>    219:14  0 (display-download-progress "google@" #f #:start-time _ # …)
>
> guix/progress.scm:219:14: In procedure display-download-progress:
> In procedure =: Wrong type: #f

Could you try again, this time stracing the process with:

  ./pre-inst-env strace -o /tmp/log -s 300 guix build jami

?

Once you’ve reproduced the failure above, could you send /tmp/log (or
the tail of that file)?

Thanks in advance!

Ludo’.

bug#38050: Guix fails during downloading a substitute of google-brotli, throws an ugly backtrace

[Jan]

On Sun, 10 Nov 2019 17:24:15 +0100
Ludovic Courtès <ludo@gnu.org> wrote:

> Hi Jan,
> 
> How reproducible is it?  100%?
> 
I tried only two times by now. It doesn't happen when I run
"./pre-inst-env guix build google-brotli" though. So reproducibility is
equal to 100% with 25% chance for error :) (while building Jami).

> 
> Could you try again, this time stracing the process with:
> 
>   ./pre-inst-env strace -o /tmp/log -s 300 guix build jami
> 
> ?
Yes, but after I finish compiling all Jami dependencies and this takes
some time on core 2 duo. If you didn't know - compiling libreoffice
takes 7 hours, llvm - 3h, mariadb - 2h, fun!

> Once you’ve reproduced the failure above, could you send /tmp/log (or
> the tail of that file)?
Okay.

> Thanks in advance!
> 
> Ludo’.


Jan Wielkiewicz

bug#38050: during substitution: In procedure =: Wrong type argument in position 1: #f

[Maxime Devos]

[-- Attachment #1: Type: text/plain, Size: 2003 bytes --]

This seems another instance of the bug.
Daemon version:
$ ls -l /run/current-system/profile/bin/guix-daemon 
/run/current-system/profile/bin/guix-daemon -> /gnu/store/pv9i296wfjl3zwkmsg4w24ksqcb9qhnb-guix-1.3.0-2.9f2b2c4/bin/guix-daemon

During "guix build guix":

/gnu/store/3j9kzhsygg56pmhlwpvjqicvjgsni49w-guix-1.3.0-3.50dfbbf vervangen...
guix substitute: warning: [removed].local: host not found: Systeemfout
aan het downloaden van https://ci.guix.gnu.org/nar/lzip/3j9kzhsygg56pmhlwpvjqicvjgsni49w-guix-1.3.0-3.50dfbbf...
 guix-1.3.0-3.50dfbbf  35.9MiB      246.2MiB/s 00:00 [############      ]  70.9%


Backtrace:
In guix/store.scm:
   1319:8 19 (call-with-build-handler _ _)
   1319:8 18 (call-with-build-handler #<procedure 7fc17291b570 at g…> …)
In guix/ui.scm:
    463:3 17 (_)
In ice-9/boot-9.scm:
  1747:15 16 (with-exception-handler #<procedure 7fc169729b10 at ic…> …)
  1752:10 15 (with-exception-handler _ _ #:unwind? _ # _)
In guix/ui.scm:
    450:6 14 (_)
In guix/scripts/build.scm:
    608:5 13 (_)
In srfi/srfi-1.scm:
   673:15 12 (append-map _ _ . _)
   586:17 11 (map1 ("x86_64-linux"))
In guix/scripts/build.scm:
   610:20 10 (_ _)
In guix/store.scm:
   1376:5  9 (map/accumulate-builds #<store-connection 256.99 7fc17…> …)
  1387:15  8 (_ #<store-connection 256.99 7fc172a29b40> _ _)
   759:13  7 (process-stderr _ _)
In unknown file:
           6 (display "@ substituter-succeeded /gnu/store/3j9kzhsyg…" …)
In guix/status.scm:
   722:16  5 (write! _ _ _)
    636:6  4 (_ (download-progress "/gnu/store/3j9kzhsygg56pmhlw…" …) …)
In guix/progress.scm:
   223:17  3 (display-download-progress "ci.guix.gnu.o@" _ #:tty? _ # …)
In ice-9/boot-9.scm:
  1685:16  2 (raise-exception _ #:continuable? _)
  1685:16  1 (raise-exception _ #:continuable? _)
  1685:16  0 (raise-exception _ #:continuable? _)

ice-9/boot-9.scm:1685:16: In procedure raise-exception:
In procedure =: Wrong type argument in position 1: #f

[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 260 bytes --]

bug#38050: another instance

[Attila Lendvai]

$ make check-system
[..]
substitute: updating substitutes from 'http://10.0.8.103:9999'... 100.0%
substitute: updating substitutes from 'https://substitutes.nonguix.org'... 100.0%
substitute: updating substitutes from 'https://bordeaux.guix.gnu.org'... 100.0%
downloading from https://ci.guix.gnu.org/nar/sifkzg6ab707f389k9d7ixwkz2s8k6mk-docker-pack.tar.gz ...
 docker-pack.tar.gz  38.2MiB                                                                                        4.40GiB/s 00:00 ▕█████▉            ▏  32.8%Backtrace:
In guix/store.scm:
   1330:8 19 (call-with-build-handler _ _)
   1330:8 18 (call-with-build-handler _ _)
   1330:8 17 (call-with-build-handler _ _)
   1330:8 16 (call-with-build-handler _ _)
   1330:8 15 (call-with-build-handler _ _)
   1330:8 14 (call-with-build-handler _ _)
   1330:8 13 (call-with-build-handler _ _)
   1330:8 12 (call-with-build-handler _ _)
   1330:8 11 (call-with-build-handler _ _)
   1330:8 10 (call-with-build-handler _ _)
   1330:8  9 (call-with-build-handler #<procedure 7fc4897a16c0 at guix/ui.scm:1236:2 (continue store things mode)> _)
In guix/scripts/build.scm:
   802:27  8 (_)
In guix/store.scm:
  1449:15  7 (_ #<store-connection 256.100 7fc48ef26910> _ _)
   772:14  6 (process-stderr _ _)
In unknown file:
           5 (display "@ substituter-succeeded /gnu/store/sifkzg6ab707f389k9d7ixwkz2s8k6mk-docker-pack.tar.gz\n" #<output: string 7fc4897fa0e0>)
In guix/status.scm:
   757:16  4 (write! _ _ _)
    670:6  3 (_ (download-progress "/gnu/store/sifkzg6ab707f389k9d7ixwkz2s8k6mk-docker-pack.tar.gz" "https://ci.guix.gnu.org/nar/sifkzg6ab707f389k9d7ix…" …) …)
In guix/progress.scm:
   255:17  2 (display-download-progress "sifkzg6ab707f389k9d7ixwkz2s8k6m@" _ #:tty? _ #:start-time _ #:transferred _ #:log-port _)
In ice-9/boot-9.scm:
  1685:16  1 (raise-exception _ #:continuable? _)
  1685:16  0 (raise-exception _ #:continuable? _)

ice-9/boot-9.scm:1685:16: In procedure raise-exception:
In procedure =: Wrong type argument in position 1: #f
make: *** [Makefile:7285: check-system] Error 1