GNU bug report logs -
#75679
Frequent TLS error in `guix substitute'
Previous Next
Reported by: "Timo Wilken" <guix <at> twilken.net>
Date: Sun, 19 Jan 2025 22:58:02 UTC
Severity: important
Merged with 76486
Done: Ludovic Courtès <ludo <at> gnu.org>
Bug is archived. No further changes may be made.
To add a comment to this bug, you must first unarchive it, by sending
a message to control AT debbugs.gnu.org, with unarchive 75679 in the body.
You can then email your comments to 75679 AT debbugs.gnu.org in the normal way.
Toggle the display of automated, internal messages from the tracker.
Report forwarded
to
bug-guix <at> gnu.org
:
bug#75679
; Package
guix
.
(Sun, 19 Jan 2025 22:58:02 GMT)
Full text and
rfc822 format available.
Acknowledgement sent
to
"Timo Wilken" <guix <at> twilken.net>
:
New bug report received and forwarded. Copy sent to
bug-guix <at> gnu.org
.
(Sun, 19 Jan 2025 22:58:02 GMT)
Full text and
rfc822 format available.
Message #5 received at submit <at> debbugs.gnu.org (full text, mbox):
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
repository URL: https://git.twilken.net/dotfiles
branch: master
commit: 387cd9f2085d0ef3e192523113b9ed6d9041aae0
guix 5e834c2
repository URL: https://git.savannah.gnu.org/git/guix.git
branch: master
commit: 5e834c220e81fddb77a26e23cf0cd5055b866844
[non-free channels omitted]
Severity set to 'important' from 'normal'
Request was from
Ludovic Courtès <ludo <at> gnu.org>
to
control <at> debbugs.gnu.org
.
(Wed, 05 Feb 2025 14:51:02 GMT)
Full text and
rfc822 format available.
Merged 75679 76486.
Request was from
Ludovic Courtès <ludo <at> gnu.org>
to
control <at> debbugs.gnu.org
.
(Tue, 25 Feb 2025 15:54:03 GMT)
Full text and
rfc822 format available.
Information forwarded
to
bug-guix <at> gnu.org
:
bug#75679
; Package
guix
.
(Tue, 25 Feb 2025 16:06:02 GMT)
Full text and
rfc822 format available.
Message #12 received at 75679 <at> debbugs.gnu.org (full text, mbox):
Hi,
"Timo Wilken" <guix <at> twilken.net> skribis:
> 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:
https://issues.guix.gnu.org/76558
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:
--8<---------------cut here---------------start------------->8---
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
--8<---------------cut here---------------end--------------->8---
WDYT, Chris?
Thanks,
Ludo’.
Information forwarded
to
bug-guix <at> gnu.org
:
bug#75679
; Package
guix
.
(Fri, 07 Mar 2025 09:26:02 GMT)
Full text and
rfc822 format available.
Message #15 received at 75679 <at> debbugs.gnu.org (full text, mbox):
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>:
> 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
Information forwarded
to
bug-guix <at> gnu.org
:
bug#75679
; Package
guix
.
(Tue, 08 Apr 2025 20:33:02 GMT)
Full text and
rfc822 format available.
Message #18 received at 75679 <at> debbugs.gnu.org (full text, mbox):
Hello,
can this be closed now as
https://issues.guix.gnu.org/76558
is merged?
Andreas
Information forwarded
to
bug-guix <at> gnu.org
:
bug#75679
; Package
guix
.
(Tue, 08 Apr 2025 20:37:01 GMT)
Full text and
rfc822 format available.
Message #21 received at 75679 <at> debbugs.gnu.org (full text, mbox):
Hi Andreas,
On Tue 8 Apr 2025 at 10:31 pm CEST, Andreas Enge wrote:
> can this be closed now as
> https://issues.guix.gnu.org/76558
> is merged?
I am no longer inconvenienced by this, though I still see the warnings emitted
by the change in the patch you linked, so the underlying issue is still there.
Up to you if you consider this fixed. Feel free to close this if so :)
Cheers,
Timo
Information forwarded
to
bug-guix <at> gnu.org
:
bug#75679
; Package
guix
.
(Wed, 09 Apr 2025 07:51:02 GMT)
Full text and
rfc822 format available.
Message #24 received at 75679 <at> debbugs.gnu.org (full text, mbox):
Hello Timo,
Am Tue, Apr 08, 2025 at 10:36:06PM +0200 schrieb Timo Wilken:
> I am no longer inconvenienced by this, though I still see the warnings emitted
> by the change in the patch you linked, so the underlying issue is still there.
> Up to you if you consider this fixed. Feel free to close this if so :)
I will let Ludovic decide, I just asked the question since I randomly
stumbled upon this issue.
Andreas
Reply sent
to
Ludovic Courtès <ludo <at> gnu.org>
:
You have taken responsibility.
(Fri, 11 Apr 2025 19:14:02 GMT)
Full text and
rfc822 format available.
Notification sent
to
"Timo Wilken" <guix <at> twilken.net>
:
bug acknowledged by developer.
(Fri, 11 Apr 2025 19:14:02 GMT)
Full text and
rfc822 format available.
Message #29 received at 75679-done <at> debbugs.gnu.org (full text, mbox):
Andreas Enge <andreas <at> enge.fr> skribis:
> can this be closed now as
> https://issues.guix.gnu.org/76558
> is merged?
I think so. Done! :-)
Reply sent
to
Ludovic Courtès <ludo <at> gnu.org>
:
You have taken responsibility.
(Fri, 11 Apr 2025 19:14:02 GMT)
Full text and
rfc822 format available.
Notification sent
to
"Timo Wilken" <guix <at> twilken.net>
:
bug acknowledged by developer.
(Fri, 11 Apr 2025 19:14:02 GMT)
Full text and
rfc822 format available.
bug archived.
Request was from
Debbugs Internal Request <help-debbugs <at> gnu.org>
to
internal_control <at> debbugs.gnu.org
.
(Sat, 10 May 2025 11:24:18 GMT)
Full text and
rfc822 format available.
This bug report was last modified 39 days ago.
Previous Next
GNU bug tracking system
Copyright (C) 1999 Darren O. Benham,
1997,2003 nCipher Corporation Ltd,
1994-97 Ian Jackson.