GNU bug report logs - #62213
GSSH ERROR while sending store items with 'guix deploy'

Previous Next

To reply to this bug, email your comments to 62213 AT debbugs.gnu.org.

Toggle the display of automated, internal messages from the tracker.

Message #5 received at submit <at> debbugs.gnu.org (full text, mbox):

From: Maxim Cournoyer <maxim.cournoyer <at> gmail.com>
To: bug-guix <bug-guix <at> gnu.org>
Subject: GSSH ERROR while sending store items with 'guix deploy'
Date: Wed, 15 Mar 2023 22:02:20 -0400

Hi,

I'm trying to update one of my machines using 'guix deploy' and I keep
getting the following error:

--8<---------------cut here---------------start------------->8---
guix deploy: sending 599 store items (3,794 MiB) to 'x200.local'...
 20% ▕███████████████████▋                                                                               ▏
 27% ▕██████████████████████████▎                                                                        ▏;;; [2023/03/15 21:57:28.007492, 0] [GSSH ERROR] Parent session is not connected: #<unknown channel (freed) 7fca183c31c0>
Backtrace:
In ice-9/boot-9.scm:
  1752:10 19 (with-exception-handler _ _ #:unwind? _ # _)
In guix/scripts/deploy.scm:
    166:6 18 (_)
In guix/store.scm:
  2168:25 17 (run-with-store #<store-connection 256.99 7fca0e115d70> …)
In gnu/machine/ssh.scm:
    528:8 16 (_ _)
   530:30 15 (_ _)
In ice-9/boot-9.scm:
  1752:10 14 (with-exception-handler _ _ #:unwind? _ # _)
In gnu/machine/ssh.scm:
   530:30 13 (_)
In guix/store.scm:
  2168:25 12 (run-with-store #<store-connection 256.99 7fca0c81c140> …)
In guix/remote.scm:
   136:10 11 (_ _)
In guix/store.scm:
  2040:38 10 (_ #<store-connection 256.99 7fca0c81c140>)
In guix/ssh.scm:
    530:7  9 (send-files _ _ _ #:recursive? _ #:log-port _)
In guix/store.scm:
  1764:12  8 (export-paths #<store-connection 256.99 7fca0c81c140> _ …)
  1731:22  7 (export-path #<store-connection 256.99 7fca0c81c140> _ # …)
   716:13  6 (process-stderr _ _)
In guix/build/utils.scm:
  1014:11  5 (loop _ _)
In unknown file:
           4 (put-bytevector #<unknown channel (freed) 7fca183c31c0> …)
In ice-9/boot-9.scm:
  1685:16  3 (raise-exception _ #:continuable? _)
  1683: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:
Throw to key `guile-ssh-error' with args `("write_to_channel_port"
"Parent session is not connected" #<unknown channel (freed)
7fca183c31c0> #f)'.
--8<---------------cut here---------------end--------------->8---

It works for a while, so it'll eventually succeeds, but that seems a new
regression (it didn't use to do that).

-- 
Thanks,
Maxim

Message #8 received at 62213 <at> debbugs.gnu.org (full text, mbox):

From: Ludovic Courtès <ludo <at> gnu.org>
To: Maxim Cournoyer <maxim.cournoyer <at> gmail.com>
Cc: 62213 <at> debbugs.gnu.org
Subject: Re: bug#62213: GSSH ERROR while sending store items with 'guix deploy'
Date: Fri, 17 Mar 2023 22:15:42 +0100

Hi,

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

> I'm trying to update one of my machines using 'guix deploy' and I keep
> getting the following error:
>
> guix deploy: sending 599 store items (3,794 MiB) to 'x200.local'...
>  20% ▕███████████████████▋                                                                               ▏

[...]

>    716:13  6 (process-stderr _ _)
> In guix/build/utils.scm:
>   1014:11  5 (loop _ _)
> In unknown file:
>            4 (put-bytevector #<unknown channel (freed) 7fca183c31c0> …)
> In ice-9/boot-9.scm:
>   1685:16  3 (raise-exception _ #:continuable? _)
>   1683: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:
> Throw to key `guile-ssh-error' with args `("write_to_channel_port"
> "Parent session is not connected" #<unknown channel (freed)

What version of guix-daemon is running on the machine that runs "guix
deploy"?

Do the sshd logs on x200.local show anything interesting at the moment
the connection is dropped?

Thanks,
Ludo'.

Message #11 received at 62213 <at> debbugs.gnu.org (full text, mbox):

From: Maxim Cournoyer <maxim.cournoyer <at> gmail.com>
To: Ludovic Courtès <ludo <at> gnu.org>
Cc: 62213 <at> debbugs.gnu.org
Subject: Re: bug#62213: GSSH ERROR while sending store items with 'guix deploy'
Date: Mon, 20 Mar 2023 16:22:06 -0400

Hi Ludo!

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

> Hi,
>
> Maxim Cournoyer <maxim.cournoyer <at> gmail.com> skribis:
>
>> I'm trying to update one of my machines using 'guix deploy' and I keep
>> getting the following error:
>>
>> guix deploy: sending 599 store items (3,794 MiB) to 'x200.local'...
>>  20% ▕███████████████████▋ ▏
>
> [...]
>
>>    716:13  6 (process-stderr _ _)
>> In guix/build/utils.scm:
>>   1014:11  5 (loop _ _)
>> In unknown file:
>>            4 (put-bytevector #<unknown channel (freed) 7fca183c31c0> …)
>> In ice-9/boot-9.scm:
>>   1685:16  3 (raise-exception _ #:continuable? _)
>>   1683: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:
>> Throw to key `guile-ssh-error' with args `("write_to_channel_port"
>> "Parent session is not connected" #<unknown channel (freed)
>
> What version of guix-daemon is running on the machine that runs "guix
> deploy"?

Two variants of 1.4.0-4.01fd830:

--8<---------------cut here---------------start------------->8---
$ pgrep -a guix-daemon
6883 /gnu/store/izxlr8c7aml0ajqpblidkq014wyxcczz-guix-1.4.0-4.01fd830/bin/guix-daemon 6822                guixbuild --max-silent-time 0 --timeout 0 --log-compression none --discover=yes --substitute-urls http://127.0.0.1:8181 https://ci.guix.gnu.org https://bordeaux.guix.gnu.org --max-jobs=4
13519 /gnu/store/izxlr8c7aml0ajqpblidkq014wyxcczz-guix-1.4.0-4.01fd830/bin/guix-daemon 13504               guixbuild --max-silent-time 0 --timeout 0 --log-compression none --discover=yes --substitute-urls http://127.0.0.1:8181 https://ci.guix.gnu.org https://bordeaux.guix.gnu.org --max-jobs=4
27855 /gnu/store/izxlr8c7aml0ajqpblidkq014wyxcczz-guix-1.4.0-4.01fd830/bin/guix-daemon --build-users-group guixbuild --max-silent-time 0 --timeout 0 --log-compression none --discover=yes --substitute-urls http://127.0.0.1:8181 https://ci.guix.gnu.org https://bordeaux.guix.gnu.org --max-jobs=4
28995 /gnu/store/izxlr8c7aml0ajqpblidkq014wyxcczz-guix-1.4.0-4.01fd830/bin/guix-daemon 28982               guixbuild --max-silent-time 0 --timeout 0 --log-compression none --discover=yes --substitute-urls http://127.0.0.1:8181 https://ci.guix.gnu.org https://bordeaux.guix.gnu.org --max-jobs=4
--8<---------------cut here---------------end--------------->8---

> Do the sshd logs on x200.local show anything interesting at the moment
> the connection is dropped?

In my logs, at around the time I was observing these problems, I see a
couple instances of:

--8<---------------cut here---------------start------------->8---
Mar 15 22:03:58 localhost shepherd[1]: Service sshd-7 has been started. 
Mar 15 22:03:59 localhost sshd[24950]: Accepted publickey for mcournoyer from 192.168.10.15 port 40696 ssh2: RSA SHA256:bNjGrjJ6+adVo155SohxuXbuxeJB+w/+vQzhdFs3vUg
Mar 15 22:07:57 localhost sshd[24952]: ssh_dispatch_run_fatal: Connection from user mcournoyer 192.168.10.15 port 40696: invalid format
Mar 15 22:07:57 localhost shepherd[1]: 0 connections still in use after sshd-7 termination. 
Mar 15 22:07:57 localhost shepherd[1]: Service sshd-7 (PID 24950) exited with 255. 
Mar 15 22:07:57 localhost shepherd[1]: Service sshd-7 has been disabled. 
Mar 15 22:07:57 localhost shepherd[1]: Transient service sshd-7 terminated, now unregistered. 
Mar 15 22:14:41 localhost shepherd[1]: Service sshd-8 has been started. 
Mar 15 22:14:42 localhost sshd[25142]: Accepted publickey for mcournoyer from 192.168.10.15 port 45596 ssh2: RSA SHA256:bNjGrjJ6+adVo155SohxuXbuxeJB+w/+vQzhdFs3vUg
Mar 15 22:20:02 localhost shepherd[1]: 0 connections still in use after sshd-8 termination. 
Mar 15 22:20:02 localhost shepherd[1]: Service sshd-8 (PID 25142) exited with 255. 
Mar 15 22:20:02 localhost shepherd[1]: Service sshd-8 has been disabled. 
Mar 15 22:20:02 localhost shepherd[1]: Transient service sshd-8 terminated, now unregistered. 
Mar 15 22:24:19 localhost shepherd[1]: Service sshd-9 has been started. 
Mar 15 22:24:20 localhost sshd[25463]: Accepted publickey for mcournoyer from 192.168.10.15 port 41702 ssh2: RSA SHA256:bNjGrjJ6+adVo155SohxuXbuxeJB+w/+vQzhdFs3vUg
--8<---------------cut here---------------end--------------->8---

Where the 'ssh_dispatch_run_fatal ... invalid format' stands out to me.

I'll report with more if I can reproduce the issue again.

-- 
Thanks,
Maxim

Message #14 received at 62213 <at> debbugs.gnu.org (full text, mbox):

From: Leo Famulari <leo <at> famulari.name>
To: Maxim Cournoyer <maxim.cournoyer <at> gmail.com>
Cc: 62213 <at> debbugs.gnu.org
Subject: Re: bug#62213: GSSH ERROR while sending store items with 'guix deploy'
Date: Thu, 18 May 2023 14:24:56 -0400

On Wed, Mar 15, 2023 at 10:02:20PM -0400, Maxim Cournoyer wrote:
> ice-9/boot-9.scm:1685:16: In procedure raise-exception:
> Throw to key `guile-ssh-error' with args `("write_to_channel_port"
> "Parent session is not connected" #<unknown channel (freed)
> 7fca183c31c0> #f)'.
> --8<---------------cut here---------------end--------------->8---

I'm seeing this too with offloading.

Previous Next

GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.