bug#56709: Channel opening failure with guix deploy

bug#56709: Channel opening failure with guix deploy

[Aleksandr Vityazev]

Hi,

I use 'guix deploy' to deploy on a machine on the local network. There
is no problem using ssh as standard, but 'guix deploy' fails.  Machine
configuration:
https://paste.sr.ht/~akagi/04c11305b19b1b25d0e61a88f6892057dee01b67

So far, I do not understand how to approach this problem, I would be
very grateful for any advice.

Log:

-*- mode: compilation; default-directory: "~/dotfiles/" -*-
Compilation started at Fri Jul 22 19:46:59

make deploy
guix deploy magi/system/remote/deploy.scm
The following 1 machine will be deployed:
  home-server

guix deploy: deploying to home-server...
guix deploy: sending 0 store items (0 MiB) to '192.168.1.103'...
guix deploy: sending 0 store items (0 MiB) to '192.168.1.103'...
substitute: updating substitutes from 'http://ci.guix.trop.in'... 100.0%
substitute: updating substitutes from 'https://bordeaux.guix.gnu.org'... 100.0%
substitute: updating substitutes from 'https://substitutes.nonguix.org'... 100.0%
The following derivations will be built:
  /gnu/store/fjychria4fq95iy5m1zasxnirk0y6v48-remote-exp.scm.drv
  /gnu/store/nlx7rql98r2vmcp3vsh8iyza84idygrs-switch-to-system.scm.drv
  /gnu/store/hnrjnbqgzn664zqs2wvcsvm8ld5y0vf3-system.drv
  /gnu/store/4p6q4l0ya16z0vahfp6i52r1gps82642-profile.drv
  /gnu/store/835gjdjaclznrpymk8f5ir6c259pg4xy-provenance.drv

building /gnu/store/835gjdjaclznrpymk8f5ir6c259pg4xy-provenance.drv...
building CA certificate bundle...
listing Emacs sub-directories...
building fonts directory...
building directory of Info manuals...
building database for manual pages...
building profile with 51 packages...
building /gnu/store/hnrjnbqgzn664zqs2wvcsvm8ld5y0vf3-system.drv...
building /gnu/store/nlx7rql98r2vmcp3vsh8iyza84idygrs-switch-to-system.scm.drv...
building /gnu/store/fjychria4fq95iy5m1zasxnirk0y6v48-remote-exp.scm.drv...
guix deploy: sending 11 store items (2 MiB) to '192.168.1.103'...
guix deploy: sending 0 store items (0 MiB) to '192.168.1.103'...
The following derivations will be built:
  /gnu/store/p6hxcnb7drm1yhcsmhicziv1mmad1p7y-remote-exp.scm.drv
  /gnu/store/z2p4a8zq70vqcx9lk7mn0rravy6nw46r-upgrade-shepherd-services.scm.drv

