GNU bug report logs - #36364
Potential SSH session exhaustion

Previous Next

Package: guix;

Reported by: zerodaysfordays <at> sdf.lonestar.org (Jakob L. Kreuze)

Date: Mon, 24 Jun 2019 17:31:02 UTC

Severity: normal

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

Bug is archived. No further changes may be made.

Full log


View this message in rfc822 format

From: help-debbugs <at> gnu.org (GNU bug Tracking System)
To: zerodaysfordays <at> sdf.lonestar.org (Jakob L. Kreuze)
Subject: bug#36364: closed (Re: bug#36364: Potential SSH session exhaustion)
Date: Tue, 25 Jun 2019 16:15:02 +0000
[Message part 1 (text/plain, inline)]
Your bug report

#36364: Potential SSH session exhaustion

which was filed against the guix package, has been closed.

The explanation is attached below, along with your original report.
If you require more details, please reply to 36364 <at> debbugs.gnu.org.

-- 
36364: http://debbugs.gnu.org/cgi/bugreport.cgi?bug=36364
GNU Bug Tracking System
Contact help-debbugs <at> gnu.org with problems
[Message part 2 (message/rfc822, inline)]
From: Ludovic Courtès <ludo <at> gnu.org>
To: zerodaysfordays <at> sdf.lonestar.org (Jakob L. Kreuze)
Cc: 36364-done <at> debbugs.gnu.org
Subject: Re: bug#36364: Potential SSH session exhaustion
Date: Tue, 25 Jun 2019 18:14:16 +0200
Hi,

zerodaysfordays <at> sdf.lonestar.org (Jakob L. Kreuze) skribis:

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

[...]

>> I see that ‘remote-eval’ does not close ‘remote’ though, so this
>> channel port remains open until it’s GC’d, which happens too late.
>> Could you try the attached patch? It allows me to do more than 10
>> ‘remote-eval’ calls in a row.
>
> Wow, that was quick. The patch works like a charm, thanks!

Cool, thanks for testing!

(I plan to merge the ‘remove-eval’ patches soonish…)

Ludo’.

[Message part 3 (message/rfc822, inline)]
From: zerodaysfordays <at> sdf.lonestar.org (Jakob L. Kreuze)
To: bug-guix <at> gnu.org
Subject: Potential SSH session exhaustion
Date: Mon, 24 Jun 2019 13:23:31 -0400
[Message part 4 (text/plain, inline)]
Hello, Guix

In developing a test suite for the internals of 'guix deploy', the
virtual machine I spun up spat out an OpenSSH error that I've never
encountered before.

  Jun 24 16:59:26 localhost sshd[235]: error: no more sessions

