Frequent TLS error in `guix substitute'

  • Open
  • quality assurance status badge
Details
2 participants
  • Timo Wilken
  • Ludovic Courtès
Owner
unassigned
Submitted by
Timo Wilken
Severity
important
Merged with

Debbugs page

T
T
Timo Wilken wrote on 19 Jan 14:57 -0800
(address . bug-guix@gnu.org)
D76F690BCTUG.3OIU4NB1EAG5F@twilken.net
Hi, unfortunately I frequently get the following error when Guix is looking
for substitutes:

substitute: looking for substitutes on 'https://bordeaux.guix.gnu.org'... 0.0%guix substitute: error: TLS error in procedure 'write_to_session_record_port': Error in the push function.

(Formatting as in the original error message - all in one long line.)

This happens during `guix system reconfigure' and `guix home reconfigure', my
most frequently used Guix subcommands.

Re-running the same command usually works, since the error only happens
intermittently. It's not a show-stopper, but still annoying - especially when
I start a long-running Guix command and come back to it later with very little
progress made due to this crash.

This has been happening for a long time (at least a few months), but for
completeness, here is my current `guix describe' output:

Generation 11 Jan 19 2025 23:31:14 (current)
tw 387cd9f
branch: master
commit: 387cd9f2085d0ef3e192523113b9ed6d9041aae0
guix 5e834c2
branch: master
commit: 5e834c220e81fddb77a26e23cf0cd5055b866844
[non-free channels omitted]
L
L
Ludovic Courtès wrote on 5 Feb 06:50 -0800
control message for bug #75679
(address . control@debbugs.gnu.org)
87y0yk8mz7.fsf@gnu.org
severity 75679 important
quit
L
L
Ludovic Courtès wrote on 25 Feb 07:53 -0800
(address . control@debbugs.gnu.org)
87plj6nhqn.fsf@gnu.org
merge 75679 76486
quit
L
L
Ludovic Courtès wrote on 25 Feb 08:04 -0800
Re: bug#76486: `guix substitute' occasionally crashes while looking for substitutes
(name . Timo Wilken)(address . guix@twilken.net)
87bjuqnh78.fsf@gnu.org
Hi,

"Timo Wilken" <guix@twilken.net> skribis:

Toggle quote (5 lines)
> Sometimes, apparently randomly, `guix substitute' crashes as follows for me:
>
> substitute: looking for substitutes on 'https://bordeaux.guix.gnu.org'... 0.0%guix substitute: error: TLS error in procedure 'write_to_session_record_port': Error in the push function.
> guix system: error: `/gnu/store/jpbjljfva1hqspw1kd6hgnl63sgvw966-guix-1.4.0-32.5f6fdad/bin/guix substitute' died unexpectedly

I’ve sent patch fixing the client-side issue:


Now, I think this only happens with bordeaux.guix.gnu.org, and started
to happen more frequently lately.

Substitutes there are served by nar-herder so I wonder what’s special
about it compared to ‘guix publish’ (used on ci.guix).

Looking at the logs, the nar-herder doesn’t crash (i.e., shepherd never
has to respawn it). The only thing I see in its own log file that might
be suspicious is this:

Toggle snippet (17 lines)
2025-02-23 21:33:00 error: #<procedure 7fba1010cc60 at nar-herder/storage.scm:433:13 ()>:
2025-02-23 21:33:00 #<&port-read-timeout thunk: #<procedure 7fba1010cc80 at nar-herder/storage.scm:431:10 ()> port: #<closed: file 7fb9512eb700>>,
2025-02-23 21:33:00 attempt 1 of 3, retrying in 5
2025-02-23 21:33:01 2025-02-23 21:33:01 (INFO ): processing 1 recent changes
2025-02-23 21:33:11 2025-02-23 21:33:11 (INFO ): processing 1 recent changes
2025-02-23 21:33:21 2025-02-23 21:33:21 (INFO ): processing 1 recent changes
2025-02-23 21:33:31 2025-02-23 21:33:31 (INFO ): processing 1 recent changes
2025-02-23 21:33:35 error: #<procedure 7fba1010cc60 at nar-herder/storage.scm:433:13 ()>:
2025-02-23 21:33:35 #<&port-read-timeout thunk: #<procedure 7fba1010cc80 at nar-herder/storage.scm:431:10 ()> port: #<closed: file 7fb946607070>>,
2025-02-23 21:33:35 attempt 2 of 3, last retry in 5
2025-02-23 21:33:40 running last retry of #<procedure 7fba1010cc60 at nar-herder/storage.scm:433:13 ()> after 2 failed attempts
2025-02-23 21:33:51 2025-02-23 21:33:51 (INFO ): processing 1 recent changes
2025-02-23 21:33:58 error: #<procedure 7fb95e06b640 at nar-herder/storage.scm:433:13 ()>:
2025-02-23 21:33:58 #<&compound-exception components: (#<&error> #<&irritants irritants: (read-header-line #<eof>)> #<&exception-with-kind-and-args kind: bad-header args: (read-header-line #<eof>)>)>,
2025-02-23 21:33:58 attempt 1 of 3, retrying in 5

WDYT, Chris?

Thanks,
Ludo’.
T
T
Timo Wilken wrote on 7 Mar 01:24 -0800
Frequent TLS error in `guix substitute'
D89XC16HTQWZ.1H013DS6Q0PDT@twilken.net
Hi Ludo’,

Thank you very much for your effort in tracking this down!

Just to be clear, in case this is server-related: I reported this issue when
it happened to me with bordeaux, but I have a (nonfree) substitute server
before it in the list, which fails more frequently (and which I'm happy to
name on request).

I can't remember ever seeing the same failure with ci.guix.gnu.org, but that
may just be down to random chance, since ci.guix is checked last on my system.

So, my list of substitute servers is, in order:

1. https://substitutes.[redacted].org: most frequent TLS errors
2. https://bordeaux.guix.gnu.org:very occasional TLS errors
3. https://ci.guix.gnu.org:no TLS errors observed

Ludovic Courtès wrote 1 weeks ago https://issues.guix.gnu.org/76558:
Toggle quote (3 lines)
> At long last. Note that we'll need to update the ‘guix’ package to make this
> change effective.

That explains why it's still happening to me then!

Cheers,
Timo
?
Your comment

Commenting via the web interface is currently disabled.

To comment on this conversation send an email to 75679@patchwise.org

To respond to this issue using the mumi CLI, first switch to it
mumi current 75679
Then, you may apply the latest patchset in this issue (with sign off)
mumi am -- -s
Or, compose a reply to this issue
mumi compose
Or, send patches to this issue
mumi send-email *.patch