bug#53668: Updating substitutes on LAN hosts dies unexpectedly

bug#53668: Updating substitutes on LAN hosts dies unexpectedly

[Simon Streit]

Hello,

quite often, and quite randomly I run into this situation that whenever
Guix tries to rebuild a profile, and sometimes while downloading from
local Guix hosts sharing their store items, the process will crash with
the following error:

--8<---------------cut here---------------start------------->8---
~ $1 reconfigure
substitute: updating substitutes from 'http://192.168.0.157:3000'...  56.3%Backtrace:
substitute: In ice-9/boot-9.scm:
substitute:   1752:10 17 (with-exception-handler _ _ #:unwind? _ # _)
substitute: In unknown file:
substitute:           16 (apply-smob/0 #<thunk 7f309a1caf60>)
substitute: In ice-9/boot-9.scm:
substitute:     724:2 15 (call-with-prompt _ _ #<procedure default-prompt-handle…>)
substitute: In ice-9/eval.scm:
substitute:     619:8 14 (_ #(#(#<directory (guile-user) 7f309a1c4c80>)))
substitute: In guix/ui.scm:
substitute:    2206:7 13 (run-guix . _)
substitute:   2169:10 12 (run-guix-command _ . _)
substitute: In ice-9/boot-9.scm:
substitute:   1752:10 11 (with-exception-handler _ _ #:unwind? _ # _)
substitute:   1752:10 10 (with-exception-handler _ _ #:unwind? _ # _)
substitute: In guix/scripts/substitute.scm:
substitute:    757:18  9 (_)
substitute:    348:26  8 (process-query #<output: file 4> _ #:cache-urls _ #:acl _)
substitute: In guix/substitutes.scm:
substitute:    365:27  7 (lookup-narinfos/diverse _ _ #<procedure 7f309690d320 …> …)
substitute:    322:31  6 (lookup-narinfos _ _ #:open-connection _ # _)
substitute:    245:26  5 (fetch-narinfos _ _ #:open-connection _ # _)
substitute: In ice-9/boot-9.scm:
substitute:   1685:16  4 (raise-exception _ #:continuable? _)
substitute:   1685:16  3 (raise-exception _ #:continuable? _)
substitute:   1780:13  2 (_ #<&compound-exception components: (#<&assertion-fail…>)
substitute:   1685:16  1 (raise-exception _ #:continuable? _)
substitute:   1685:16  0 (raise-exception _ #:continuable? _)
substitute:
substitute: ice-9/boot-9.scm:1685:16: In procedure raise-exception:
substitute: Wrong type (expecting exact integer): #f
guix system: error: `/gnu/store/kcc8zh1fhp05wgw2m48w3gk228j39f5q-guix-1.3.0-21.e427593/bin/guix substitute' died unexpectedly
--8<---------------cut here---------------end--------------->8---

Unfortunately this crash happens at random.  Other times it goes
through.  Current checkout is ff14bc60e56fb0c6636da1da9a850b7b04abb367,
which isn't the most current, I know.  I've been observing this behavior
since some time now, and haven't figured out what the reason is behind
it yet.  The error message looks similar to [1].

The way this error appears is, that I usually have one host that I
upgrade first, and then share the checkout and the store between hosts
to speed up the upgrading process locally.  Unfortunately the updater
will crash randomly whenever the host starts scanning other hosts that
are found through mDNS.  Sometimes this happens while fetching new
packages into a profile.

I've set up publishing:

--8<---------------cut here---------------start------------->8---
(service guix-publish-service-type
              (guix-publish-configuration (host "0.0.0.0")
                                          (port 3000)
                                          (ttl #f)
                                          (advertise? #t)))
--8<---------------cut here---------------end--------------->8---

and of course host discovery in guix-service-type too.


Kind regards
Simon


[1] https://issues.guix.gnu.org/52464

bug#53668: Updating substitutes on LAN hosts dies unexpectedly

[Guillaume Le Vaillant]

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

Simon Streit <simon@netpanic.org> skribis:

> Hello,
>
> quite often, and quite randomly I run into this situation that whenever
> Guix tries to rebuild a profile, and sometimes while downloading from
> local Guix hosts sharing their store items, the process will crash with
> the following error:
>
> ~ $1 reconfigure
> substitute: updating substitutes from 'http://192.168.0.157:3000'...  56.3%Backtrace:
> substitute: In ice-9/boot-9.scm:
> substitute:   1752:10 17 (with-exception-handler _ _ #:unwind? _ # _)
> substitute: In unknown file:
> substitute:           16 (apply-smob/0 #<thunk 7f309a1caf60>)
> substitute: In ice-9/boot-9.scm:
> substitute:     724:2 15 (call-with-prompt _ _ #<procedure default-prompt-handle…>)
> substitute: In ice-9/eval.scm:
> substitute:     619:8 14 (_ #(#(#<directory (guile-user) 7f309a1c4c80>)))
> substitute: In guix/ui.scm:
> substitute:    2206:7 13 (run-guix . _)
> substitute:   2169:10 12 (run-guix-command _ . _)
> substitute: In ice-9/boot-9.scm:
> substitute:   1752:10 11 (with-exception-handler _ _ #:unwind? _ # _)
> substitute:   1752:10 10 (with-exception-handler _ _ #:unwind? _ # _)
> substitute: In guix/scripts/substitute.scm:
> substitute:    757:18  9 (_)
> substitute:    348:26  8 (process-query #<output: file 4> _ #:cache-urls _ #:acl _)
> substitute: In guix/substitutes.scm:
> substitute:    365:27  7 (lookup-narinfos/diverse _ _ #<procedure 7f309690d320 …> …)
> substitute:    322:31  6 (lookup-narinfos _ _ #:open-connection _ # _)
> substitute:    245:26  5 (fetch-narinfos _ _ #:open-connection _ # _)
> substitute: In ice-9/boot-9.scm:
> substitute:   1685:16  4 (raise-exception _ #:continuable? _)
> substitute:   1685:16  3 (raise-exception _ #:continuable? _)
> substitute:   1780:13  2 (_ #<&compound-exception components: (#<&assertion-fail…>)
> substitute:   1685:16  1 (raise-exception _ #:continuable? _)
> substitute:   1685:16  0 (raise-exception _ #:continuable? _)
> substitute:
> substitute: ice-9/boot-9.scm:1685:16: In procedure raise-exception:
> substitute: Wrong type (expecting exact integer): #f
> guix system: error: `/gnu/store/kcc8zh1fhp05wgw2m48w3gk228j39f5q-guix-1.3.0-21.e427593/bin/guix substitute' died unexpectedly
>
>
> Unfortunately this crash happens at random.  Other times it goes
> through.  Current checkout is ff14bc60e56fb0c6636da1da9a850b7b04abb367,
> which isn't the most current, I know.  I've been observing this behavior
> since some time now, and haven't figured out what the reason is behind
> it yet.  The error message looks similar to [1].
>
> The way this error appears is, that I usually have one host that I
> upgrade first, and then share the checkout and the store between hosts
> to speed up the upgrading process locally.  Unfortunately the updater
> will crash randomly whenever the host starts scanning other hosts that
> are found through mDNS.  Sometimes this happens while fetching new
> packages into a profile.
>
> I've set up publishing:
>
> (service guix-publish-service-type
>               (guix-publish-configuration (host "0.0.0.0")
>                                           (port 3000)
>                                           (ttl #f)
>                                           (advertise? #t)))
>
> and of course host discovery in guix-service-type too.
>
>
> Kind regards
> Simon
>
>
> [1] https://issues.guix.gnu.org/52464

Hi,

I have also seen this kind of crashes on my LAN.
I don't know what causes this issue, but I noticed that it has happened
less often since I activated the cache for the guix-publish service.

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 247 bytes --]

bug#53668: Updating substitutes on LAN hosts dies unexpectedly

[Simon Streit]

Hello Guillaume,

Guillaume Le Vaillant <glv@posteo.net> writes:

> I have also seen this kind of crashes on my LAN.
> I don't know what causes this issue, but I noticed that it has happened
> less often since I activated the cache for the guix-publish service.

I just activated the cache. It hasn't crashed so far.

bug#53668: Updating substitutes on LAN hosts dies unexpectedly

[Simon Streit]

Simon Streit <simon@netpanic.org> writes:
> I just activated the cache. It hasn't crashed so far.

No, it did crash again.

bug#53668: Updating substitutes on LAN hosts dies unexpectedly

[Maxim Cournoyer]

Hi Simon,

Simon Streit <simon@netpanic.org> writes:

> Hello,
>
> quite often, and quite randomly I run into this situation that whenever
> Guix tries to rebuild a profile, and sometimes while downloading from
> local Guix hosts sharing their store items, the process will crash with
> the following error:
>
> ~ $1 reconfigure
> substitute: updating substitutes from 'http://192.168.0.157:3000'...  56.3%Backtrace:
> substitute: In ice-9/boot-9.scm:
> substitute:   1752:10 17 (with-exception-handler _ _ #:unwind? _ # _)
> substitute: In unknown file:
> substitute:           16 (apply-smob/0 #<thunk 7f309a1caf60>)
> substitute: In ice-9/boot-9.scm:
> substitute:     724:2 15 (call-with-prompt _ _ #<procedure default-prompt-handle…>)
> substitute: In ice-9/eval.scm:
> substitute:     619:8 14 (_ #(#(#<directory (guile-user) 7f309a1c4c80>)))
> substitute: In guix/ui.scm:
> substitute:    2206:7 13 (run-guix . _)
> substitute:   2169:10 12 (run-guix-command _ . _)
> substitute: In ice-9/boot-9.scm:
> substitute:   1752:10 11 (with-exception-handler _ _ #:unwind? _ # _)
> substitute:   1752:10 10 (with-exception-handler _ _ #:unwind? _ # _)
> substitute: In guix/scripts/substitute.scm:
> substitute:    757:18  9 (_)
> substitute:    348:26  8 (process-query #<output: file 4> _ #:cache-urls _ #:acl _)
> substitute: In guix/substitutes.scm:
> substitute:    365:27  7 (lookup-narinfos/diverse _ _ #<procedure 7f309690d320 …> …)
> substitute:    322:31  6 (lookup-narinfos _ _ #:open-connection _ # _)
> substitute:    245:26  5 (fetch-narinfos _ _ #:open-connection _ # _)
> substitute: In ice-9/boot-9.scm:
> substitute:   1685:16  4 (raise-exception _ #:continuable? _)
> substitute:   1685:16  3 (raise-exception _ #:continuable? _)
> substitute:   1780:13  2 (_ #<&compound-exception components: (#<&assertion-fail…>)
> substitute:   1685:16  1 (raise-exception _ #:continuable? _)
> substitute:   1685:16  0 (raise-exception _ #:continuable? _)
> substitute:
> substitute: ice-9/boot-9.scm:1685:16: In procedure raise-exception:
> substitute: Wrong type (expecting exact integer): #f
> guix system: error: `/gnu/store/kcc8zh1fhp05wgw2m48w3gk228j39f5q-guix-1.3.0-21.e427593/bin/guix substitute' died unexpectedly

I suffer from this routinely on my slow HDD machine.  I attribute the
failure to some timeout that isn't reported correctly by guile-ssh.
Perhaps related to
https://github.com/artyom-poptsov/guile-ssh/issues/29; there's a new
update of guile-ssh to try that Artyom has put up on guix-patches; we
should test it.

Thanks,

Maxim

bug#53668: Updating substitutes on LAN hosts dies unexpectedly

[Ludovic Courtès]

Hello!

Maxim Cournoyer <maxim.cournoyer@gmail.com> skribis:

> Simon Streit <simon@netpanic.org> writes:
>
>> Hello,
>>
>> quite often, and quite randomly I run into this situation that whenever
>> Guix tries to rebuild a profile, and sometimes while downloading from
>> local Guix hosts sharing their store items, the process will crash with
>> the following error:
>>
>> ~ $1 reconfigure
>> substitute: updating substitutes from 'http://192.168.0.157:3000'...  56.3%Backtrace:
>> substitute: In ice-9/boot-9.scm:
>> substitute:   1752:10 17 (with-exception-handler _ _ #:unwind? _ # _)
>> substitute: In unknown file:
>> substitute:           16 (apply-smob/0 #<thunk 7f309a1caf60>)
>> substitute: In ice-9/boot-9.scm:
>> substitute:     724:2 15 (call-with-prompt _ _ #<procedure default-prompt-handle…>)
>> substitute: In ice-9/eval.scm:
>> substitute:     619:8 14 (_ #(#(#<directory (guile-user) 7f309a1c4c80>)))
>> substitute: In guix/ui.scm:
>> substitute:    2206:7 13 (run-guix . _)
>> substitute:   2169:10 12 (run-guix-command _ . _)
>> substitute: In ice-9/boot-9.scm:
>> substitute:   1752:10 11 (with-exception-handler _ _ #:unwind? _ # _)
>> substitute:   1752:10 10 (with-exception-handler _ _ #:unwind? _ # _)
>> substitute: In guix/scripts/substitute.scm:
>> substitute:    757:18  9 (_)
>> substitute:    348:26  8 (process-query #<output: file 4> _ #:cache-urls _ #:acl _)
>> substitute: In guix/substitutes.scm:
>> substitute:    365:27  7 (lookup-narinfos/diverse _ _ #<procedure 7f309690d320 …> …)
>> substitute:    322:31  6 (lookup-narinfos _ _ #:open-connection _ # _)
>> substitute:    245:26  5 (fetch-narinfos _ _ #:open-connection _ # _)
>> substitute: In ice-9/boot-9.scm:
>> substitute:   1685:16  4 (raise-exception _ #:continuable? _)
>> substitute:   1685:16  3 (raise-exception _ #:continuable? _)
>> substitute:   1780:13  2 (_ #<&compound-exception components: (#<&assertion-fail…>)
>> substitute:   1685:16  1 (raise-exception _ #:continuable? _)
>> substitute:   1685:16  0 (raise-exception _ #:continuable? _)
>> substitute:
>> substitute: ice-9/boot-9.scm:1685:16: In procedure raise-exception:
>> substitute: Wrong type (expecting exact integer): #f
>> guix system: error: `/gnu/store/kcc8zh1fhp05wgw2m48w3gk228j39f5q-guix-1.3.0-21.e427593/bin/guix substitute' died unexpectedly
>
> I suffer from this routinely on my slow HDD machine.  I attribute the
> failure to some timeout that isn't reported correctly by guile-ssh.

Guile-SSH is not involved here though.

However, this may well be this ‘guix publish’ bug that was recently
fixed, whereby ‘guix publish’ without ‘--cache’ would send bogus HTTP
replies:

  https://issues.guix.gnu.org/54723

Could you confirm?

Ludo’.

bug#53668: Updating substitutes on LAN hosts dies unexpectedly

[Maxime Devos]

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

Ludovic Courtès schreef op wo 11-05-2022 om 16:58 [+0200]:
> However, this may well be this ‘guix publish’ bug that was recently
> fixed, whereby ‘guix publish’ without ‘--cache’ would send bogus HTTP
> replies:
> 
>   https://issues.guix.gnu.org/54723
> 
> Could you confirm?
> 
> Ludo’.

Even then, the error message says ‘wrong type error ...’, shouldn't it
say something like ‘bogus HTTP’ or ‘bogus narinfo’ or such instead?

Greetings,
Maxime.

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

bug#53668: Updating substitutes on LAN hosts dies unexpectedly

[Maxim Cournoyer]

Hi Ludovic,

Ludovic Courtès <ludo@gnu.org> writes:

[...]

> However, this may well be this ‘guix publish’ bug that was recently
> fixed, whereby ‘guix publish’ without ‘--cache’ would send bogus HTTP
> replies:
>
>   https://issues.guix.gnu.org/54723
>
> Could you confirm?

I've reconfigured my offload machine and haven't seen the issue yet.
Tentatively closing.

Thank you for investigating and fixing the issue!

Maxim

bug#53668: Updating substitutes on LAN hosts dies unexpectedly

[Maxim Cournoyer]

Hi Maxime,

Maxime Devos <maximedevos@telenet.be> writes:

> Ludovic Courtès schreef op wo 11-05-2022 om 16:58 [+0200]:
>> However, this may well be this ‘guix publish’ bug that was recently
>> fixed, whereby ‘guix publish’ without ‘--cache’ would send bogus HTTP
>> replies:
>> 
>>   https://issues.guix.gnu.org/54723
>> 
>> Could you confirm?
>> 
>> Ludo’.
>
> Even then, the error message says ‘wrong type error ...’, shouldn't it
> say something like ‘bogus HTTP’ or ‘bogus narinfo’ or such instead?

I agree that a more accurate error message would have been useful.  If
you have the bandwidth for a patch, I'd be more than happy reviewing it
:-).

Thanks,

Maxim

bug#53668: Updating substitutes on LAN hosts dies unexpectedly

[Ludovic Courtès]

Hi,

Maxim Cournoyer <maxim.cournoyer@gmail.com> skribis:

> Maxime Devos <maximedevos@telenet.be> writes:
>
>> Ludovic Courtès schreef op wo 11-05-2022 om 16:58 [+0200]:
>>> However, this may well be this ‘guix publish’ bug that was recently
>>> fixed, whereby ‘guix publish’ without ‘--cache’ would send bogus HTTP
>>> replies:
>>> 
>>>   https://issues.guix.gnu.org/54723
>>> 
>>> Could you confirm?
>>> 
>>> Ludo’.
>>
>> Even then, the error message says ‘wrong type error ...’, shouldn't it
>> say something like ‘bogus HTTP’ or ‘bogus narinfo’ or such instead?
>
> I agree that a more accurate error message would have been useful.  If
> you have the bandwidth for a patch, I'd be more than happy reviewing it
> :-).

HTTP response parsing happens in (web response) though, not in Guix, so
this is where things should be patch.

Currently that code pretty much expects it’s talking to a well-behaved
HTTP server.  Changing it to gracefully deal with any kind of garbage
might turn out to be quite an effort.

Food for thought!

Ludo’.

bug#53668: Updating substitutes on LAN hosts dies unexpectedly

[Maxim Cournoyer]

Hello,

Ludovic Courtès <ludo@gnu.org> writes:

> Hi,
>
> Maxim Cournoyer <maxim.cournoyer@gmail.com> skribis:
>
>> Maxime Devos <maximedevos@telenet.be> writes:
>>
>>> Ludovic Courtès schreef op wo 11-05-2022 om 16:58 [+0200]:
>>>> However, this may well be this ‘guix publish’ bug that was recently
>>>> fixed, whereby ‘guix publish’ without ‘--cache’ would send bogus HTTP
>>>> replies:
>>>> 
>>>>   https://issues.guix.gnu.org/54723
>>>> 
>>>> Could you confirm?
>>>> 
>>>> Ludo’.
>>>
>>> Even then, the error message says ‘wrong type error ...’, shouldn't it
>>> say something like ‘bogus HTTP’ or ‘bogus narinfo’ or such instead?
>>
>> I agree that a more accurate error message would have been useful.  If
>> you have the bandwidth for a patch, I'd be more than happy reviewing it
>> :-).
>
> HTTP response parsing happens in (web response) though, not in Guix, so
> this is where things should be patch.
>
> Currently that code pretty much expects it’s talking to a well-behaved
> HTTP server.  Changing it to gracefully deal with any kind of garbage
> might turn out to be quite an effort.

Hmm.  I see.  Maxime, perhaps an issue can be logged against Guile to at
least remember it exists, to tackle by anyone with the
interest/bandwidth.  I think it'd be valuable in the long run.

Thank you!

Maxim