This is, initially, quite curious. Creating the SSH session with
#:log-verbosity set to 'protocol gives some insight.

  ;;; [2019/06/24 13:08:36.711847, 2] channel_open: Creating a channel 43 with 64000 window and 32768 max packet
  ;;; [2019/06/24 13:08:36.711959, 2] ssh_packet_global_request: Received SSH_MSG_GLOBAL_REQUEST packet
  ;;; [2019/06/24 13:08:36.711987, 2] ssh_packet_global_request: UNKNOWN SSH_MSG_GLOBAL_REQUEST hostkeys-00 <at> openssh.com 0
  ;;; [2019/06/24 13:08:36.712010, 1] ssh_packet_process: Couldn't do anything with packet type 80
  ;;; [2019/06/24 13:08:36.712197, 2] ssh_packet_channel_open_conf: Received a CHANNEL_OPEN_CONFIRMATION for channel 43:0
  ;;; [2019/06/24 13:08:36.712219, 2] ssh_packet_channel_open_conf: Remote window : 0, maxpacket : 32768
  ;;; [2019/06/24 13:08:36.712618, 2] channel_rcv_change_window: Adding 2097152 bytes to channel (43:0) (from 0 bytes)
  ;;; [2019/06/24 13:08:36.712651, 2] channel_request: Channel request exec success
  ...
  ;;; [2019/06/24 12:59:26.296022, 2] channel_open: Creating a channel 74 with 64000 window and 32768 max packet
  ;;; [2019/06/24 12:59:26.296262, 2] ssh_packet_channel_open_conf: Received a CHANNEL_OPEN_CONFIRMATION for channel 74:8
  ;;; [2019/06/24 12:59:26.296308, 2] ssh_packet_channel_open_conf: Remote window : 0, maxpacket : 32768
  ;;; [2019/06/24 12:59:26.296667, 2] channel_rcv_change_window: Adding 2097152 bytes to channel (74:8) (from 0 bytes)
  ;;; [2019/06/24 12:59:26.296721, 2] channel_request: Channel request exec success
  ;;; [2019/06/24 12:59:26.487339, 2] grow_window: growing window (channel 74:8) to 1280000 bytes
  ;;; [2019/06/24 12:59:26.489031, 2] channel_open: Creating a channel 75 with 64000 window and 32768 max packet
  ;;; [2019/06/24 12:59:26.489376, 2] ssh_packet_channel_open_conf: Received a CHANNEL_OPEN_CONFIRMATION for channel 75:8
  ;;; [2019/06/24 12:59:26.489402, 2] ssh_packet_channel_open_conf: Remote window : 0, maxpacket : 32768
  ;;; [2019/06/24 12:59:26.489858, 2] channel_rcv_change_window: Adding 2097152 bytes to channel (75:8) (from 0 bytes)
  ;;; [2019/06/24 12:59:26.489906, 2] channel_request: Channel request exec success
  ;;; [2019/06/24 12:59:26.542586, 2] grow_window: growing window (channel 75:8) to 1280000 bytes
  ;;; [2019/06/24 12:59:26.546104, 2] channel_open: Creating a channel 76 with 64000 window and 32768 max packet
  ;;; [2019/06/24 12:59:26.546407, 2] ssh_packet_channel_open_conf: Received a CHANNEL_OPEN_CONFIRMATION for channel 76:9
  ;;; [2019/06/24 12:59:26.546438, 2] ssh_packet_channel_open_conf: Remote window : 0, maxpacket : 32768
  ;;; [2019/06/24 12:59:26.546839, 2] channel_rcv_change_window: Adding 2097152 bytes to channel (76:9) (from 0 bytes)
  ;;; [2019/06/24 12:59:26.546865, 2] channel_request: Channel request exec success
  ;;; [2019/06/24 12:59:26.630055, 2] grow_window: growing window (channel 76:9) to 1280000 bytes
  ;;; [2019/06/24 12:59:27.272139, 2] channel_open: Creating a channel 77 with 64000 window and 32768 max packet
  ;;; [2019/06/24 12:59:27.272846, 1] ssh_packet_channel_open_fail: Channel opening failure: channel 77 error (2) open failed

I will admit that my knowledge of the SSH protocol is limited, but the
rising channel number gives me the impression that channels are going
out of scope and aren't being cleaned up. For reference, this occurs
when 'remote-eval' is invoked multiple times -- which, in turn, invokes
'send-files'.

  building path(s) `/gnu/store/3rfkwdbayg7m3wdrydmcljnfqhvrady5-remote-exp.scm'
  sending 1 store item (0 MiB) to 'localhost'...
  exporting path `/gnu/store/3rfkwdbayg7m3wdrydmcljnfqhvrady5-remote-exp.scm'
  building path(s) `/gnu/store/ib59b0pnypsw4vf59f2gwpwhn343xnzb-remote-exp.scm'
  sending 1 store item (0 MiB) to 'localhost'...
  exporting path `/gnu/store/ib59b0pnypsw4vf59f2gwpwhn343xnzb-remote-exp.scm'
  [this is where the "no more sessions" error occurs]

Currently, my code performs all of these 'remote-eval' calls with the
same session. I suppose it would be possible to create a new session for
each call, but I feel I should raise this as it may cause issues down
the line: do we need to do something about cleaning up SSH channels?

If a reproducible example is necessary, you can look to the temporary
'tests/machine.scm' in 64ffe453b0c71f417927737fa808dffe858359cd on my
personal branch.[1]

Regards,
Jakob

[1]: https://git.sr.ht/~jakob/guix/
[signature.asc (application/pgp-signature, inline)]

This bug report was last modified 6 years and 23 days ago.

Previous Next


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