Subject: bug#58290: guile ssh error on guix deploy

From: Ludovic Courtès <[email-masked]>
Date: Thu, 12 Jan 2023 13:11:24 +0100

Hi,

Marius Bakke <[email-masked]> skribis:

> Nov  3 21:50:28 capella sshd[26115]: debug1: server_input_channel_open: ctype session rchan 66 win 64000 max 32768
> Nov  3 21:50:28 capella sshd[26115]: debug1: input_session_request
> Nov  3 21:50:28 capella sshd[26115]: debug1: channel 10: new [server-session]
> Nov  3 21:50:28 capella sshd[26115]: debug1: session_open: channel 10
> ["no more sessions" error occurs here, in a different log file]
> Nov  3 21:50:28 capella sshd[26115]: debug1: session open failed, free channel 10
> Nov  3 21:50:28 capella sshd[26115]: debug1: channel 10: free: server-session, nchannels 11
> Nov  3 21:50:28 capella sshd[26115]: debug1: server_input_channel_open: failure session
> Nov  3 21:50:28 capella sshd[26115]: debug1: channel 0: free: server-session, nchannels 10
> Nov  3 21:50:28 capella sshd[26115]: debug1: channel 1: free: server-session, nchannels 9
> Nov  3 21:50:28 capella sshd[26115]: debug1: channel 2: free: server-session, nchannels 8
> Nov  3 21:50:28 capella sshd[26115]: debug1: channel 3: free: server-session, nchannels 7
> Nov  3 21:50:28 capella sshd[26115]: debug1: channel 4: free: server-session, nchannels 6

[...]

> In my current tests the failure always occur at the
> very end of deploy:
>
> building /gnu/store/19yajyzw4jhnkkz9w0l9gm4az0jxihkc-install-bootloader.scm.drv...
> building /gnu/store/m7ngq5gszyswm6sficinz7ghpra30dl4-remote-exp.scm.drv...
> ;;; [2022/11/03 21:50:28.892606, 0] [GSSH ERROR] Channel opening failure: channel 66 error (2) open failed: #<input-output: channel (closed) 7fdefb015e80>
>
> What's interesting is that all of the failed deploys fail to open
> "channel 10", whereas successful deploys never reach it.  All of these
> are deploying the exact same configuration and commit, so the SSH
> traffic should nearly identical.

Here’s a reproducer:

--8<---------------cut here---------------start------------->8---
(use-modules (guix ssh)
             (guix))

(define %local
  (open-connection))

(define %remote
  (connect-to-remote-daemon (open-ssh-session "HOST-OF-YOUR-CHOICE")))

(let loop ((i 0))
  (pk 'loop i)
  (send-files %local '("/gnu/store/8fpk2cja3f07xls48jfnpgrzrljpqivr-coreutils-8.32") %remote)
  (loop (+ 1 i)))
--8<---------------cut here---------------end--------------->8---

It fails after 8 iterations.  It looks like we’re leaking SSH channels
or something.

However, in GDB, we can see that ‘ssh_channel_close’ is indeed called
after each iteration (via ‘ptob_close’ in Guile-SSH).

Artyom, does that ring a bell?

Thanks,
Ludo’.