building /gnu/store/z2p4a8zq70vqcx9lk7mn0rravy6nw46r-upgrade-shepherd-services.scm.drv...
building /gnu/store/p6hxcnb7drm1yhcsmhicziv1mmad1p7y-remote-exp.scm.drv...
;;; [2022/07/22 19:47:46.682720, 0] [GSSH ERROR] Channel opening failure: channel 63 error (2) open failed: #<input-output: channel (closed) 7f55329f2720>
Backtrace:
In guix/store.scm:
  1380:11 19 (map/accumulate-builds #<store-connection 256.99 7f553…> …)
   1298:8 18 (call-with-build-handler #<procedure 7f5532e12e40 at g…> …)
In ice-9/boot-9.scm:
  1752:10 17 (with-exception-handler _ _ #:unwind? _ # _)
In guix/scripts/deploy.scm:
    159:6 16 (_)
In guix/store.scm:
  2168:25 15 (run-with-store #<store-connection 256.99 7f55359e6820> …)
In gnu/machine/ssh.scm:
   498:10 14 (_ _)
   499:39 13 (_ _)
In ice-9/boot-9.scm:
  1752:10 12 (with-exception-handler _ _ #:unwind? _ # _)
In gnu/machine/ssh.scm:
   499:39 11 (_)
In guix/store.scm:
  2168:25 10 (run-with-store #<store-connection 256.99 7f553484f0f0> …)
In guix/remote.scm:
   138:10  9 (_ _)
In guix/store.scm:
  2040:38  8 (_ #<store-connection 256.99 7f553484f0f0>)
In guix/ssh.scm:
    372:2  7 (send-files #<store-connection 256.99 7f553484f0f0> _ # …)
    218:5  6 (remote-run (begin (use-modules (guix) (srfi #) # #) …) #)
In ssh/popen.scm:
     64:4  5 (open-remote-pipe* _ "r+" _ . _)
In unknown file:
           4 (channel-open-session #<input-output: channel (closed) …>)
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 `("channel-open-session" "Channel opening failure: channel 63 error (2) open failed" #<input-output: channel (closed) 7f55329f2720> #f)'.
make: *** [Makefile:32: deploy] Error 1

-- 
Best regards,
Aleksandr Vityazev

bug#56709: (No Subject)

[Attila Lendvai]

i'm also seeing this, and the solution was to comment out the (identity ...) field of my machine-ssh-configuration.

maybe my id_ed25519 key is not supported?

it seems to be able to talk to the target and even installed some stuff into its store, and only dies when it's already deep into the process.

BTW, the configuration field names and doc are somewhat confusing. e.g. the identity field expects a file path as a string; i.e. a file-like GEXP object doesn't work, and neither does a copy-pasted public key as a scheme string.

also, should it be the .pub part, or the private part?

maybe a pitfall pointer could be added to the manual until the error message is made more edifying?

- attila

PS: my output when it failed for me:

$ guix deploy lendvai.scm
The following 1 machine will be deployed:
  lendvai

guix deploy: deploying to lendvai...
guix deploy: sending 0 store items (0 MiB) to 'lendvai.name'...
guix deploy: sending 0 store items (0 MiB) to 'lendvai.name'...
guix deploy: sending 0 store items (0 MiB) to 'lendvai.name'...
guix deploy: sending 0 store items (0 MiB) to 'lendvai.name'...
;;; [2022/12/21 22:16:19.061054, 0] [GSSH ERROR] Channel opening failure: channel 63 error (2) open failed: #<input-output: channel (closed) 7ff538de42e0>
Backtrace:
In guix/store.scm:
  1382:11 19 (map/accumulate-builds #<store-connection 256.99 7ff53be77a50> …)
   1300:8 18 (call-with-build-handler #<procedure 7ff5387f3a20 at guix/sto…> …)
In ice-9/boot-9.scm:
  1752:10 17 (with-exception-handler _ _ #:unwind? _ #:unwind-for-type _)
In guix/scripts/deploy.scm:
    167:6 16 (_)
In guix/store.scm:
  2170:25 15 (run-with-store #<store-connection 256.99 7ff53be77a50> _ # _ # …)
In gnu/machine/ssh.scm:
   538:12 14 (_ _)
   539:41 13 (_ _)
In ice-9/boot-9.scm:
  1752:10 12 (with-exception-handler _ _ #:unwind? _ #:unwind-for-type _)
In gnu/machine/ssh.scm:
   539:41 11 (_)
In guix/store.scm:
  2170:25 10 (run-with-store #<store-connection 256.99 7ff53823e910> #<pro…> …)
In guix/remote.scm:
   138:10  9 (_ _)
In guix/store.scm:
  2042:38  8 (_ #<store-connection 256.99 7ff53823e910>)
In guix/ssh.scm:
    376:2  7 (send-files #<store-connection 256.99 7ff53823e910> _ #<store…> …)
    222:5  6 (remote-run (begin (use-modules (guix) (srfi srfi-34) (…) …) …) …)
In ssh/popen.scm:
     64:4  5 (open-remote-pipe* _ "r+" _ . _)
In unknown file:
           4 (channel-open-session #<input-output: channel (closed) 7ff538d…>)
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 `("channel-open-session" "Channel opening failure: channel 63 error (2) open failed" #<input-output: channel (closed) 7ff538de42e0> #f)'.

bug#56709: (No Subject)

[Attila Lendvai]

> i'm also seeing this, and the solution was to comment
> out the (identity ...) field of my machine-ssh-configuration.

i spoke too soon. today it's again broken for me the same way, even though identity is commented out. lechner on IRC also reported that it's broken for him.

random hint, maybe not relevant: i may have pulled in the short time since i wrote my previous mail, and there may have been a guile-ssh update in that pull.

- attila

bug#56709: (No Subject)

[Attila Lendvai]

> > i'm also seeing this, and the solution was to comment
> > out the (identity ...) field of my machine-ssh-configuration.
> 
>
> i spoke too soon. today it's again broken for me the same way, even
> though identity is commented out. lechner on IRC also reported that
> it's broken for him.


since then it's working again. this seems to be some transient issue. possibly related to network state?

note that normal SSH always works. it's only a late phase of `guix deploy` where this error sometimes shows up.

-- 
• attila lendvai
• PGP: 963F 5D5F 45C7 DFCD 0A39
--
“The most urgent necessity is, not that the State should teach, but that it should allow education. All monopolies are detestable, but the worst of all is the monopoly of education.”
	— Frédéric Bastiat (1801–1850), 'What Is Money?'

bug#56709: Channel opening failure with guix deploy

[Thompson, David]

Hello,

This problem is strangely transient.  I've seen it happen to others
when it wasn't happening to me with the same remote machine.  Now I am
having this problem again on 2 different servers that I manage.  I dug
around a bit and found that calls to 'open-remote-pipe*' from
guile-ssh have some chance of failure even though the SSH session is
fine. This procedure is called many times during a deploy, so the odds
are high that one of them will fail.  I got lucky once today and had a
deploy finish but that was after many failures.  I was able to unblock
myself by hacking call sites to repeatedly call 'open-remote-pipe*' in
a loop, like this:

    (let loop ()
         (or (false-if-exception
              (apply open-remote-pipe* session OPEN_BOTH repl-command))
             (loop)))

I also added some 'pk' logging and found that 'open-remote-pipe*'
would typically succeed on the first or second try.  I think there
could be a bit more investigation done to better understand *why* this
happens in the first place, but as a resiliency tactic I think it
would be appropriate to write a wrapper procedure that retries a few
times before giving up.

Thoughts?

- Dave