From debbugs-submit-bounces@debbugs.gnu.org Tue Oct 04 07:09:41 2022 Received: (at submit) by debbugs.gnu.org; 4 Oct 2022 11:09:41 +0000 Received: from localhost ([127.0.0.1]:52680 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1offnu-0004Su-05 for submit@debbugs.gnu.org; Tue, 04 Oct 2022 07:09:41 -0400 Received: from lists.gnu.org ([209.51.188.17]:42142) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1offnq-0004Sl-NE for submit@debbugs.gnu.org; Tue, 04 Oct 2022 07:09:35 -0400 Received: from eggs.gnu.org ([2001:470:142:3::10]:57490) by lists.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1offnn-0004YO-Mo for bug-guix@gnu.org; Tue, 04 Oct 2022 07:09:34 -0400 Received: from relay2-d.mail.gandi.net ([2001:4b98:dc4:8::222]:61597) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1offnk-0005Ad-3m for bug-guix@gnu.org; Tue, 04 Oct 2022 07:09:31 -0400 Received: (Authenticated sender: andrew@trop.in) by mail.gandi.net (Postfix) with ESMTPSA id D2B944000A for ; Tue, 4 Oct 2022 11:09:17 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=trop.in; s=gm1; t=1664881760; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:mime-version:mime-version:content-type:content-type; bh=invUQMAOJY6eAdrebLr7TAEvPCvXXPMLbBdnjyF+DaE=; b=eTW99gtSHxqUOzbT8qoK36X1lqrq4/9hj2CyE/Loi2+DGvIJkk3iWPv5IkS9lzl0qVV9UR poywlhoXFEgPv4h6lH5mWPbvFx1KuafGiAVZH/W63aXTxoLJLGOkxZDCU0faeW7uSkG68/ afJvyh2AMuY7F+Mf5/Bysv9l+ez69m6nRUuP+GvteNoN8hs3I/WT5nqCbKiLcSfio4M3gS 3h83akizIpU6sxEuwBgs0Zkf4AUipa/N4z2leiRb1TaPLa0ShNm7Pe5+B45n7aToMye2v5 SLF6zypApwzH4yw4w4bA08cLsDUrQuTYZMvmjBXqDp2nodlG0huCR6BIB9fJkQ== From: Andrew Tropin To: bug-guix@gnu.org Subject: guile ssh error on guix deploy Date: Tue, 04 Oct 2022 15:09:12 +0400 Message-ID: <87sfk34zhj.fsf@trop.in> MIME-Version: 1.0 Content-Type: multipart/signed; boundary="=-=-="; micalg=pgp-sha512; protocol="application/pgp-signature" Received-SPF: pass client-ip=2001:4b98:dc4:8::222; envelope-from=andrew@trop.in; helo=relay2-d.mail.gandi.net X-Spam_score_int: -27 X-Spam_score: -2.8 X-Spam_bar: -- X-Spam_report: (-2.8 / 5.0 requ) BAYES_00=-1.9, DKIM_SIGNED=0.1, DKIM_VALID=-0.1, DKIM_VALID_AU=-0.1, DKIM_VALID_EF=-0.1, RCVD_IN_DNSWL_LOW=-0.7, SPF_HELO_NONE=0.001, SPF_PASS=-0.001 autolearn=ham autolearn_force=no X-Spam_action: no action X-Spam-Score: -1.6 (-) X-Debbugs-Envelope-To: submit X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -3.3 (---) --=-=-= Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable From=20time to time I get the following error, the only thing I change is IPv6 config in static-networking service. Sometimes it fails, but after a few more attempts with the same config it deploys sucessfully. =2D-8<---------------cut here---------------start------------->8--- =2D*- mode: compilation; default-directory: "~/work/abcdw/trop.in/" -*- Compilation started at Tue Oct 4 14:19:46 make -k deploy-pinky guix deploy ./guix/pinky.scm The following 1 machine will be deployed: pinky guix deploy: deploying to pinky... guix deploy: sending 0 store items (0 MiB) to '23.137.249.202'... guix deploy: sending 0 store items (0 MiB) to '23.137.249.202'... substitute: updating substitutes from 'https://substitutes.nonguix.org'... = 100.0% substitute: updating substitutes from 'https://bordeaux.guix.gnu.org'... 10= 0.0% substitute: updating substitutes from 'http://ci.guix.trop.in'... 100.0% The following derivations will be built: /gnu/store/yzilvx4jr4s7174f6azxxbb5c24311xc-remote-exp.scm.drv /gnu/store/sqlbbg5z19h2ww86p8nzhfbnidsm5sag-switch-to-system.scm.drv /gnu/store/ayssizgz8i4mnk6p2yhilqgzwim4ql7j-system.drv /gnu/store/9fxf3gcgi07hg5nmhjvnvlhk6829h304-provenance.drv /gnu/store/djs7vabv5wr3inz3pva87wfw7ya10ajq-boot.drv /gnu/store/smmzsd1b9v4qmncvl0pl6f0nrasp39ks-activate.scm.drv /gnu/store/5hpm7v0xnqqilhj7qdg66cjkf8dvkimx-activate-service.scm.drv /gnu/store/g62yd6a8wd081w0y4jji83dbcxhiks3i-etc.drv building /gnu/store/9fxf3gcgi07hg5nmhjvnvlhk6829h304-provenance.drv... building /gnu/store/g62yd6a8wd081w0y4jji83dbcxhiks3i-etc.drv... building /gnu/store/5hpm7v0xnqqilhj7qdg66cjkf8dvkimx-activate-service.scm.d= rv... building /gnu/store/smmzsd1b9v4qmncvl0pl6f0nrasp39ks-activate.scm.drv... building /gnu/store/djs7vabv5wr3inz3pva87wfw7ya10ajq-boot.drv... building /gnu/store/ayssizgz8i4mnk6p2yhilqgzwim4ql7j-system.drv... building /gnu/store/sqlbbg5z19h2ww86p8nzhfbnidsm5sag-switch-to-system.scm.d= rv... building /gnu/store/yzilvx4jr4s7174f6azxxbb5c24311xc-remote-exp.scm.drv... guix deploy: sending 10 store items (0 MiB) to '23.137.249.202'... guix deploy: sending 0 store items (0 MiB) to '23.137.249.202'... guix deploy: sending 0 store items (0 MiB) to '23.137.249.202'... The following derivations will be built: /gnu/store/36rmj2xp0sd7lx0ndv8imkyxrh2lmmdy-remote-exp.scm.drv /gnu/store/823hs0g4wxdmfwmj6nn8smcnrp45a1g7-install-bootloader.scm.drv /gnu/store/0m7f6gg0d0iq6r99p40rw3m65z52fjiy-grub.cfg.drv building /gnu/store/0m7f6gg0d0iq6r99p40rw3m65z52fjiy-grub.cfg.drv... building /gnu/store/823hs0g4wxdmfwmj6nn8smcnrp45a1g7-install-bootloader.scm= .drv... building /gnu/store/36rmj2xp0sd7lx0ndv8imkyxrh2lmmdy-remote-exp.scm.drv... ;;; [2022/10/04 14:20:23.191118, 0] [GSSH ERROR] Channel opening failure: c= hannel 67 error (2) open failed: # Backtrace: In guix/store.scm: 1402:13 19 (map/accumulate-builds # =E2=80=A6) 1377:11 18 (map/accumulate-builds # =E2=80=A6) 1295:8 17 (call-with-build-handler # =E2=80=A6) In ice-9/boot-9.scm: 1752:10 16 (with-exception-handler _ _ #:unwind? _ # _) In guix/scripts/deploy.scm: 168:6 15 (_) In guix/store.scm: 2165:25 14 (run-with-store # =E2=80= =A6) In gnu/machine/ssh.scm: 506:32 13 (_ _) In ice-9/boot-9.scm: 1752:10 12 (with-exception-handler _ _ #:unwind? _ # _) In gnu/machine/ssh.scm: 506:32 11 (_) In guix/store.scm: 2165:25 10 (run-with-store # =E2=80= =A6) In guix/remote.scm: 138:10 9 (_ _) In guix/store.scm: 2037:38 8 (_ #) In guix/ssh.scm: 376:2 7 (send-files # _ # =E2=80= =A6) 222:5 6 (remote-run (begin (use-modules (guix) (srfi #) # #) =E2=80=A6= ) #) In ssh/popen.scm: 64:4 5 (open-remote-pipe* _ "r+" _ . _) In unknown file: 4 (channel-open-session #) 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 67 error (2) open failed" # #f)'. make: *** [Makefile:28: deploy-pinky] Error 1 Compilation exited abnormally with code 2 at Tue Oct 4 14:20:23 =2D-8<---------------cut here---------------end--------------->8--- =2D-=20 Best regards, Andrew Tropin --=-=-= Content-Type: application/pgp-signature; name="signature.asc" -----BEGIN PGP SIGNATURE----- iQIzBAEBCgAdFiEEKEGaxlA4dEDH6S/6IgjSCVjB3rAFAmM8FFkACgkQIgjSCVjB 3rCMmg/7BujBW2WmTY5VAIk1cCDgo4K17H7E5P3fqGmMKNMTUXsZys1fjcXKnAEt 4Hh/Uyize0bpXXwRIRHHGdeLVXyp5KpF7AhKXYZOS9CawFVwhL8/9MdDIX+FM+FE mOKVgO5Y3qN4Onn7jHWzetayz8A8uKQjcZCWzhXPcXy/eBCoeQFof8TNZP5tbxpp 7VV+zD68WRx2Lg6OlvhpeZHf5q9msoMTJKj7pFIAOs0SrDn55/t1kSYcnYhPjUBx Oo8RoG+UsCGC6beJGgfLY4bMe9cl6fV1VafoZgVDSdzDu4DDsAuRMINyUwCQl+7m HV6HUYCyLu1MyM+fGlbdGY4f7tR9rvNWDzWNZeu6Yw02JjsfmR401BQpQ8uFzup2 dSLPMrTycEGALAfyywupW8+H6iDT2rYfNJ7ZGwkHWBN6MtBhUtLyU2fdbFX0YYqt Q16CEWGcm+zIfO36tB/4/Bvma2mfEfZYswpyC5ylXOfPNX181k9r152VEhRfAFaJ BVXisk9G82F8VheUduUEFJSOGbegulMBtEYFYrXCqLGEZKSL1Qq42pkGZjZsFaL2 /ZsgMiROY+SVnT2qAEldBxxrD32yvqudPcKYFhyKUTpMaCaHRt7eRpnHNfsHZWdv HRLUNA7vP/Vyqunuvo/WQQ63TUjjidYDP8WCxoLpe4A53HC76Pw= =2ZlB -----END PGP SIGNATURE----- --=-=-=-- From debbugs-submit-bounces@debbugs.gnu.org Sat Oct 08 08:40:02 2022 Received: (at 58290) by debbugs.gnu.org; 8 Oct 2022 12:40:02 +0000 Received: from localhost ([127.0.0.1]:38541 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1oh97Z-0001Ci-Vw for submit@debbugs.gnu.org; Sat, 08 Oct 2022 08:40:02 -0400 Received: from eggs.gnu.org ([209.51.188.92]:54356) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1oh97X-0001CF-D8 for 58290@debbugs.gnu.org; Sat, 08 Oct 2022 08:40:00 -0400 Received: from fencepost.gnu.org ([2001:470:142:3::e]:47898) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1oh97S-0006Od-0B; Sat, 08 Oct 2022 08:39:54 -0400 DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=gnu.org; s=fencepost-gnu-org; h=MIME-Version:In-Reply-To:Date:References:Subject:To: From; bh=vv2bQA/O6tZ66KKR/HjHKZyWSj7DgpAuDYwrVo6AH14=; b=lbKhTikCXndzwn2M4P+w fE4zA2JC9UXv0uyd6/tCZAmMfQaR8aHw0e1vlaLLCUBYc593yQ1asRQx9flqzMHT39fLeyCLDqggJ PMUkDtyxwexS42SUfMnFMvoD4z2eMK4kzSB26++E86cNWw4RQGvyR777qX7LMum+qiJVHkbCitEju 0n86daHv5OpOkK3ZkujVMlsN61QcU/P+xN9d/R2SUnLrxH/iYvrlTCpjjlJME5UiH3SqNXzw5MSXB tJS5YJMDypsLcseeL5K3ZjajEcac2Cb3SeeNHklfm69WXw/9mlMpLCGg/uiS6BQEVEW7Tijcg5pxQ LvG0M6jHfC9bKA==; Received: from 91-160-117-201.subs.proxad.net ([91.160.117.201]:64968 helo=ribbon) by fencepost.gnu.org with esmtpsa (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1oh97R-0003gF-In; Sat, 08 Oct 2022 08:39:53 -0400 From: =?utf-8?Q?Ludovic_Court=C3=A8s?= To: Andrew Tropin Subject: Re: bug#58290: guile ssh error on guix deploy References: <87sfk34zhj.fsf@trop.in> Date: Sat, 08 Oct 2022 14:39:52 +0200 In-Reply-To: <87sfk34zhj.fsf@trop.in> (Andrew Tropin's message of "Tue, 04 Oct 2022 15:09:12 +0400") Message-ID: <87bkqm8p5z.fsf@gnu.org> User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/28.1 (gnu/linux) MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-Spam-Score: -2.3 (--) X-Debbugs-Envelope-To: 58290 Cc: 58290@debbugs.gnu.org X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -3.3 (---) Hi! Andrew Tropin skribis: > From time to time I get the following error, the only thing I change is > IPv6 config in static-networking service. Sometimes it fails, but after > a few more attempts with the same config it deploys sucessfully. > > -*- mode: compilation; default-directory: "~/work/abcdw/trop.in/" -*- > Compilation started at Tue Oct 4 14:19:46 > > make -k deploy-pinky > guix deploy ./guix/pinky.scm [...] > In guix/ssh.scm: > 376:2 7 (send-files # _ # =E2= =80=A6) > 222:5 6 (remote-run (begin (use-modules (guix) (srfi #) # #) =E2=80= =A6) #) > In ssh/popen.scm: > 64:4 5 (open-remote-pipe* _ "r+" _ . _) > In unknown file: > 4 (channel-open-session #) > 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" "Channe= l opening failure: channel 67 error (2) open failed" # #f)'. Are there any hints from sshd in the /var/log/messages of that machine as to why the connection was closed? Thanks, Ludo=E2=80=99. From debbugs-submit-bounces@debbugs.gnu.org Fri Oct 14 02:45:30 2022 Received: (at 58290) by debbugs.gnu.org; 14 Oct 2022 06:45:30 +0000 Received: from localhost ([127.0.0.1]:35604 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1ojERk-00060q-Gr for submit@debbugs.gnu.org; Fri, 14 Oct 2022 02:45:30 -0400 Received: from relay2-d.mail.gandi.net ([217.70.183.194]:48493) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1ojERf-00060M-Bc for 58290@debbugs.gnu.org; Fri, 14 Oct 2022 02:45:26 -0400 Received: (Authenticated sender: andrew@trop.in) by mail.gandi.net (Postfix) with ESMTPSA id B9FFB40011; Fri, 14 Oct 2022 06:45:16 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=trop.in; s=gm1; t=1665729917; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:cc:mime-version:mime-version:content-type:content-type: in-reply-to:in-reply-to:references:references; bh=kvmTD6INaZ6g7fb8fWFPlzWUGelW1GpVwDVPVL2plIU=; b=hm7HuLNAScbFap4ObHee/BIGUAvZe9zzcvg4p1qKTwAlqFqyI0Bozp9UqJzLMgktRbCLfu w6spopgQ+0u28SkKo0kYbIZyu9FQxYGLbqr5z48T+zMLU7UzjUetMuUYmTNha4T7uV+j8t AWfSyt8byWLDVowlAEze5pnb23+x4jIWjrNZ7ZiAxtT0ypBhG+/p5r5CAK9Om37iNL5thx J6MGeud3FB+b1nZFJhurKHsaBUSd/qJceT28OIQrYwmaRFQ9kVrN83EIzLmJL2ey31uhBg /St9uefyHIy5mZ7odqcjowgxcFaMxKK1SWDbJOx1uf1LyUQ8FIG7sBJJ5kZajg== From: Andrew Tropin To: Ludovic =?utf-8?Q?Court=C3=A8s?= Subject: Re: bug#58290: guile ssh error on guix deploy In-Reply-To: <87bkqm8p5z.fsf@gnu.org> References: <87sfk34zhj.fsf@trop.in> <87bkqm8p5z.fsf@gnu.org> Date: Fri, 14 Oct 2022 10:45:12 +0400 Message-ID: <87o7uec39j.fsf@trop.in> MIME-Version: 1.0 Content-Type: multipart/signed; boundary="=-=-="; micalg=pgp-sha512; protocol="application/pgp-signature" X-Spam-Score: -0.7 (/) X-Debbugs-Envelope-To: 58290 Cc: 58290@debbugs.gnu.org X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -1.7 (-) --=-=-= Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable On 2022-10-08 14:39, Ludovic Court=C3=A8s wrote: > Hi! > > Andrew Tropin skribis: > >> From time to time I get the following error, the only thing I change is >> IPv6 config in static-networking service. Sometimes it fails, but after >> a few more attempts with the same config it deploys sucessfully. >> >> -*- mode: compilation; default-directory: "~/work/abcdw/trop.in/" -*- >> Compilation started at Tue Oct 4 14:19:46 >> >> make -k deploy-pinky >> guix deploy ./guix/pinky.scm > > [...] > >> In guix/ssh.scm: >> 376:2 7 (send-files # _ # =E2= =80=A6) >> 222:5 6 (remote-run (begin (use-modules (guix) (srfi #) # #) =E2=80= =A6) #) >> In ssh/popen.scm: >> 64:4 5 (open-remote-pipe* _ "r+" _ . _) >> In unknown file: >> 4 (channel-open-session #) >> 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" "Chann= el opening failure: channel 67 error (2) open failed" # #f)'. > > Are there any hints from sshd in the /var/log/messages of that machine > as to why the connection was closed? =2D-8<---------------cut here---------------start------------->8--- bob@pinky /var/log$ zcat messages.1.gz | grep "Oct 4" | grep ssh Oct 4 05:57:09 localhost shepherd[1]: Service sshd-380 has been started.=20 Oct 4 05:57:11 localhost sshd[15950]: Accepted publickey for bob from 201:= 2a73:cac3:e128:cf3d:8dc:8afa:df66 port 54710 ssh2: RSA SHA256:/X3jyhyMizAOK= OjCfXK5cLN3Pa0vmi7dbQG+fxK3d3Y Oct 4 06:34:17 localhost shepherd[1]: Service sshd-381 has been started.=20 Oct 4 06:34:19 localhost sshd[15958]: Accepted publickey for bob from 201:= 2a73:cac3:e128:cf3d:8dc:8afa:df66 port 57064 ssh2: RSA SHA256:/X3jyhyMizAOK= OjCfXK5cLN3Pa0vmi7dbQG+fxK3d3Y Oct 4 06:36:55 localhost shepherd[1]: Service sshd-382 has been started.=20 Oct 4 06:36:57 localhost sshd[15991]: Accepted publickey for bob from 201:= 2a73:cac3:e128:cf3d:8dc:8afa:df66 port 41088 ssh2: RSA SHA256:/X3jyhyMizAOK= OjCfXK5cLN3Pa0vmi7dbQG+fxK3d3Y Oct 4 06:37:30 localhost shepherd[1]: Service sshd-383 has been started.=20 Oct 4 06:37:33 localhost sshd[16031]: Accepted publickey for bob from 201:= 2a73:cac3:e128:cf3d:8dc:8afa:df66 port 56148 ssh2: RSA SHA256:/X3jyhyMizAOK= OjCfXK5cLN3Pa0vmi7dbQG+fxK3d3Y Oct 4 06:43:39 localhost shepherd[1]: 3 connections still in use after ssh= d-382 termination.=20 Oct 4 06:43:39 localhost shepherd[1]: Service sshd-382 (PID 15991) exited = with 255.=20 Oct 4 06:43:39 localhost shepherd[1]: Service sshd-382 has been disabled.= =20 Oct 4 06:43:39 localhost shepherd[1]: Transient service sshd-382 terminate= d, now unregistered.=20 Oct 4 06:43:41 localhost shepherd[1]: Service sshd-384 has been started.=20 Oct 4 06:43:42 localhost sshd[16166]: Accepted publickey for bob from 201:= 2a73:cac3:e128:cf3d:8dc:8afa:df66 port 36040 ssh2: RSA SHA256:/X3jyhyMizAOK= OjCfXK5cLN3Pa0vmi7dbQG+fxK3d3Y Oct 4 06:43:49 localhost shepherd[1]: 3 connections still in use after ssh= d-384 termination.=20 Oct 4 06:43:49 localhost shepherd[1]: Service sshd-384 has been disabled.= =20 Oct 4 06:43:49 localhost shepherd[1]: Transient service sshd-384 terminate= d, now unregistered.=20 Oct 4 06:48:58 localhost shepherd[1]: Service sshd-385 has been started.=20 Oct 4 06:49:00 localhost sshd[16205]: Accepted publickey for bob from 201:= 2a73:cac3:e128:cf3d:8dc:8afa:df66 port 34134 ssh2: RSA SHA256:/X3jyhyMizAOK= OjCfXK5cLN3Pa0vmi7dbQG+fxK3d3Y Oct 4 06:52:05 localhost shepherd[1]: Service sshd-386 has been started.=20 Oct 4 06:52:06 localhost sshd[16212]: Accepted publickey for bob from 201:= 2a73:cac3:e128:cf3d:8dc:8afa:df66 port 55922 ssh2: RSA SHA256:/X3jyhyMizAOK= OjCfXK5cLN3Pa0vmi7dbQG+fxK3d3Y Oct 4 06:53:02 localhost shepherd[1]: 4 connections still in use after ssh= d-386 termination.=20 Oct 4 06:53:02 localhost shepherd[1]: Service sshd-386 has been disabled.= =20 Oct 4 06:53:02 localhost shepherd[1]: Transient service sshd-386 terminate= d, now unregistered.=20 Oct 4 06:53:03 localhost shepherd[1]: Service sshd-387 has been started.=20 Oct 4 06:53:04 localhost sshd[16370]: Accepted publickey for bob from 201:= 2a73:cac3:e128:cf3d:8dc:8afa:df66 port 50604 ssh2: RSA SHA256:/X3jyhyMizAOK= OjCfXK5cLN3Pa0vmi7dbQG+fxK3d3Y Oct 4 06:53:11 localhost shepherd[1]: 4 connections still in use after ssh= d-387 termination.=20 Oct 4 06:53:11 localhost shepherd[1]: Service sshd-387 has been disabled.= =20 Oct 4 06:53:11 localhost shepherd[1]: Transient service sshd-387 terminate= d, now unregistered.=20 Oct 4 06:54:25 localhost shepherd[1]: Service ssh-daemon has been stopped.= =20 Oct 4 06:57:42 localhost shepherd[1]: Service ssh-daemon has been started.= =20 Oct 4 06:58:20 localhost shepherd[1]: Service sshd-1 has been started.=20 Oct 4 06:58:22 localhost sshd[239]: Accepted publickey for bob from 185.11= 5.7.223 port 10436 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:01:22 localhost shepherd[1]: Service sshd-2 has been started.=20 Oct 4 07:01:24 localhost sshd[247]: Accepted publickey for bob from 185.11= 5.7.223 port 29449 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:02:29 localhost shepherd[1]: Service sshd-3 has been started.=20 Oct 4 07:02:31 localhost sshd[254]: Accepted publickey for bob from 185.11= 5.7.223 port 29456 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:03:05 localhost sshd[256]: error: no more sessions Oct 4 07:03:05 localhost shepherd[1]: 2 connections still in use after ssh= d-3 termination.=20 Oct 4 07:03:05 localhost shepherd[1]: Service sshd-3 has been disabled.=20 Oct 4 07:03:05 localhost shepherd[1]: Transient service sshd-3 terminated,= now unregistered.=20 Oct 4 07:04:21 localhost shepherd[1]: Service sshd-4 has been started.=20 Oct 4 07:04:22 localhost sshd[385]: Accepted publickey for bob from 185.11= 5.7.223 port 10409 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:04:36 localhost shepherd[1]: Service sshd-5 has been started.=20 Oct 4 07:04:38 localhost sshd[435]: Accepted publickey for bob from 185.11= 5.7.223 port 10426 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:04:50 localhost sshd[387]: error: no more sessions Oct 4 07:04:50 localhost shepherd[1]: 3 connections still in use after ssh= d-4 termination.=20 Oct 4 07:04:50 localhost shepherd[1]: Service sshd-4 has been disabled.=20 Oct 4 07:04:50 localhost shepherd[1]: Transient service sshd-4 terminated,= now unregistered.=20 Oct 4 07:05:10 localhost shepherd[1]: Service sshd-6 has been started.=20 Oct 4 07:05:12 localhost sshd[508]: Accepted publickey for bob from 185.11= 5.7.223 port 29519 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:05:57 localhost shepherd[1]: 3 connections still in use after ssh= d-6 termination.=20 Oct 4 07:05:57 localhost shepherd[1]: Service sshd-6 has been disabled.=20 Oct 4 07:05:57 localhost shepherd[1]: Transient service sshd-6 terminated,= now unregistered.=20 Oct 4 07:05:57 localhost shepherd[1]: Service sshd-7 has been started.=20 Oct 4 07:05:59 localhost sshd[666]: Accepted publickey for bob from 185.11= 5.7.223 port 29495 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:06:03 localhost shepherd[1]: 3 connections still in use after ssh= d-7 termination.=20 Oct 4 07:06:03 localhost shepherd[1]: Service sshd-7 has been disabled.=20 Oct 4 07:06:03 localhost shepherd[1]: Transient service sshd-7 terminated,= now unregistered.=20 Oct 4 07:07:13 localhost shepherd[1]: Service sshd-8 has been started.=20 Oct 4 07:07:14 localhost sshd[699]: Accepted publickey for bob from 185.11= 5.7.223 port 29463 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:07:51 localhost shepherd[1]: 3 connections still in use after ssh= d-8 termination.=20 Oct 4 07:07:51 localhost shepherd[1]: Service sshd-8 has been disabled.=20 Oct 4 07:07:51 localhost shepherd[1]: Transient service sshd-8 terminated,= now unregistered.=20 Oct 4 07:07:52 localhost shepherd[1]: Service sshd-9 has been started.=20 Oct 4 07:07:54 localhost sshd[857]: Accepted publickey for bob from 185.11= 5.7.223 port 10407 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:07:58 localhost shepherd[1]: 3 connections still in use after ssh= d-9 termination.=20 Oct 4 07:07:58 localhost shepherd[1]: Service sshd-9 (PID 857) exited with= 255.=20 Oct 4 07:07:58 localhost shepherd[1]: Service sshd-9 has been disabled.=20 Oct 4 07:07:58 localhost shepherd[1]: Transient service sshd-9 terminated,= now unregistered.=20 Oct 4 07:08:22 localhost shepherd[1]: Service sshd-10 has been started.=20 Oct 4 07:08:24 localhost sshd[889]: Accepted publickey for bob from 185.11= 5.7.223 port 10478 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:08:55 localhost sshd[891]: error: no more sessions Oct 4 07:08:55 localhost shepherd[1]: 3 connections still in use after ssh= d-10 termination.=20 Oct 4 07:08:55 localhost shepherd[1]: Service sshd-10 has been disabled.=20 Oct 4 07:08:55 localhost shepherd[1]: Transient service sshd-10 terminated= , now unregistered.=20 Oct 4 07:09:24 localhost shepherd[1]: Service sshd-11 has been started.=20 Oct 4 07:09:25 localhost sshd[1010]: Accepted publickey for bob from 185.1= 15.7.223 port 10489 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fx= K3d3Y Oct 4 07:10:01 localhost shepherd[1]: 3 connections still in use after ssh= d-11 termination.=20 Oct 4 07:10:01 localhost shepherd[1]: Service sshd-11 (PID 1010) exited wi= th 255.=20 Oct 4 07:10:01 localhost shepherd[1]: Service sshd-11 has been disabled.=20 Oct 4 07:10:01 localhost shepherd[1]: Transient service sshd-11 terminated= , now unregistered.=20 Oct 4 07:10:01 localhost shepherd[1]: Service sshd-12 has been started.=20 Oct 4 07:10:03 localhost sshd[1164]: Accepted publickey for bob from 185.1= 15.7.223 port 29458 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fx= K3d3Y Oct 4 07:10:08 localhost shepherd[1]: 3 connections still in use after ssh= d-12 termination.=20 Oct 4 07:10:08 localhost shepherd[1]: Service sshd-12 (PID 1164) exited wi= th 255.=20 Oct 4 07:10:08 localhost shepherd[1]: Service sshd-12 has been disabled.=20 Oct 4 07:10:08 localhost shepherd[1]: Transient service sshd-12 terminated= , now unregistered.=20 Oct 4 07:11:09 localhost shepherd[1]: Service sshd-1 has been stopped.=20 Oct 4 07:11:09 localhost shepherd[1]: Transient service sshd-1 unregistere= d.=20 Oct 4 07:11:09 localhost shepherd[1]: Service ssh-daemon has been stopped.= =20 Oct 4 07:11:59 localhost shepherd[1]: Service ssh-daemon has been started.= =20 Oct 4 07:12:02 localhost shepherd[1]: Service sshd-1 has been started.=20 Oct 4 07:12:04 localhost sshd[241]: Accepted publickey for bob from 185.11= 5.7.223 port 10202 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:15:09 localhost shepherd[1]: Service sshd-2 has been started.=20 Oct 4 07:15:11 localhost sshd[269]: Accepted publickey for bob from 185.11= 5.7.223 port 29443 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:16:08 localhost sshd[271]: error: no more sessions Oct 4 07:16:08 localhost shepherd[1]: 1 connection still in use after sshd= -2 termination.=20 Oct 4 07:16:08 localhost shepherd[1]: Service sshd-2 has been disabled.=20 Oct 4 07:16:08 localhost shepherd[1]: Transient service sshd-2 terminated,= now unregistered.=20 Oct 4 07:16:31 localhost shepherd[1]: Service sshd-3 has been started.=20 Oct 4 07:16:33 localhost sshd[404]: Accepted publickey for bob from 185.11= 5.7.223 port 10413 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:17:13 localhost shepherd[1]: 1 connection still in use after sshd= -3 termination.=20 Oct 4 07:17:13 localhost shepherd[1]: Service sshd-3 (PID 404) exited with= 255.=20 Oct 4 07:17:13 localhost shepherd[1]: Service sshd-3 has been disabled.=20 Oct 4 07:17:13 localhost shepherd[1]: Transient service sshd-3 terminated,= now unregistered.=20 Oct 4 07:17:14 localhost shepherd[1]: Service sshd-4 has been started.=20 Oct 4 07:17:15 localhost sshd[556]: Accepted publickey for bob from 185.11= 5.7.223 port 10454 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:17:19 localhost shepherd[1]: 1 connection still in use after sshd= -4 termination.=20 Oct 4 07:17:19 localhost shepherd[1]: Service sshd-4 has been disabled.=20 Oct 4 07:17:19 localhost shepherd[1]: Transient service sshd-4 terminated,= now unregistered.=20 Oct 4 07:27:39 localhost shepherd[1]: Service sshd-5 has been started.=20 Oct 4 07:27:41 localhost sshd[602]: Accepted publickey for bob from 185.11= 5.7.223 port 29522 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:28:13 localhost sshd[604]: error: no more sessions Oct 4 07:28:13 localhost shepherd[1]: 1 connection still in use after sshd= -5 termination.=20 Oct 4 07:28:13 localhost shepherd[1]: Service sshd-5 has been disabled.=20 Oct 4 07:28:13 localhost shepherd[1]: Transient service sshd-5 terminated,= now unregistered.=20 Oct 4 07:28:20 localhost shepherd[1]: Service sshd-6 has been started.=20 Oct 4 07:28:21 localhost sshd[723]: Accepted publickey for bob from 185.11= 5.7.223 port 29474 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:28:50 localhost sshd[725]: error: no more sessions Oct 4 07:28:50 localhost shepherd[1]: 1 connection still in use after sshd= -6 termination.=20 Oct 4 07:28:50 localhost shepherd[1]: Service sshd-6 has been disabled.=20 Oct 4 07:28:50 localhost shepherd[1]: Transient service sshd-6 terminated,= now unregistered.=20 Oct 4 07:30:39 localhost shepherd[1]: Service sshd-7 has been started.=20 Oct 4 07:30:40 localhost sshd[840]: Accepted publickey for bob from 185.11= 5.7.223 port 10445 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:31:44 localhost shepherd[1]: Service sshd-8 has been started.=20 Oct 4 07:31:46 localhost sshd[857]: Accepted publickey for bob from 185.11= 5.7.223 port 10393 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:32:13 localhost sshd[859]: error: no more sessions Oct 4 07:32:13 localhost shepherd[1]: 2 connections still in use after ssh= d-8 termination.=20 Oct 4 07:32:13 localhost shepherd[1]: Service sshd-8 has been disabled.=20 Oct 4 07:32:13 localhost shepherd[1]: Transient service sshd-8 terminated,= now unregistered.=20 Oct 4 07:33:07 localhost shepherd[1]: Service ssh-daemon has been stopped.= =20 Oct 4 07:34:15 localhost shepherd[1]: Service ssh-daemon has been started.= =20 Oct 4 07:34:26 localhost shepherd[1]: Service sshd-1 has been started.=20 Oct 4 07:34:28 localhost sshd[239]: Accepted publickey for bob from 185.11= 5.7.223 port 29462 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:35:14 localhost shepherd[1]: Service sshd-2 has been started.=20 Oct 4 07:35:16 localhost sshd[258]: Accepted publickey for bob from 185.11= 5.7.223 port 29504 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:35:52 localhost shepherd[1]: 1 connection still in use after sshd= -2 termination.=20 Oct 4 07:35:52 localhost shepherd[1]: Service sshd-2 has been disabled.=20 Oct 4 07:35:52 localhost shepherd[1]: Transient service sshd-2 terminated,= now unregistered.=20 Oct 4 07:36:13 localhost shepherd[1]: Service sshd-3 has been started.=20 Oct 4 07:36:14 localhost sshd[418]: Accepted publickey for bob from 185.11= 5.7.223 port 29463 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:36:52 localhost shepherd[1]: 1 connection still in use after sshd= -3 termination.=20 Oct 4 07:36:52 localhost shepherd[1]: Service sshd-3 (PID 418) exited with= 255.=20 Oct 4 07:36:52 localhost shepherd[1]: Service sshd-3 has been disabled.=20 Oct 4 07:36:52 localhost shepherd[1]: Transient service sshd-3 terminated,= now unregistered.=20 Oct 4 07:38:51 localhost shepherd[1]: Service ssh-daemon has been started.= =20 Oct 4 07:38:58 localhost shepherd[1]: Service sshd-1 has been started.=20 Oct 4 07:39:00 localhost sshd[257]: Accepted publickey for bob from 185.11= 5.7.223 port 29563 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:40:14 localhost sshd[259]: Received disconnect from 185.115.7.223= port 29563:11: disconnected by user Oct 4 07:40:14 localhost sshd[259]: Disconnected from user bob 185.115.7.2= 23 port 29563 Oct 4 07:40:14 localhost shepherd[1]: 0 connections still in use after ssh= d-1 termination.=20 Oct 4 07:40:14 localhost shepherd[1]: Service sshd-1 (PID 257) exited with= 255.=20 Oct 4 07:40:14 localhost shepherd[1]: Service sshd-1 has been disabled.=20 Oct 4 07:40:14 localhost shepherd[1]: Transient service sshd-1 terminated,= now unregistered.=20 Oct 4 07:40:31 localhost shepherd[1]: Service sshd-2 has been started.=20 Oct 4 07:40:33 localhost sshd[267]: Accepted publickey for bob from 185.11= 5.7.223 port 10488 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:40:43 localhost sshd[269]: Received disconnect from 185.115.7.223= port 10488:11: disconnected by user Oct 4 07:40:43 localhost sshd[269]: Disconnected from user bob 185.115.7.2= 23 port 10488 Oct 4 07:40:43 localhost shepherd[1]: 0 connections still in use after ssh= d-2 termination.=20 Oct 4 07:40:43 localhost shepherd[1]: Service sshd-2 (PID 267) exited with= 255.=20 Oct 4 07:40:43 localhost shepherd[1]: Service sshd-2 has been disabled.=20 Oct 4 07:40:43 localhost shepherd[1]: Transient service sshd-2 terminated,= now unregistered.=20 Oct 4 07:41:03 localhost shepherd[1]: Service sshd-3 has been started.=20 Oct 4 07:41:05 localhost sshd[271]: Accepted publickey for bob from 185.11= 5.7.223 port 10368 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:41:10 localhost sshd[273]: Received disconnect from 185.115.7.223= port 10368:11: disconnected by user Oct 4 07:41:10 localhost sshd[273]: Disconnected from user bob 185.115.7.2= 23 port 10368 Oct 4 07:41:10 localhost shepherd[1]: 0 connections still in use after ssh= d-3 termination.=20 Oct 4 07:41:10 localhost shepherd[1]: Service sshd-3 (PID 271) exited with= 255.=20 Oct 4 07:41:10 localhost shepherd[1]: Service sshd-3 has been disabled.=20 Oct 4 07:41:10 localhost shepherd[1]: Transient service sshd-3 terminated,= now unregistered.=20 Oct 4 07:41:13 localhost shepherd[1]: Service sshd-4 has been started.=20 Oct 4 07:41:16 localhost sshd[275]: Accepted publickey for bob from 201:2a= 73:cac3:e128:cf3d:8dc:8afa:df66 port 47302 ssh2: RSA SHA256:/X3jyhyMizAOKOj= CfXK5cLN3Pa0vmi7dbQG+fxK3d3Y Oct 4 07:41:19 localhost sshd[277]: Received disconnect from 201:2a73:cac3= :e128:cf3d:8dc:8afa:df66 port 47302:11: disconnected by user Oct 4 07:41:19 localhost sshd[277]: Disconnected from user bob 201:2a73:ca= c3:e128:cf3d:8dc:8afa:df66 port 47302 Oct 4 07:41:19 localhost shepherd[1]: 0 connections still in use after ssh= d-4 termination.=20 Oct 4 07:41:19 localhost shepherd[1]: Service sshd-4 (PID 275) exited with= 255.=20 Oct 4 07:41:19 localhost shepherd[1]: Service sshd-4 has been disabled.=20 Oct 4 07:41:19 localhost shepherd[1]: Transient service sshd-4 terminated,= now unregistered.=20 Oct 4 07:41:24 localhost shepherd[1]: Service sshd-5 has been started.=20 Oct 4 07:41:26 localhost sshd[280]: Accepted publickey for bob from 201:2a= 73:cac3:e128:cf3d:8dc:8afa:df66 port 33450 ssh2: RSA SHA256:/X3jyhyMizAOKOj= CfXK5cLN3Pa0vmi7dbQG+fxK3d3Y Oct 4 07:42:39 localhost shepherd[1]: 0 connections still in use after ssh= d-5 termination.=20 Oct 4 07:42:39 localhost shepherd[1]: Service sshd-5 has been disabled.=20 Oct 4 07:42:39 localhost shepherd[1]: Transient service sshd-5 terminated,= now unregistered.=20 Oct 4 07:43:20 localhost shepherd[1]: Service sshd-6 has been started.=20 Oct 4 07:43:22 localhost sshd[436]: Accepted publickey for bob from 201:2a= 73:cac3:e128:cf3d:8dc:8afa:df66 port 60366 ssh2: RSA SHA256:/X3jyhyMizAOKOj= CfXK5cLN3Pa0vmi7dbQG+fxK3d3Y Oct 4 07:44:08 localhost shepherd[1]: 0 connections still in use after ssh= d-6 termination.=20 Oct 4 07:44:08 localhost shepherd[1]: Service sshd-6 (PID 436) exited with= 255.=20 Oct 4 07:44:08 localhost shepherd[1]: Service sshd-6 has been disabled.=20 Oct 4 07:44:08 localhost shepherd[1]: Transient service sshd-6 terminated,= now unregistered.=20 Oct 4 07:44:23 localhost shepherd[1]: Service sshd-7 has been started.=20 Oct 4 07:44:25 localhost sshd[592]: Accepted publickey for bob from 201:2a= 73:cac3:e128:cf3d:8dc:8afa:df66 port 34526 ssh2: RSA SHA256:/X3jyhyMizAOKOj= CfXK5cLN3Pa0vmi7dbQG+fxK3d3Y Oct 4 07:44:56 localhost shepherd[1]: Service sshd-8 has been started.=20 Oct 4 07:44:57 localhost sshd[598]: Accepted publickey for bob from 201:2a= 73:cac3:e128:cf3d:8dc:8afa:df66 port 59492 ssh2: RSA SHA256:/X3jyhyMizAOKOj= CfXK5cLN3Pa0vmi7dbQG+fxK3d3Y Oct 4 07:45:42 localhost shepherd[1]: 1 connection still in use after sshd= -8 termination.=20 Oct 4 07:45:42 localhost shepherd[1]: Service sshd-8 (PID 598) exited with= 255.=20 Oct 4 07:45:42 localhost shepherd[1]: Service sshd-8 has been disabled.=20 Oct 4 07:45:42 localhost shepherd[1]: Transient service sshd-8 terminated,= now unregistered.=20 Oct 4 07:45:49 localhost shepherd[1]: Service sshd-9 has been started.=20 Oct 4 07:45:51 localhost sshd[754]: Accepted publickey for bob from 201:2a= 73:cac3:e128:cf3d:8dc:8afa:df66 port 56454 ssh2: RSA SHA256:/X3jyhyMizAOKOj= CfXK5cLN3Pa0vmi7dbQG+fxK3d3Y Oct 4 07:46:35 localhost shepherd[1]: 1 connection still in use after sshd= -9 termination.=20 Oct 4 07:46:35 localhost shepherd[1]: Service sshd-9 has been disabled.=20 Oct 4 07:46:35 localhost shepherd[1]: Transient service sshd-9 terminated,= now unregistered.=20 Oct 4 07:46:52 localhost shepherd[1]: Service ssh-daemon has been stopped.= =20 Oct 4 07:47:33 localhost shepherd[1]: Service ssh-daemon has been started.= =20 Oct 4 07:48:24 localhost shepherd[1]: Service sshd-1 has been started.=20 Oct 4 07:48:26 localhost sshd[239]: Accepted publickey for bob from 185.11= 5.7.223 port 29446 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:49:13 localhost shepherd[1]: Service sshd-2 has been started.=20 Oct 4 07:49:15 localhost sshd[253]: Accepted publickey for bob from 185.11= 5.7.223 port 29550 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:49:54 localhost shepherd[1]: 1 connection still in use after sshd= -2 termination.=20 Oct 4 07:49:54 localhost shepherd[1]: Service sshd-2 (PID 253) exited with= 255.=20 Oct 4 07:49:54 localhost shepherd[1]: Service sshd-2 has been disabled.=20 Oct 4 07:49:54 localhost shepherd[1]: Transient service sshd-2 terminated,= now unregistered.=20 Oct 4 07:50:56 localhost shepherd[1]: Service sshd-3 has been started.=20 Oct 4 07:50:58 localhost sshd[405]: Accepted publickey for bob from 185.11= 5.7.223 port 10382 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:51:01 localhost shepherd[1]: Service sshd-1 has been stopped.=20 Oct 4 07:51:01 localhost shepherd[1]: Transient service sshd-1 unregistere= d.=20 Oct 4 07:52:54 localhost shepherd[1]: Service ssh-daemon has been started.= =20 Oct 4 07:52:56 localhost shepherd[1]: Service sshd-1 has been started.=20 Oct 4 07:52:57 localhost sshd[238]: Accepted publickey for bob from 185.11= 5.7.223 port 10479 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:53:22 localhost shepherd[1]: Service sshd-2 has been started.=20 Oct 4 07:53:24 localhost sshd[246]: Accepted publickey for bob from 185.11= 5.7.223 port 10482 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:53:59 localhost sshd[248]: error: no more sessions Oct 4 07:53:59 localhost shepherd[1]: 1 connection still in use after sshd= -2 termination.=20 Oct 4 07:53:59 localhost shepherd[1]: Service sshd-2 has been disabled.=20 Oct 4 07:53:59 localhost shepherd[1]: Transient service sshd-2 terminated,= now unregistered.=20 Oct 4 07:56:18 localhost shepherd[1]: Service sshd-3 has been started.=20 Oct 4 07:56:20 localhost sshd[368]: Accepted publickey for bob from 185.11= 5.7.223 port 25376 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:56:24 localhost shepherd[1]: Service ssh-daemon has been stopped.= =20 Oct 4 07:57:09 localhost shepherd[1]: Service ssh-daemon has been started.= =20 Oct 4 07:57:11 localhost shepherd[1]: Service sshd-1 has been started.=20 Oct 4 07:57:12 localhost sshd[237]: Accepted publickey for bob from 185.11= 5.7.223 port 25371 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:57:22 localhost shepherd[1]: Service sshd-2 has been started.=20 Oct 4 07:57:23 localhost sshd[245]: Accepted publickey for bob from 185.11= 5.7.223 port 29507 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:57:56 localhost sshd[247]: error: no more sessions Oct 4 07:57:56 localhost shepherd[1]: 1 connection still in use after sshd= -2 termination.=20 Oct 4 07:57:56 localhost shepherd[1]: Service sshd-2 (PID 245) exited with= 255.=20 Oct 4 07:57:56 localhost shepherd[1]: Service sshd-2 has been disabled.=20 Oct 4 07:57:56 localhost shepherd[1]: Transient service sshd-2 terminated,= now unregistered.=20 Oct 4 07:58:19 localhost shepherd[1]: Service sshd-3 has been started.=20 Oct 4 07:58:20 localhost sshd[368]: Accepted publickey for bob from 185.11= 5.7.223 port 29460 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 07:58:49 localhost sshd[370]: error: no more sessions Oct 4 07:58:49 localhost shepherd[1]: 1 connection still in use after sshd= -3 termination.=20 Oct 4 07:58:49 localhost shepherd[1]: Service sshd-3 has been disabled.=20 Oct 4 07:58:49 localhost shepherd[1]: Transient service sshd-3 terminated,= now unregistered.=20 Oct 4 08:00:15 localhost shepherd[1]: Service sshd-4 has been started.=20 Oct 4 08:00:17 localhost sshd[485]: Accepted publickey for bob from 185.11= 5.7.223 port 10372 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 08:00:26 localhost sshd[239]: Received disconnect from 185.115.7.223= port 25371:11: disconnected by user Oct 4 08:00:26 localhost sshd[239]: Disconnected from user bob 185.115.7.2= 23 port 25371 Oct 4 08:00:26 localhost shepherd[1]: 1 connection still in use after sshd= -1 termination.=20 Oct 4 08:00:26 localhost shepherd[1]: Service sshd-1 (PID 237) exited with= 255.=20 Oct 4 08:00:26 localhost shepherd[1]: Service sshd-1 has been disabled.=20 Oct 4 08:00:26 localhost shepherd[1]: Transient service sshd-1 terminated,= now unregistered.=20 Oct 4 08:00:51 localhost sshd[487]: error: no more sessions Oct 4 08:00:51 localhost shepherd[1]: 0 connections still in use after ssh= d-4 termination.=20 Oct 4 08:00:51 localhost shepherd[1]: Service sshd-4 (PID 485) exited with= 255.=20 Oct 4 08:00:51 localhost shepherd[1]: Service sshd-4 has been disabled.=20 Oct 4 08:00:51 localhost shepherd[1]: Transient service sshd-4 terminated,= now unregistered.=20 Oct 4 08:19:30 localhost shepherd[1]: Service sshd-5 has been started.=20 Oct 4 08:19:32 localhost sshd[609]: Accepted publickey for bob from 176.22= 1.231.220 port 43732 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+f= xK3d3Y Oct 4 08:21:49 localhost shepherd[1]: Service sshd-6 has been started.=20 Oct 4 08:21:53 localhost sshd[621]: Accepted publickey for bob from 176.22= 1.231.220 port 51448 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+f= xK3d3Y Oct 4 08:23:42 localhost shepherd[1]: Service sshd-7 has been started.=20 Oct 4 08:23:43 localhost sshd[630]: Accepted publickey for bob from 185.70= .53.164 port 29603 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 08:24:13 localhost sshd[632]: error: no more sessions Oct 4 08:24:13 localhost shepherd[1]: 2 connections still in use after ssh= d-7 termination.=20 Oct 4 08:24:13 localhost shepherd[1]: Service sshd-7 has been disabled.=20 Oct 4 08:24:13 localhost shepherd[1]: Transient service sshd-7 terminated,= now unregistered.=20 Oct 4 08:24:36 localhost shepherd[1]: Service sshd-8 has been started.=20 Oct 4 08:24:38 localhost sshd[752]: Accepted publickey for bob from 185.70= .53.164 port 29677 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 08:25:05 localhost shepherd[1]: 2 connections still in use after ssh= d-8 termination.=20 Oct 4 08:25:05 localhost shepherd[1]: Service sshd-8 has been disabled.=20 Oct 4 08:25:05 localhost shepherd[1]: Transient service sshd-8 terminated,= now unregistered.=20 Oct 4 08:29:46 localhost shepherd[1]: Service sshd-9 has been started.=20 Oct 4 08:29:47 localhost sshd[900]: Accepted publickey for bob from 185.70= .53.164 port 29693 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 08:30:15 localhost shepherd[1]: 2 connections still in use after ssh= d-9 termination.=20 Oct 4 08:30:15 localhost shepherd[1]: Service sshd-9 (PID 900) exited with= 255.=20 Oct 4 08:30:15 localhost shepherd[1]: Service sshd-9 has been disabled.=20 Oct 4 08:30:15 localhost shepherd[1]: Transient service sshd-9 terminated,= now unregistered.=20 Oct 4 08:34:22 localhost shepherd[1]: Service sshd-10 has been started.=20 Oct 4 08:34:23 localhost sshd[1049]: Accepted publickey for bob from 185.7= 0.53.164 port 44181 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fx= K3d3Y Oct 4 08:34:24 localhost shepherd[1]: Service ssh-daemon has been stopped.= =20 Oct 4 08:35:14 localhost shepherd[1]: Service ssh-daemon has been started.= =20 Oct 4 08:35:46 localhost shepherd[1]: Service sshd-1 has been started.=20 Oct 4 08:35:48 localhost sshd[259]: Accepted publickey for bob from 185.70= .53.164 port 29608 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 08:35:51 localhost shepherd[1]: Service sshd-2 has been started.=20 Oct 4 08:35:53 localhost sshd[264]: Accepted publickey for bob from 201:2a= 73:cac3:e128:cf3d:8dc:8afa:df66 port 54908 ssh2: RSA SHA256:/X3jyhyMizAOKOj= CfXK5cLN3Pa0vmi7dbQG+fxK3d3Y Oct 4 08:36:33 localhost shepherd[1]: Service sshd-3 has been started.=20 Oct 4 08:36:34 localhost sshd[274]: Accepted publickey for bob from 185.70= .53.164 port 44804 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 08:37:05 localhost shepherd[1]: 2 connections still in use after ssh= d-3 termination.=20 Oct 4 08:37:05 localhost shepherd[1]: Service sshd-3 has been disabled.=20 Oct 4 08:37:05 localhost shepherd[1]: Transient service sshd-3 terminated,= now unregistered.=20 Oct 4 08:37:18 localhost shepherd[1]: Service sshd-4 has been started.=20 Oct 4 08:37:20 localhost sshd[424]: Accepted publickey for bob from 185.70= .53.164 port 44907 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 08:38:09 localhost shepherd[1]: Service ssh-daemon has been started.= =20 Oct 4 08:38:28 localhost shepherd[1]: Service sshd-1 has been started.=20 Oct 4 08:38:29 localhost sshd[239]: Accepted publickey for bob from 185.70= .53.164 port 29582 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 08:39:05 localhost shepherd[1]: Service sshd-2 has been started.=20 Oct 4 08:39:06 localhost sshd[248]: Accepted publickey for bob from 185.70= .53.164 port 44208 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 08:39:21 localhost shepherd[1]: 1 connection still in use after sshd= -2 termination.=20 Oct 4 08:39:21 localhost shepherd[1]: Service sshd-2 has been disabled.=20 Oct 4 08:39:21 localhost shepherd[1]: Transient service sshd-2 terminated,= now unregistered.=20 Oct 4 08:39:53 localhost shepherd[1]: Service sshd-3 has been started.=20 Oct 4 08:39:54 localhost sshd[309]: Accepted publickey for bob from 185.70= .53.164 port 44253 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 08:40:22 localhost shepherd[1]: 1 connection still in use after sshd= -3 termination.=20 Oct 4 08:40:22 localhost shepherd[1]: Service sshd-3 (PID 309) exited with= 255.=20 Oct 4 08:40:22 localhost shepherd[1]: Service sshd-3 has been disabled.=20 Oct 4 08:40:22 localhost shepherd[1]: Transient service sshd-3 terminated,= now unregistered.=20 Oct 4 08:42:19 localhost shepherd[1]: Service ssh-daemon has been started.= =20 Oct 4 08:42:22 localhost shepherd[1]: Service sshd-1 has been started.=20 Oct 4 08:42:24 localhost sshd[254]: Accepted publickey for bob from 185.70= .53.164 port 29687 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 08:46:41 localhost shepherd[1]: Service sshd-2 has been started.=20 Oct 4 08:46:44 localhost sshd[267]: Accepted publickey for bob from 201:2a= 73:cac3:e128:cf3d:8dc:8afa:df66 port 48908 ssh2: RSA SHA256:/X3jyhyMizAOKOj= CfXK5cLN3Pa0vmi7dbQG+fxK3d3Y Oct 4 08:48:49 localhost sshd[256]: Received disconnect from 185.70.53.164= port 29687:11: disconnected by user Oct 4 08:48:49 localhost sshd[256]: Disconnected from user bob 185.70.53.1= 64 port 29687 Oct 4 08:48:49 localhost shepherd[1]: 1 connection still in use after sshd= -1 termination.=20 Oct 4 08:48:49 localhost shepherd[1]: Service sshd-1 (PID 254) exited with= 255.=20 Oct 4 08:48:49 localhost shepherd[1]: Service sshd-1 has been disabled.=20 Oct 4 08:48:49 localhost shepherd[1]: Transient service sshd-1 terminated,= now unregistered.=20 Oct 4 11:03:31 localhost shepherd[1]: 0 connections still in use after ssh= d-2 termination.=20 Oct 4 11:03:31 localhost shepherd[1]: Service sshd-2 (PID 267) exited with= 255.=20 Oct 4 11:03:31 localhost shepherd[1]: Service sshd-2 has been disabled.=20 Oct 4 11:03:31 localhost shepherd[1]: Transient service sshd-2 terminated,= now unregistered.=20 Oct 4 11:45:49 localhost shepherd[1]: Service sshd-3 has been started.=20 Oct 4 11:45:51 localhost sshd[294]: Accepted publickey for bob from 185.70= .53.164 port 29659 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 11:47:35 localhost shepherd[1]: Service sshd-4 has been started.=20 Oct 4 11:47:37 localhost sshd[306]: Accepted publickey for bob from 185.70= .53.164 port 1907 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK3= d3Y Oct 4 11:47:49 localhost shepherd[1]: Service sshd-5 has been started.=20 Oct 4 11:47:52 localhost sshd[347]: Accepted publickey for bob from 201:2a= 73:cac3:e128:cf3d:8dc:8afa:df66 port 55988 ssh2: RSA SHA256:/X3jyhyMizAOKOj= CfXK5cLN3Pa0vmi7dbQG+fxK3d3Y Oct 4 11:48:15 localhost shepherd[1]: 2 connections still in use after ssh= d-4 termination.=20 Oct 4 11:48:15 localhost shepherd[1]: Service sshd-4 has been disabled.=20 Oct 4 11:48:15 localhost shepherd[1]: Transient service sshd-4 terminated,= now unregistered.=20 Oct 4 11:49:03 localhost shepherd[1]: Service sshd-5 has been stopped.=20 Oct 4 11:49:03 localhost shepherd[1]: Transient service sshd-5 unregistere= d.=20 Oct 4 11:50:46 localhost shepherd[1]: Service ssh-daemon has been started.= =20 Oct 4 11:50:53 localhost shepherd[1]: Service sshd-1 has been started.=20 Oct 4 11:50:55 localhost sshd[238]: Accepted publickey for bob from 185.70= .53.164 port 29589 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 11:51:49 localhost shepherd[1]: Service sshd-2 has been started.=20 Oct 4 11:51:50 localhost sshd[250]: Accepted publickey for bob from 185.70= .53.164 port 1915 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK3= d3Y Oct 4 11:52:28 localhost sshd[252]: error: no more sessions Oct 4 11:52:28 localhost shepherd[1]: 1 connection still in use after sshd= -2 termination.=20 Oct 4 11:52:28 localhost shepherd[1]: Service sshd-2 has been disabled.=20 Oct 4 11:52:28 localhost shepherd[1]: Transient service sshd-2 terminated,= now unregistered.=20 Oct 4 11:52:46 localhost shepherd[1]: Service sshd-3 has been started.=20 Oct 4 11:52:48 localhost sshd[380]: Accepted publickey for bob from 185.70= .53.164 port 3549 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK3= d3Y Oct 4 11:53:22 localhost shepherd[1]: 1 connection still in use after sshd= -3 termination.=20 Oct 4 11:53:22 localhost shepherd[1]: Service sshd-3 (PID 380) exited with= 255.=20 Oct 4 11:53:22 localhost shepherd[1]: Service sshd-3 has been disabled.=20 Oct 4 11:53:22 localhost shepherd[1]: Transient service sshd-3 terminated,= now unregistered.=20 Oct 4 12:05:47 localhost shepherd[1]: Service sshd-4 has been started.=20 Oct 4 12:05:48 localhost sshd[668]: Accepted publickey for bob from 185.70= .53.164 port 1847 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK3= d3Y Oct 4 12:06:21 localhost shepherd[1]: 1 connection still in use after sshd= -4 termination.=20 Oct 4 12:06:21 localhost shepherd[1]: Service sshd-4 (PID 668) exited with= 255.=20 Oct 4 12:06:21 localhost shepherd[1]: Service sshd-4 has been disabled.=20 Oct 4 12:06:21 localhost shepherd[1]: Transient service sshd-4 terminated,= now unregistered.=20 Oct 4 12:06:39 localhost shepherd[1]: Service ssh-daemon has been stopped.= =20 Oct 4 12:10:31 localhost shepherd[1]: Service ssh-daemon has been started.= =20 Oct 4 12:10:41 localhost shepherd[1]: Service sshd-1 has been started.=20 Oct 4 12:10:43 localhost sshd[258]: Accepted publickey for bob from 185.70= .53.164 port 1914 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK3= d3Y Oct 4 12:11:25 localhost shepherd[1]: Service sshd-2 has been started.=20 Oct 4 12:11:27 localhost sshd[283]: Accepted publickey for bob from 201:2a= 73:cac3:e128:cf3d:8dc:8afa:df66 port 43872 ssh2: RSA SHA256:/X3jyhyMizAOKOj= CfXK5cLN3Pa0vmi7dbQG+fxK3d3Y Oct 4 12:11:54 localhost shepherd[1]: Service sshd-3 has been started.=20 Oct 4 12:11:58 localhost sshd[286]: Accepted publickey for bob from 185.70= .53.164 port 29596 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 12:12:54 localhost shepherd[1]: 2 connections still in use after ssh= d-3 termination.=20 Oct 4 12:12:54 localhost shepherd[1]: Service sshd-3 (PID 286) exited with= 255.=20 Oct 4 12:12:54 localhost shepherd[1]: Service sshd-3 has been disabled.=20 Oct 4 12:12:54 localhost shepherd[1]: Transient service sshd-3 terminated,= now unregistered.=20 Oct 4 12:14:10 localhost shepherd[1]: Service sshd-4 has been started.=20 Oct 4 12:14:11 localhost sshd[461]: Accepted publickey for bob from 185.70= .53.164 port 29693 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 12:14:49 localhost shepherd[1]: 2 connections still in use after ssh= d-4 termination.=20 Oct 4 12:14:49 localhost shepherd[1]: Service sshd-4 (PID 461) exited with= 255.=20 Oct 4 12:14:49 localhost shepherd[1]: Service sshd-4 has been disabled.=20 Oct 4 12:14:49 localhost shepherd[1]: Transient service sshd-4 terminated,= now unregistered.=20 Oct 4 12:15:25 localhost shepherd[1]: Service ssh-daemon has been stopped.= =20 Oct 4 12:17:34 localhost shepherd[1]: Service ssh-daemon has been started.= =20 Oct 4 12:17:56 localhost shepherd[1]: Service sshd-1 has been started.=20 Oct 4 12:17:58 localhost sshd[256]: Accepted publickey for bob from 185.70= .53.164 port 29656 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 12:19:46 localhost shepherd[1]: Service sshd-2 has been started.=20 Oct 4 12:19:48 localhost sshd[262]: Accepted publickey for bob from 185.70= .53.164 port 1871 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK3= d3Y Oct 4 12:20:23 localhost sshd[264]: error: no more sessions Oct 4 12:20:23 localhost shepherd[1]: 1 connection still in use after sshd= -2 termination.=20 Oct 4 12:20:23 localhost shepherd[1]: Service sshd-2 has been disabled.=20 Oct 4 12:20:23 localhost shepherd[1]: Transient service sshd-2 terminated,= now unregistered.=20 Oct 4 12:30:09 localhost shepherd[1]: Service sshd-3 has been started.=20 Oct 4 12:30:11 localhost sshd[389]: Accepted publickey for bob from 185.70= .53.164 port 29601 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK= 3d3Y Oct 4 12:30:46 localhost shepherd[1]: 1 connection still in use after sshd= -3 termination.=20 Oct 4 12:30:46 localhost shepherd[1]: Service sshd-3 (PID 389) exited with= 255.=20 Oct 4 12:30:46 localhost shepherd[1]: Service sshd-3 has been disabled.=20 Oct 4 12:30:46 localhost shepherd[1]: Transient service sshd-3 terminated,= now unregistered.=20 Oct 4 12:44:29 localhost shepherd[1]: Service sshd-4 has been started.=20 Oct 4 12:44:31 localhost sshd[540]: Accepted publickey for bob from 185.70= .53.164 port 1209 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fxK3= d3Y Oct 4 12:46:33 localhost shepherd[1]: Service sshd-5 has been started.=20 Oct 4 12:46:34 localhost sshd[550]: Accepted publickey for bob from 201:2a= 73:cac3:e128:cf3d:8dc:8afa:df66 port 56270 ssh2: RSA SHA256:/X3jyhyMizAOKOj= CfXK5cLN3Pa0vmi7dbQG+fxK3d3Y Oct 4 12:47:17 localhost shepherd[1]: 2 connections still in use after ssh= d-5 termination.=20 Oct 4 12:47:17 localhost shepherd[1]: Service sshd-5 (PID 550) exited with= 255.=20 Oct 4 12:47:17 localhost shepherd[1]: Service sshd-5 has been disabled.=20 Oct 4 12:47:17 localhost shepherd[1]: Transient service sshd-5 terminated,= now unregistered.=20 Oct 4 13:28:20 localhost shepherd[1]: Service sshd-6 has been started.=20 Oct 4 13:28:22 localhost sshd[713]: Accepted publickey for bob from 201:2a= 73:cac3:e128:cf3d:8dc:8afa:df66 port 42030 ssh2: RSA SHA256:/X3jyhyMizAOKOj= CfXK5cLN3Pa0vmi7dbQG+fxK3d3Y Oct 4 14:29:39 localhost shepherd[1]: 2 connections still in use after ssh= d-1 termination.=20 Oct 4 14:29:39 localhost shepherd[1]: Service sshd-1 (PID 256) exited with= 255.=20 Oct 4 14:29:39 localhost shepherd[1]: Service sshd-1 has been disabled.=20 Oct 4 14:29:39 localhost shepherd[1]: Transient service sshd-1 terminated,= now unregistered.=20 Oct 4 14:57:54 localhost shepherd[1]: 1 connection still in use after sshd= -4 termination.=20 Oct 4 14:57:54 localhost shepherd[1]: Service sshd-4 (PID 540) exited with= 255.=20 Oct 4 14:57:54 localhost shepherd[1]: Service sshd-4 has been disabled.=20 Oct 4 14:57:54 localhost shepherd[1]: Transient service sshd-4 terminated,= now unregistered.=20 Oct 4 17:41:45 localhost shepherd[1]: 0 connections still in use after ssh= d-6 termination.=20 Oct 4 17:41:45 localhost shepherd[1]: Service sshd-6 (PID 713) exited with= 255.=20 Oct 4 17:41:45 localhost shepherd[1]: Service sshd-6 has been disabled.=20 Oct 4 17:41:45 localhost shepherd[1]: Transient service sshd-6 terminated,= now unregistered.=20 =2D-8<---------------cut here---------------end--------------->8--- =2D-=20 Best regards, Andrew Tropin --=-=-= Content-Type: application/pgp-signature; name="signature.asc" -----BEGIN PGP SIGNATURE----- iQIzBAEBCgAdFiEEKEGaxlA4dEDH6S/6IgjSCVjB3rAFAmNJBXgACgkQIgjSCVjB 3rAJNA//R63FpeXwzUZQr4SUG/2DS0BtRipxwfekAfZaobqeRmNqNTeg/2MBROfL KgPue2NYOPyxbsZMKGNEMFMgsKRLPd6sVG3d61HEx/W6aI+f1PONZBYkqJlfhbaQ r6DR3w/hfejDuH1pNJ/wADeAC5qN5HAcdOjBNVW+qFoYihjJZ38rGyX9AcVw78vY 0ruMUkolKRtN9I8IKn2ziFBq8BUbs+f4BE5wrRMn3Qzgk7857AjMxmI0TT393oHt jU0Bl85faLWSRlSuQq5CIsXOjtJp8nnRsIW+9irtUnUZSURW3Rtc82d0BwrPIQ67 6m3lY2Vzb/HFqhoWZBhPSQrYrJ4ahqLKemY8q5vEczxid/gOivald4XTgWG9aqkr csavvFTeqkNbVOofFLmtm27LTC+rcLUsEcyr42jqcnuTpd0Si+MF3MCGyAxWrz3g pZdJuA4slaoqO0okfcrQIaA1ZshtieTgri/0kOIOvXoDIqfFh+fYsHVyoy6+TsOf YnQtCwEX6Y/5bPZRBkP5PPUcP8BJ0KBSO+ni9Uhm9lC6RWMIMJb685406io4RWoh y4PBCIH98IDyJzUpi1ZDzRgMdmREgRlI6I+X6GDbbZrbRuzuLp0tAEzkxroYux0z CMjBy3emSy5GJ3q42iCDxdUOpJh2VogYrOyOc76HME3BfhzcF9s= =ekjf -----END PGP SIGNATURE----- --=-=-=-- From debbugs-submit-bounces@debbugs.gnu.org Mon Oct 17 10:39:38 2022 Received: (at 58290) by debbugs.gnu.org; 17 Oct 2022 14:39:38 +0000 Received: from localhost ([127.0.0.1]:49619 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1okRHG-0002Vy-9G for submit@debbugs.gnu.org; Mon, 17 Oct 2022 10:39:38 -0400 Received: from eggs.gnu.org ([209.51.188.92]:60078) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1okRHE-0002Vl-7g for 58290@debbugs.gnu.org; Mon, 17 Oct 2022 10:39:36 -0400 Received: from fencepost.gnu.org ([2001:470:142:3::e]:55492) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1okRH8-0006Fq-Dp; Mon, 17 Oct 2022 10:39:30 -0400 DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=gnu.org; s=fencepost-gnu-org; h=MIME-Version:In-Reply-To:Date:References:Subject:To: From; bh=bfSSIH6qhBHGpg2V0pEmSt4te/HVlOdbLYfGoY9Sn2s=; b=F/T9DQiR7EGQDScCOvsf 81SbtjxFG1Xiq26axoLXPDIwHGr6VZsyp4J8F4HpGIqZ2pwdKNVqvudPMBAwS2st7v3vhIDyhWwUw RmM5smlng2wKOkna4nNjYfNwyezAkakzeyFkmCuwedmCgQ6oIsEvxHqq5eByUw3BPRqH1UEeZseyp 62L5zEHpc/zMK51XC3w1/vQbFKeUldhNC96O2PnZKNZdnjBlZdgdqhVwIKuv5rEvsB18eGQ20ePNu yg+ORsO6y4KDxPjfGS/MB4cwiVAd8BpCPOZ8ftqLnbNtwxKgiY2/3pdmMLktsJg0/nCC8YesGA6w8 sP8uh03u/xiHtQ==; Received: from nat-eduroam-36-gw-01-bso.bordeaux.inria.fr ([194.199.1.36]:46358 helo=ribbon) by fencepost.gnu.org with esmtpsa (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1okRH7-0005Ny-Vd; Mon, 17 Oct 2022 10:39:30 -0400 From: =?utf-8?Q?Ludovic_Court=C3=A8s?= To: Andrew Tropin Subject: Re: bug#58290: guile ssh error on guix deploy References: <87sfk34zhj.fsf@trop.in> <87bkqm8p5z.fsf@gnu.org> <87o7uec39j.fsf@trop.in> Date: Mon, 17 Oct 2022 16:39:26 +0200 In-Reply-To: <87o7uec39j.fsf@trop.in> (Andrew Tropin's message of "Fri, 14 Oct 2022 10:45:12 +0400") Message-ID: <8735bmsee9.fsf@gnu.org> User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/28.1 (gnu/linux) MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-Spam-Score: -2.3 (--) X-Debbugs-Envelope-To: 58290 Cc: 58290@debbugs.gnu.org X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -3.3 (---) Hi, Andrew Tropin skribis: >>> ice-9/boot-9.scm:1685:16: In procedure raise-exception: >>> Throw to key `guile-ssh-error' with args `("channel-open-session" "Chan= nel opening failure: channel 67 error (2) open failed" # #f)'. >> >> Are there any hints from sshd in the /var/log/messages of that machine >> as to why the connection was closed? > > bob@pinky /var/log$ zcat messages.1.gz | grep "Oct 4" | grep ssh It=E2=80=99s hard (if not impossible) to see which lines correspond to the = error above. :-) Could try to reproduce the bug, and have =E2=80=98tail -f /var/log/messages= =E2=80=99 running on the server side so you can capture just the right lines? /var/log/debug might be interesting too. Thanks, Ludo=E2=80=99. From debbugs-submit-bounces@debbugs.gnu.org Mon Oct 17 13:27:42 2022 Received: (at 58290) by debbugs.gnu.org; 17 Oct 2022 17:27:42 +0000 Received: from localhost ([127.0.0.1]:49877 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1okTtt-0000nl-Vc for submit@debbugs.gnu.org; Mon, 17 Oct 2022 13:27:42 -0400 Received: from eggs.gnu.org ([209.51.188.92]:48682) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1okTtr-0000nU-8O for 58290@debbugs.gnu.org; Mon, 17 Oct 2022 13:27:40 -0400 Received: from fencepost.gnu.org ([2001:470:142:3::e]:42420) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1okTtk-0001X8-5Y; Mon, 17 Oct 2022 13:27:33 -0400 DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=gnu.org; s=fencepost-gnu-org; h=MIME-Version:Date:References:In-Reply-To:Subject:To: From; bh=kWjzZj6hhE50E2FReOAgVfHfVvGSplAXy0dSWiBL3mk=; b=DYxLDX2MwVykO+KMjFzc xLJY2gD8M8Z5GM629aKstCzVS7cstq5mAz59k37KPjpgAP53Qh/tPjVfwhIkod1gK5BoTDmSvYlKM YPLpDrMVJ4Km1gY3HucbiiWo8vwSK1S60HYxD+G4Eam6EjK92xiTiUIe5edjW39bQiAaOtqARk3GF bzXoBm8eXCp03KGTia++BAMKFsmWnrzblYWljrLcC5QoMTwEpXeQXsCeAA2c9aeZm6Y0TsnINUOsA Vaxg5xnWyYfgpZqBwJX2Y7wefzSvW2CezwtCz9Dd6iyBqPLQ/J06N02r42lsiqi94rxQGfgXq4iFD L0KT7ABvHfhjQg==; Received: from [84.211.203.64] (port=55724 helo=localhost) by fencepost.gnu.org with esmtpsa (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1okTtb-000418-9y; Mon, 17 Oct 2022 13:27:27 -0400 From: Marius Bakke To: Ludovic =?utf-8?Q?Court=C3=A8s?= , Andrew Tropin Subject: Re: bug#58290: guile ssh error on guix deploy In-Reply-To: <8735bmsee9.fsf@gnu.org> References: <87sfk34zhj.fsf@trop.in> <87bkqm8p5z.fsf@gnu.org> <87o7uec39j.fsf@trop.in> <8735bmsee9.fsf@gnu.org> Date: Mon, 17 Oct 2022 19:27:20 +0200 Message-ID: <87h702uzrb.fsf@gnu.org> MIME-Version: 1.0 Content-Type: multipart/signed; boundary="=-=-="; micalg=pgp-sha512; protocol="application/pgp-signature" X-Spam-Score: -2.3 (--) X-Debbugs-Envelope-To: 58290 Cc: 58290@debbugs.gnu.org X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -3.3 (---) --=-=-= Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable Ludovic Court=C3=A8s skriver: > Hi, > > Andrew Tropin skribis: > >>>> ice-9/boot-9.scm:1685:16: In procedure raise-exception: >>>> Throw to key `guile-ssh-error' with args `("channel-open-session" "Cha= nnel opening failure: channel 67 error (2) open failed" # #f)'. >>> >>> Are there any hints from sshd in the /var/log/messages of that machine >>> as to why the connection was closed? >> >> bob@pinky /var/log$ zcat messages.1.gz | grep "Oct 4" | grep ssh > > It=E2=80=99s hard (if not impossible) to see which lines correspond to th= e error > above. :-) > > Could try to reproduce the bug, and have =E2=80=98tail -f /var/log/messag= es=E2=80=99 > running on the server side so you can capture just the right lines? > /var/log/debug might be interesting too. I have the same problem. Log messages around failure look something like this (extracted from above message): Oct 4 11:51:49 localhost shepherd[1]: Service sshd-2 has been started.=20 Oct 4 11:51:50 localhost sshd[250]: Accepted publickey for bob from 185.= 70.53.164 port 1915 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+fx= K3d3Y Oct 4 11:52:28 localhost sshd[252]: error: no more sessions Oct 4 11:52:28 localhost shepherd[1]: 1 connection still in use after ss= hd-2 termination.=20 Oct 4 11:52:28 localhost shepherd[1]: Service sshd-2 has been disabled.= =20 Then deploy crashes with 'Channel opening failure'. Due to the number of SSH connections made by deploy and frequent occurence of this problem, I was not able to successfully deploy through many attempts. I found that removing the memoizing open-machine-ssh-session* in (gnu machine ssh) works around it and can happily deploy again. (that is, just use 'open-machine-ssh-session' instead) --=-=-= Content-Type: application/pgp-signature; name="signature.asc" -----BEGIN PGP SIGNATURE----- iIUEARYKAC0WIQRNTknu3zbaMQ2ddzTocYulkRQQdwUCY02QeA8cbWFyaXVzQGdu dS5vcmcACgkQ6HGLpZEUEHfSOwEAvIflhP7SIu4QVTzDTPeVj5tf4c5yKWUkCqzT Fp5bbZ0BAOkXwYDz1lmBlIJzRzZ7TAErhs3EXLvyUbqh/eBliEEF =BIX7 -----END PGP SIGNATURE----- --=-=-=-- From debbugs-submit-bounces@debbugs.gnu.org Tue Oct 18 11:31:59 2022 Received: (at 58290) by debbugs.gnu.org; 18 Oct 2022 15:31:59 +0000 Received: from localhost ([127.0.0.1]:53803 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1okoZP-00083f-VZ for submit@debbugs.gnu.org; Tue, 18 Oct 2022 11:31:59 -0400 Received: from eggs.gnu.org ([209.51.188.92]:48158) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1okoZO-00083T-FC for 58290@debbugs.gnu.org; Tue, 18 Oct 2022 11:31:55 -0400 Received: from fencepost.gnu.org ([2001:470:142:3::e]:39050) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1okoZI-0000K2-QV; Tue, 18 Oct 2022 11:31:48 -0400 DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=gnu.org; s=fencepost-gnu-org; h=MIME-Version:In-Reply-To:Date:References:Subject:To: From; bh=TtWPOrX2Qx0d3Axf2j8p0aOX5SVhQQUOloNT5KF6WQk=; b=cT1CHBdeSyvzE8wo5bxt Oc1BAmkMXxyGeAAf5XGfGjcW8HfEOy2BGazMxcJnuhTULJlAkkGzHPBTI9QHa26HqgeSWvNDOUvvc uU5OrtFrkU0GbNOo7AgaolEZ2tkkxls2kjDVaabYcuu6hWOgxi8G20zcMO+4tNa03D+NqN5vUsjdq 81IG2PBdAHJe1fgACWnXI9jaZYv8w87Kn3znxpWblS6ayxsOkFlaRtu4nY+svJ0Ov5vlIgdYKjqKk WFcON/xQhCSwAKYFGogg5e76TZcXG7xBlS+Wbj3zoAVSWp6HY/uIo0YxOb59hlKgaSZhWekiEvGtC 084OitxccbzLfw==; Received: from [193.50.110.209] (port=37976 helo=ribbon) by fencepost.gnu.org with esmtpsa (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1okoZF-00047c-Ai; Tue, 18 Oct 2022 11:31:46 -0400 From: =?utf-8?Q?Ludovic_Court=C3=A8s?= To: Marius Bakke Subject: Re: bug#58290: guile ssh error on guix deploy References: <87sfk34zhj.fsf@trop.in> <87bkqm8p5z.fsf@gnu.org> <87o7uec39j.fsf@trop.in> <8735bmsee9.fsf@gnu.org> <87h702uzrb.fsf@gnu.org> X-URL: http://www.fdn.fr/~lcourtes/ X-Revolutionary-Date: Septidi 27 =?utf-8?Q?Vend=C3=A9miaire?= an 231 de la =?utf-8?Q?R=C3=A9volution=2C?= jour du Piment X-PGP-Key-ID: 0x090B11993D9AEBB5 X-PGP-Key: http://www.fdn.fr/~lcourtes/ludovic.asc X-PGP-Fingerprint: 3CE4 6455 8A84 FDC6 9DB4 0CFB 090B 1199 3D9A EBB5 X-OS: x86_64-pc-linux-gnu Date: Tue, 18 Oct 2022 17:31:42 +0200 In-Reply-To: <87h702uzrb.fsf@gnu.org> (Marius Bakke's message of "Mon, 17 Oct 2022 19:27:20 +0200") Message-ID: <87y1tdkv1d.fsf@gnu.org> User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/28.1 (gnu/linux) MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-Spam-Score: -2.3 (--) X-Debbugs-Envelope-To: 58290 Cc: 58290@debbugs.gnu.org, Andrew Tropin X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -3.3 (---) Hi, Marius Bakke skribis: > I have the same problem. Log messages around failure look something > like this (extracted from above message): > > Oct 4 11:51:49 localhost shepherd[1]: Service sshd-2 has been started.= =20 > Oct 4 11:51:50 localhost sshd[250]: Accepted publickey for bob from 18= 5.70.53.164 port 1915 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG+= fxK3d3Y > Oct 4 11:52:28 localhost sshd[252]: error: no more sessions > Oct 4 11:52:28 localhost shepherd[1]: 1 connection still in use after = sshd-2 termination.=20 > Oct 4 11:52:28 localhost shepherd[1]: Service sshd-2 has been disabled= .=20 > > Then deploy crashes with 'Channel opening failure'. =E2=80=9Cno more sessions=E2=80=9D comes from this: --8<---------------cut here---------------start------------->8--- int session_open(Authctxt *authctxt, int chanid) { Session *s =3D session_new(); debug("session_open: channel %d", chanid); if (s =3D=3D NULL) { error("no more sessions"); return 0; } [...] } --8<---------------cut here---------------end--------------->8--- Would be interesting to run sshd in verbose/debug mode and see why we hit that; it could be because the maximum number of sessions has been reached or something. > Due to the number of SSH connections made by deploy and frequent > occurence of this problem, I was not able to successfully deploy through > many attempts. Ouch. Normally, thanks to memoization, =E2=80=98guix deploy=E2=80=99 opens= only one session per machine. (I think it works well with the 25 local build machines behind berlin; it=E2=80=99s also fine for a small set of machines I take care of at work.) > I found that removing the memoizing open-machine-ssh-session* in > (gnu machine ssh) works around it and can happily deploy again. > > (that is, just use 'open-machine-ssh-session' instead) Interesting. That gives us a hint. Could you add a =E2=80=98pk=E2=80=99 in =E2=80=98open-machine-ssh-session*=E2=80=99 to see how many connections it = opens? Thanks for your feedback! Ludo=E2=80=99. From debbugs-submit-bounces@debbugs.gnu.org Thu Nov 03 19:47:19 2022 Received: (at 58290) by debbugs.gnu.org; 3 Nov 2022 23:47:20 +0000 Received: from localhost ([127.0.0.1]:51022 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1oqjvb-0003H6-7K for submit@debbugs.gnu.org; Thu, 03 Nov 2022 19:47:19 -0400 Received: from eggs.gnu.org ([209.51.188.92]:35260) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1oqjvW-0003Go-4Y for 58290@debbugs.gnu.org; Thu, 03 Nov 2022 19:47:17 -0400 Received: from fencepost.gnu.org ([2001:470:142:3::e]) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1oqjvP-0000Yz-37; Thu, 03 Nov 2022 19:47:08 -0400 DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=gnu.org; s=fencepost-gnu-org; h=MIME-Version:Date:References:In-Reply-To:Subject:To: From; bh=/73cpX3sJtXofZ9mR3iYKLjlYHbNyASXEZSibS9d+/o=; b=qoCKLpLMe1IPUy9sdKT9 yDAlORLFYtQXfz25fWPn+RgPzPu44DRIxDxvr70Fh8yqVTs8Nn3aZQbr0DEe7BvB9VZwpoqr7qgHl 35ZyqflkmjQztRCyQyur9Kvf7vyxtY5+uvXsQlleJ+EJ0z4fNd7yUwpzqRzwJk+Esvanir6tCbcle P4NSSZ66udaePASPEd6tEeujSm7Fun9Q6PQDatkJnm/e58RoIOAcbhrXNBfLrDraQJhKDaSGwkj8j 32JJnWbynXMbX3GpLl2sXjCJKy2tDURp091KS7Z1vazKKHOrLFGBOJZgNnYe9KmXD5gVZRuRktL75 LTK+TDdKddBkow==; Received: from [84.214.173.6] (helo=localhost) by fencepost.gnu.org with esmtpsa (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1oqjvN-00085S-Pk; Thu, 03 Nov 2022 19:47:06 -0400 From: Marius Bakke To: Ludovic =?utf-8?Q?Court=C3=A8s?= Subject: Re: bug#58290: guile ssh error on guix deploy In-Reply-To: <87y1tdkv1d.fsf@gnu.org> References: <87sfk34zhj.fsf@trop.in> <87bkqm8p5z.fsf@gnu.org> <87o7uec39j.fsf@trop.in> <8735bmsee9.fsf@gnu.org> <87h702uzrb.fsf@gnu.org> <87y1tdkv1d.fsf@gnu.org> Date: Fri, 04 Nov 2022 00:47:02 +0100 Message-ID: <875yfv38jt.fsf@gnu.org> MIME-Version: 1.0 Content-Type: multipart/signed; boundary="==-=-="; micalg=pgp-sha512; protocol="application/pgp-signature" X-Spam-Score: -2.3 (--) X-Debbugs-Envelope-To: 58290 Cc: 58290@debbugs.gnu.org, Andrew Tropin X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -3.3 (---) --==-=-= Content-Type: multipart/mixed; boundary="=-=-=" --=-=-= Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable Ludovic Court=C3=A8s skriver: > Hi, > > Marius Bakke skribis: > >> I have the same problem. Log messages around failure look something >> like this (extracted from above message): >> >> Oct 4 11:51:49 localhost shepherd[1]: Service sshd-2 has been started= .=20 >> Oct 4 11:51:50 localhost sshd[250]: Accepted publickey for bob from 1= 85.70.53.164 port 1915 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQG= +fxK3d3Y >> Oct 4 11:52:28 localhost sshd[252]: error: no more sessions >> Oct 4 11:52:28 localhost shepherd[1]: 1 connection still in use after= sshd-2 termination.=20 >> Oct 4 11:52:28 localhost shepherd[1]: Service sshd-2 has been disable= d.=20 >> >> Then deploy crashes with 'Channel opening failure'. > > =E2=80=9Cno more sessions=E2=80=9D comes from this: > > --8<---------------cut here---------------start------------->8--- > int > session_open(Authctxt *authctxt, int chanid) > { > Session *s =3D session_new(); > debug("session_open: channel %d", chanid); > if (s =3D=3D NULL) { > error("no more sessions"); > return 0; > } > > [...] > > } > --8<---------------cut here---------------end--------------->8--- > > Would be interesting to run sshd in verbose/debug mode and see why we > hit that; it could be because the maximum number of sessions has been > reached or something. I enabled (log-level 'debug) and this is what happens server side: Nov 3 21:48:25 capella sshd[26345]: debug1: permanently_set_uid: 0/0 Nov 3 21:50:27 capella sshd[26115]: debug1: Received SIGCHLD. Nov 3 21:50:27 capella sshd[26115]: debug1: session_by_pid: pid 26345 Nov 3 21:50:27 capella sshd[26115]: debug1: session_exit_message: session = 8 channel 8 pid 26345 Nov 3 21:50:27 capella sshd[26115]: debug1: session_exit_message: release = channel 8 Nov 3 21:50:28 capella sshd[26115]: debug1: server_input_channel_open: cty= pe session rchan 65 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 0: new [server-session] Nov 3 21:50:28 capella sshd[26115]: debug1: session_new: session 0 Nov 3 21:50:28 capella sshd[26115]: debug1: session_open: channel 0 Nov 3 21:50:28 capella sshd[26115]: debug1: session_open: session 0: link = with channel 0 Nov 3 21:50:28 capella sshd[26115]: debug1: server_input_channel_open: con= firm session Nov 3 21:50:28 capella sshd[26115]: debug1: server_input_channel_req: chan= nel 0 request exec reply 1 Nov 3 21:50:28 capella sshd[26115]: debug1: session_by_channel: session 0 = channel 0 Nov 3 21:50:28 capella sshd[26115]: debug1: session_input_channel_req: ses= sion 0 req exec Nov 3 21:50:28 capella sshd[26535]: debug1: PAM: reinitializing credentials Nov 3 21:50:28 capella sshd[26535]: debug1: permanently_set_uid: 0/0 Nov 3 21:50:28 capella sshd[26115]: debug1: server_input_channel_open: cty= pe 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-sessio= n] 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 chan= nel 10 Nov 3 21:50:28 capella sshd[26115]: debug1: channel 10: free: server-sessi= on, nchannels 11 Nov 3 21:50:28 capella sshd[26115]: debug1: server_input_channel_open: fai= lure session Nov 3 21:50:28 capella sshd[26115]: debug1: channel 0: free: server-sessio= n, nchannels 10 Nov 3 21:50:28 capella sshd[26115]: debug1: channel 1: free: server-sessio= n, nchannels 9 Nov 3 21:50:28 capella sshd[26115]: debug1: channel 2: free: server-sessio= n, nchannels 8 Nov 3 21:50:28 capella sshd[26115]: debug1: channel 3: free: server-sessio= n, nchannels 7 Nov 3 21:50:28 capella sshd[26115]: debug1: channel 4: free: server-sessio= n, nchannels 6 Nov 3 21:50:28 capella sshd[26115]: debug1: channel 5: free: server-sessio= n, nchannels 5 Nov 3 21:50:28 capella sshd[26115]: debug1: channel 6: free: server-sessio= n, nchannels 4 Nov 3 21:50:28 capella sshd[26115]: debug1: channel 7: free: server-sessio= n, nchannels 3 Nov 3 21:50:28 capella sshd[26115]: debug1: channel 8: free: server-sessio= n, nchannels 2 Nov 3 21:50:28 capella sshd[26115]: debug1: channel 9: free: server-sessio= n, nchannels 1 Nov 3 21:50:28 capella sshd[26115]: debug1: do_cleanup I compared this with a successful deploy: Nov 3 21:44:22 capella sshd[25842]: debug1: permanently_set_uid: 0/0 Nov 3 21:46:25 capella sshd[25612]: debug1: Received SIGCHLD. Nov 3 21:46:25 capella sshd[25612]: debug1: session_by_pid: pid 25842 Nov 3 21:46:25 capella sshd[25612]: debug1: session_exit_message: session = 6 channel 6 pid 25842 Nov 3 21:46:25 capella sshd[25612]: debug1: session_exit_message: release = channel 6 Nov 3 21:46:26 capella sshd[25612]: debug1: server_input_channel_open: cty= pe session rchan 65 win 64000 max 32768 Nov 3 21:46:26 capella sshd[25612]: debug1: input_session_request Nov 3 21:46:26 capella sshd[25612]: debug1: channel 0: new [server-session] Nov 3 21:46:26 capella sshd[25612]: debug1: session_new: session 0 Nov 3 21:46:26 capella sshd[25612]: debug1: session_open: channel 0 Nov 3 21:46:26 capella sshd[25612]: debug1: session_open: session 0: link = with channel 0 Nov 3 21:46:26 capella sshd[25612]: debug1: server_input_channel_open: con= firm session Nov 3 21:46:26 capella sshd[25612]: debug1: server_input_channel_req: chan= nel 0 request exec reply 1 Nov 3 21:46:26 capella sshd[25612]: debug1: session_by_channel: session 0 = channel 0 Nov 3 21:46:26 capella sshd[25612]: debug1: session_input_channel_req: ses= sion 0 req exec Nov 3 21:46:26 capella sshd[26032]: debug1: PAM: reinitializing credentials Nov 3 21:46:26 capella sshd[26032]: debug1: permanently_set_uid: 0/0 Nov 3 21:46:26 capella sshd[25612]: debug1: server_input_channel_open: cty= pe session rchan 66 win 64000 max 32768 Nov 3 21:46:26 capella sshd[25612]: debug1: input_session_request Nov 3 21:46:26 capella sshd[25612]: debug1: channel 8: new [server-session] Nov 3 21:46:26 capella sshd[25612]: debug1: session_new: session 8 Nov 3 21:46:26 capella sshd[25612]: debug1: session_open: channel 8 Nov 3 21:46:26 capella sshd[25612]: debug1: session_open: session 8: link = with channel 8 Nov 3 21:46:26 capella sshd[25612]: debug1: server_input_channel_open: con= firm session Nov 3 21:46:26 capella sshd[25612]: debug1: server_input_channel_req: chan= nel 8 request exec reply 1 Nov 3 21:46:26 capella sshd[25612]: debug1: session_by_channel: session 8 = channel 8 Nov 3 21:46:26 capella sshd[25612]: debug1: session_input_channel_req: ses= sion 8 req exec Nov 3 21:46:26 capella sshd[26043]: debug1: PAM: reinitializing credentials Nov 3 21:46:26 capella sshd[26043]: debug1: permanently_set_uid: 0/0 Nov 3 21:46:28 capella sshd[25612]: debug1: chan_shutdown_extended_read: c= hannel 8: (i0 o3 sock -1 wfd -1 efd 13 [read]) Nov 3 21:46:28 capella sshd[25612]: debug1: server_input_channel_open: cty= pe session rchan 67 win 64000 max 32768 Nov 3 21:46:28 capella sshd[25612]: debug1: input_session_request Nov 3 21:46:28 capella sshd[25612]: debug1: channel 9: new [server-session] Nov 3 21:46:28 capella sshd[25612]: debug1: session_new: session 9 [... more channels and stuffs before graceful shutdown ...] I believe the two-minute window before SIGCHLD is waiting for some Shepherd services to time out (long story..!). 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: c= hannel 66 error (2) open failed: # 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. I have attached the transcripts of each session (by grepping the PIDs from /var/log/debug). Grepping for session_open yields some inconstencies, but haven't studied them in detail yet. >> Due to the number of SSH connections made by deploy and frequent >> occurence of this problem, I was not able to successfully deploy through >> many attempts. > > Ouch. Normally, thanks to memoization, =E2=80=98guix deploy=E2=80=99 ope= ns only one > session per machine. (I think it works well with the 25 local build > machines behind berlin; it=E2=80=99s also fine for a small set of machine= s I > take care of at work.) Have they been rebooted since the switch to inetd-style sshd? It fails more often than not for me. >> I found that removing the memoizing open-machine-ssh-session* in >> (gnu machine ssh) works around it and can happily deploy again. >> >> (that is, just use 'open-machine-ssh-session' instead) > > Interesting. That gives us a hint. Could you add a =E2=80=98pk=E2=80=99= in > =E2=80=98open-machine-ssh-session*=E2=80=99 to see how many connections i= t opens? Indeed it only opens a single connection. The problem seems to be with multiple "channels" and "sessions" over a single connection. --=-=-= Content-Type: application/gzip Content-Disposition: attachment; filename=deploy-fail.log.gz Content-Transfer-Encoding: base64 H4sICDlQZGMAA2RlcGxveS1mYWlsLmxvZwDtXWtz2zYW/d5fgemXdDt+iNRbs9vZNHGbTBsnE2d2 k+10ODQJW5xQJENSfuTX94KyZIoRiYsL0FJ3+CW2Yulc4AAHOBeXhs/jG8b6zLZmg8msN2Gem/Aw dFmWzf0/7JFlDf+cMZ9fLq+tGQsinvssi73PPM+Ye5XzlPnLJAmi6xnrH7HBd+cqcL/HnhuyG55m QRyxLE8Bh11cvDq2T3rHbxMewffO9MRSQ33PF3HOWZLGeezFj/gAesTS1Q+z+Cq/dVO++WEYXAKY 0zuZnozUwnnxInFz59KNIp7OWBSzhZt785kGZMLThRvxKA/vnYznzjLwZ2w6mZ5OJ332R5Jyd5nP /1TDDIMsd+Zxln/m905+n/BsxtLMPc7mrn08tOyjzQt7ODrinr9+GcEHE/F/AHvMfXs4tKbURsB4 2s6bi1+d384+vj5//YFl0EljYCn3eHDDfSrgZ343Y254HadBPl/AyC7TG170t2BiONICFtzDd/fl CAYoLbC9MAAij3/KOLQ4ZV6QzMVcdHkGrT6+9hb/jkFN8PkTmK3szfMXM/bPYJGEgRfkPxUzOOWZ 0MGMfYVpu/VunXat2nP806p9B9EufpdwL39YaDbzxzl78fKVU8wiA7OxhKY7J1Mupky8zB9W24E9 HUxHY3s6YpchrMOZdnvPz/7729mnCz0p8sjfovTs4wfo/y9vDY7Sup2m+mtmZILI9MDA/GF+HHHq 55cgOvGx45R/WXJYc67itPhPlsZxXkgy8Hix9Hgx7FlAM+x/C57PY58ly0sQn+gYMbqb53yR5KzH rtwgXIJ84Vsi1rvnb4TlCPLADYOvYjKIrnwvuvE9AQl20mJGwQvn/au3Fx9YHrPvf3x/9vL5iw9n L3/Uxfzw4VOBCO9WhFoPmQP0A/ez0jDkYgSTz7BnbG0WyWeYZJfs7OXq5cWr57Cgzt6dXszfXU6+ BO+T/41e5uHVf8Yff3k+/fTz7bl3Nr9K0i8fR19+dpfnFzF1TMToxqmbBmBNoNkra9I77bEf+L/g yz8U0dJ7wd6qu8XmeBWEnJ2KIT49gY+ciibCbvmV+w78OFODv/LZEPZG7hbG8q1z/vb859/fvvhN VehZHqePXf1bEWar4b+Il6EPHjZnYqtdLRvPBPgz9ggs4mbsWUPQZzN2HrNs6c1X7QPZ+gEsuMDj /f8f+Tz3TnewcOIXDO1jykqaNIO3FEmKiFH0I15GwAx9OTHevML1JGJrgjzFvRbuFhZ/SNkKnwGD uv06vy/m6nHqsTvLKv3oKWfbYey8loGdt1vlD3Kh6Vb5bpXvVvk9r/KFUXdh7b5xc+5sWr/OBCJ+ W7wF+hJ4brHCP7xHLYwfO4m7gEAejFo+gzeHIffVMBYxJE9x6sAUCH3nYSuYlbakUkNB8Jf3LEmD G5jt1/AqSWOPZ4qtJpND3anOIhd0CtClwyLYClnIb3jIRidU3DV18GHfCeNrGABBIoNvhXq9MM5U R6NIGGHqiQZnhSi9lPuCCjdUpFl29mD4jEkNThx6J64oERSH10kMXS7mHWUKy8ZXcXqKmcn3te6c RcCuAAzEN6u2gDRWfRJeUZxRKfZodcLqiFMSxw+yRKz3RIRkmcNKIcoYoSN8AQyYqBNsWpiKH7JB n93CxBsNer0ebC93rG+PRxO1kKtYD7jOg1tWrLqsGsp6s2JR+ePhpPkBU1Hs65YA0uYFU9wW1hgP zK2bpwOyaYmo3kSfgfd8TkeuH+U4ugrSxTpcBXdKwIURLVHA1ukQv+MevEjCe1Yt6UmjrHi5vF/H KLFTSwkSdEfbH7HhZdFuNWgB5mTzZe7Ht5HD73Ie+eB+xGayNXV/CHos7hcFVXZssVvYWeALhy8W 5G7i7X9W3es+mSp2vS3ox0FebY/ik2Pj4DM2d7NVhCOW5/cFTR0vZnhRW/0HiNVfEhKz+iP0JRiw UKs/kuit1Z84vbZXfy2QTUt2rf4GR1lv9e9U1fHS8dLx0g4v79c1+ovXv7549fvLanKEpzURZz3w j05f+R0kWQt4ARnjzvExGyDlIXczrjv8e5pTisClWXOVcr55dOgh4BGLHt6Rsepht3aGYrWcoVi6 hqAhQ7FqMhTIH/QzFIuSocgik5jCgtbPS+txrbPHxsERa13HC40XyR6gQGt5D6D2dfceUBofswGq e8Dfa0711Nekh1kj2wOUm6yW5Q7lWa4sJCLLxfKBOuPEjlpTlovFaDzjVANpzHKVkWlZrmU9xRmn PApGq1VKkKAUB0FhpUFTI4SmJCExmpJAKJ0cYdltqhtgMRpPjtRAGusGysj70hTGletoqqdLNqFu YNmtu/J+jSuXRFZV8xihZklIjJoRfAlKbJSapRTsULNNw9hWsxbIpiW71KyMTFQzssVqOkOConKX wdQ4OCZ36XjpeOl4aZ0X2RkAntbyGQC1r7JzYMtsANkZwGHPqaodRu7oiDOAvoG9b8tx2hjHqcG2 rWsIGhynTXSc7ShrpDjqzcoq8WY2QFVZisOCcuukp3xMu/XJQbl1XO5NcevEWdGce5PcOir3PkC3 Xn/SpL0jlKrNfcXJZ6ba3PHS8dLx0j4v7XgKal9lFbue2QCSpzYOfE4R3TriqQ3jbh11PrzP3Ihy PjzQU5bk4zXKGlc7iIRB58FmAsjyYHznFcYaCaqeB0uAFfLgatYibbJa7jBF5A6SkJjcAckHrhaO HLXG3AGJ0VwLVwJpzB2UkYm5AwVXvRZuRKtEsltYlxU1NewdlKZw+ThFU8Rhb87HSZra+XyJMvK+ NIXyOhqaqn8WTF9Ttc+XDPdWC5dEVlWzhVCzJCRGzQi+BCV9lJqlFOxQc9XCIzG21awFsmnJLjUr IxPVjGyxms6QoKga3tQ8OOZUoOOl46XjpXVeZGcAeFrLZwDUvqKfhzcTQHYGcNhzqpqwIHd0xBnA wMDet+U4+xjHqcF2X9cQNDjOPtFxtqIsu1c9n9FSVok3swGqylIclhZr4Ybdun1Qbh2Xe1PcOlGs zbk3ya2jcu8DdOv1J03aO0KphjcxD96y++p46XjpeNmnW6f2FX2DgZkAslr4Yc8poltH1MKNu3XU +fA+c6MWzofbcesWMR3B5sGGAsjyYLO3fg0Rdz7KQmI8M/6OEIRnptz6VZU86dYvLRClGnBLt36R cNVrwG3cX4MFJdSAbbN3DAwRN+nJQiI0JYNY8zjAaEpOwQ5NDWgY25rSAtm0ZJemlJFpmiLhbmlq gNAUlpddmhrokt2gqUGdphC/rS89VRpQasCyyKpqRtwYIguJUTPydoMhSs2U2w2GNIxtNWuBbFqy S83KyEQ1a9w7UK8zJGh95jLYZMN23zw4IhvueOl46XhpnxdJ7qtAazn3pfZ1d+5bGh+zAaq5LxF0 T3OqR9vRB/JTpZGBvW/LcQ4xjlOD7aGuIWhwnEOi42xHWQNiB3crq8Sb2QBVZSmCtlcDNu3WEXeR PaFbx+XeFLdOXMWac2+SW0fl3gfo1mtPmvR3hMfalW33jYO37L46XjpeOl726SmofcXWgA0FkNSA D3xOEd06ogZs3K2jzof3mRu1cD7cjrKGymOjmAebCaCdB6t5ZsSNn0/omVE1YJJnJq4ljTVgmmfG 1ID355lN1ID3uvpTasCGNYW4l+sJNTVqTVPE9W5bU1ogm5bs0pSJvfhJNDVqWVMjXbIbNDWq05SJ W/ZGpBqw2Vv2hoibMmQhMWpG3skzRqmZcsvemIaxrWYtkE1LdqlZGZmoZo27hep1pn2T0+gxG64+ xGsAHJMNd7x0vHS8tM6LLPcl3bJH7uvu3Lc0PmYDVHNf4vDvaU4pUlCaNbJTJUW7IXecY4zj1GB7 rGsIGhznuM5x9vWUJfl4jbKmNg1mt7JKvJkNUFVWdVgkoC3WgKXdUXLrI8QdXLKQGLeO4AufeyNH tDH3RmI0595KIEq5t8YoN7p1vGgVTpqQoKja1WhqHBzjMjpeOl46XlrnpR1PQe0rugZsJoCsBnzY c0oRWKEGrGg3DJ0Pa7BdnxshQSnnw/tQVr9XffhBS1nf5sGGAsjyYMOeGXHT5RN6ZlwNmOKZiWtJ cw2Y5JlRNeC9eWYjNeB9rv6UGrBhTSHuo3pCTU1a05TyZrdLU1ogm5bs0pSJvfhJNDVpWVMTXbIb NDWp0xTipnLpqdKEVAM2e7P7CHFThiwkRs3Im92nKDVTbnav5gWkm921QDYt2aVmZWSimjXuXK/X mfbfHJlssuH+Nw/x6oNjsuGOl46XjpfWeZHlvqS/B0Xu6+7ctzQ+ZgNUc1/i8O9pTlUTFuSOPpGf KlmK0HLLOcVYTg26p7qOoMFyTomWsx1pffMb8FrSKvFmNkBVWorD0mIR2LBdx1zC9XR2HZd8U+w6 cRlrTr5Jdh2VfB+gXa8/atLeEh6LV32r+gyHPnjL9qvjpeOl42WfnoLaV2wR2FAAWRH4sOcU0a4j isDf2HXt26BRJ8Qat0HXZ0f6t0HvPCEe9mb2mC4txMdrpLV1rY4CDDoTNhOgKRMWoBOzpll21yUi pMw0IyDwVWAUBZIqsAJGfRVYGQRdBdYc5VrTTMVVqwIr8IJf/hVAVavALWhKdiPV02rKMiqqyp8U og0SEyjsyg1CDv5LbKpkxHIvpbuz8jytHXfR9mXKaSqjGgoVOuTQUxqyrfYonAJyX448piErXrio gDyUI1ddARIZ8QtCAxryWI7cpyEjDrRtGvIUIRU1ZD+GTIG70TJR+9y752+gWRqfjLMguqYtHAWC DwYxFxBeyn0e5YEbZoqkxoskhfgsXubXMUCB63Rvme/mLrPs3sCaHm3eAy582usNYZV2vTxOWe+k pyrCdbQggm8r0YbjyXi0FW086k2mpXCDyXd/AVZKy1PX0AAA --=-=-= Content-Type: application/gzip Content-Disposition: attachment; filename=deploy-success.log.gz Content-Transfer-Encoding: base64 H4sICDRQZGMAA2RlcGxveS1zdWNjZXNzLmxvZwDtXWtz2zYW/d5fgcmXdDt+iJREPWY3s3m4TaeN k4kzu+l2MhyahC1OKJIhKT/66wtSlkxxSeLeC9BSO/wSW7F0LnCAA9wHfX0e3TA2ZKYxH43mA4u5 TsyDwGFpuvB+N8eWYX6ZM49frq6NOfNDnnksjdyvPEuZc5XxhHmrOPbD6zkbHrHRd+cYuF8j1wnY DU9SPwpZmiUCh11cvD02TwbH72Meiu/t2YmBQ/3Il1HGWZxEWeRGj/gC9Igl6x+m0VV26yR8+8PA vxRg9uBkdmLhzLnRMnYy+9IJQ57MWRixpZO5i7kCZMyTpRPyMAvu7ZRn9sr35mw2nZ3OpkP2e5xw Z5UtvuAwAz/N7EWUZl/5vZ3dxzydsyR1jtOFYx6PDfNo+0J88oi73uZlKD4Y5/8nYI+5Z47Hxow6 CLGepv3u4if7l7PPP5///ImlYpLawBLucv+Ge1TAr/xuzpzgOkr8bLEUK7tKbngx34KJsaUEnHMv vrsvW9BAaYHtBr4g8vhFysWIE+b68SLfiw5PxduPr93lvyOhJvH5E7Fb2buXr+fsn/4yDnzXz14U Ozjhaa6DOftDbNudd6uMaz2e4xfr8R3EuPhdzN3s4aDZ7h/77PWbt3axizTsxhKa6p5MeL5lolX2 cNqOzNloZk3MmcUuA3EOp8rjPT/77y9nv12oSZGH3g6lZ58/ifn/+F7jKm3GqWu+elbGD3UvjNg/ zItCTv38Sogu/9hxwr+tuDhzrqKk+E+WRFFWSNJ3eXH0uJG4swTN4v5b8mwReSxeXQrx5RMjWney jC/jjA3YleMHKyFf8S0R68PLd7nL4We+E/h/5Jshn8qzfBrPCEjiJi12lHhhf3z7/uITyyL27IeP Z29evv509uYHVcxPn34rEMW7kVCbJbMF/YL7eWkZsnwF46/izti5LOKvYpNdsrM365cXb18KzPmH 04vFh8vpN/9j/D/rTRZc/Wfy+ceXs99e3Z67Z4urOPn22fr2ylmdX0TUNclXN0qcxBeuiRj22jUZ nA7Y9/xf4ss/kGjJfc7eerrF5XjlB5yd5kt8eiI+cpoPUdyWf3DPFj9OcfBXHhuLu5E7hWP53j5/ f/7q1/evf8EKPc2i5HGqfynCTBz+62gVeMKHzVh+1a6Pjec5+HP2CJzbTdnzFqPP5+w8YunKXazH J2Tr+eLAFTze//3I55l7WsPCiVcwtI8tKxnSXLylCFJyG8U8olUomKEfJ9qHV3g9cX41iTjFuc69 W3H4i5Ct8DPEou6+zu6LvXqcuOzOMEo/esrddhg3r6Hh5u1P+YM8aPpTvj/l+1N+z6d84ag74uy+ cTJub0e/iQRCflu8RczFd53ihH94D86MF9mxsxSGXLFq2Vy8OQi4h8NYRiJ4ihJbbIHAsx+ugnnp SioNVAj+8p7FiX8jdvu1eBUnkctT5KjJ5FBvqrPQEToV0KVkkbgKWcBveMCsEyruhjrxYc8Oomux ADmJTHybq9cNohS7GkXAKLZePuC0EKWbcC+nwgmQNMtyD5pzTDi4POkdO3mJoEhex5GYcrHvKFtY tr7I7ZnvTL6vc+csFOzmgH7+zXosQhrrOeW+Yp6jQs5onWG18yyJ7flpnJ/3RIR4lYmTIi9jBHbu F4gFy+sE2xEm+Q/ZaMhuxcazRoPBQFwvd2xoTqwpzuTa1gOu/eAtI6su64Gywbw4VH5/yDQ/YCLF vhmJQNq+YMhrYYPxwNxmeCog25Hk1Zvwq+A9W9CRm1c5Cq/8ZLkxV8GdEHDFipYoYJtwiN9xV7yI g3tWLelJrax5ubzf2Cix00gJELRm7I/Y4mUxbhx0Dmani1XmRbehze8yHnrC+8kvk52t+70/YNGw KKiyY4PdiptFfOHiiyFit/ztX6re6z6ZKm69HejHRV5fj/knx9rB52zhpGsLRyzL7guael708II7 /UeA019iEnL6A/SVM2CATn8g0TunP3F77Z7+SiDbkdSd/hpXWe3071XV89Lz0vPSDS8fNzX6i59/ ev321zfV4AhOa5znesQ/KnPldyLIWooXImKsXR+9BhIecCflqsu/pz2FBC7tmquE8+2jQw8Gj1j4 8I6UVZPdyhGK0XGEYqg6BC0RitEUoUw1RCgGKUKRWKYxBQRt3pfG41lnVuWpDg4563peSLzI7gA4 reU7gDrX+jugtD56DVTvgL/WnqreAYAz6WHXyO6A6pBneqPcMSDKlZiERLkSCFyOU0oBIMoFYrTn OFEgrVEuGpkY5VJw8TlOIC/tWiWSTfEgNGvKOihNwTJHFE0pyaHpSCZpqrZuoPHk7FZTIK9cQVMD VbIJdQPhM3ftlQ/rvXKZZayaJ3I1y0wC1AzhK6fEhKhZTkGNmk0axq6alUC2I6lTMxqZpmboiFE6 g4KCYpeRpR0cELv0vPS89Lx0z4skB4CgtZwDoM5Vlgc29BqQ5AAOfE8NaDc6IAcw1HD37XicJsDj VGHbVHUIWjxOk+hxdqOs8USnskq86TVQVVZ1WYx9PeUjs4z11qcAb11iEuKtA/gCx95yCuSxNxSj NfbGgWBib5VVbvXWgSNGZZqgoKBq83CsHRziZfS89Lz0vHTOi8yngNNa9imoc5VV7AZ6DUie2jjw PYUELu0arLdOufvQ+WEVtptjIyAoJT9sqilL8vEGZf2fKwiEAcfBegzI4mD45BFrDQTFx8ESYEQc XI1apEPGxQ4zQOwgMQmJHYB8gGrh0FVrjR2AGK21cBxIa+yARibGDhRcdC1cj1aJZHdwLiM1NR4c lKZg8ThFU8Rlb4/HSZqqfb4EjbwvTYF8HQVNNT4LpkFTTc+XGMO91cIllrFqNgBqlpiEqBnAV07J EKRmKQU1aq668ECMXTUrgWxHUqdmNDJRzcAR43QGBAXV8KYz7eCQrEDPS89Lz0vnvMhyAHBayzkA 6lzBz8PrMSDLARz2nqoGLMAbHZADGGm4+3Y8ziHE41Rge6jqELR4nEOix9mJsiYD5Kq3K6vEm14D VWVVl2W0t1q4xDLWWzcB3rrEJMRbB/AFj72lFABibyBGe+yNAkHF3gqr3OqtA0eMyzQBQUE1vAly 82mq4fW89Lz0vHTOi8yngNNa9tapcwV3MNBjQFYLP+w9hQRG1MKr3jrl7sPnhxXYbo6NgKCU/PA+ lDUxiBOExsGaDMji4H2uNT4OhvvK2KdM9HY/GwN6X8pMQmIHeK8UQOygofsZFKO9Fq6v+xkamRg7 PEnvSygvuCfCuussY0jbQ+A0BegoKDMJ0RS89wRAU8AOGa3PlwAx2uNxFEjr8yVoZKKmKLh4X0eh L0rzs2BAUMrzJYCuBR3VwvV2eRgDOqfITELUDOzyMAKpmdLloerCk7o8KIFsR1KnZjQyUc1d9F+A gkJqeJNh9elIdXBIVqDnpeel56VzXmQ5ADit5RwAda7Q5+E1GZDlAA57T1XdYXjfJlkOoPprPMqd iEYQj1OB7ZGqQ9DicY6IHmc3yhpV8zNKyirxptdAVVnIZemwFq7ZWwf0ZHtCbx0We2voyUbz1omK J8TeB+itN2ealG+ExxrexNR+3YBqeD0vPS89L53z0o1PQZ0r9PfCNRmQ1cIPe08RvXVALVy7tw7K D+8zNuogP9yNssbEcAQcB+sx0MfBsKdMNMcOkA6wTxc7wGrhe4sdlEBaYwc0clexg5ZauBatEsnu 4FzGagrSp+3vEI8rhdJa4/Ha50sOJh7ft6/T/CxYd393wNxbj3SZZayaAZ1TZCYBaobwlVMyhqhZ TkGNmsc0jF01K4FsR1KnZjQyTc3QEaN0BgUF1fAmE+3ggKxAz0vPS89L97xIcgAIWss5AOpcwc/D 6zEgyQEc+J4a0G50QA7A0nD37XicY4DHqcL2WNUhaPE4x00ep1o/U9nHG5Q1rbqCSv1MS7zpNVBV VnVZ9tYjXT4dlLduAXqyyUxCvHWdPdKhK9oWe0MxWmNvHAgm9lZZ5VZvXUtn2OrBrbG388Sqnt1P 0tu556Xnpeele1668Smoc4X+XrgmA5Ja+IHvKSQwohaOJldHfliF7ebYSL1HemN+eC/Kms10Kqsm DtZjQBYHa/aZAZ1Pn9BnBtWAST4z8SxprQHTfGZIDXh/PrOOGvBeT39CDVi3pgD9yZ5QU1ZnmiJ6 EruaUgLZjqROUzru4ifRlNWxpixVsls0ZTVpCtC5XppVskg1YL2d/i1AxxCZSYiagZ3+JyA1Uzr9 V7P4pE7/SiDbkdSpGY1MVLNCD/5mnSn/DRprGw1PjaqbqQ4OiYZ7Xnpeel4650UW+5L+Phh5rvWx b2l99Bqoxr7E5d/TnqoGLMAb3ZJnlZDuhtzjnEA8TgW2J6oOQYvHOSF6nN0oa0hkrV5ZJd70Gqgq C7ksHdaANXvrgF5kT+itw2JvirdOPMXaY2+Stw6KvQ/QW2/ONCnfCI+1q+kAfXZrqV31vPS89Lx0 zks3PgV1rtAasCYDshrwYe8porcOqAFr99ZB+eF9xkbo/LA1N8cKypJ/vEFZI5MGA46D9RhojYMF qKXXZ5Z2/JSblPrMcghEDRhCgawGDMdoqQFjQeA1YLVVbvaZibjIGjCcF8TpDwdF14D1a0ral+tJ NTXtTFPIOdVrSglkO5I6TaGR96WpaceamqqS3aKpaZOmAB3bpVmlKb4GLLeMVbO0U4bcJETNwA73 M5CaKR3uZzSMXTUrgWxHUqdmNDJRzQq955t1BgRtjlymm2jYGuw2ydQCLo2Ge156XnpenoIXWewL p/Ux9qXPtT72La2PXgPV2Je4/HvaU9WABXijT+VZJQMJLXc5ZxCXU4HumapH0OJyzoguZzfS2u2C pyqtEm96DVSlhVyWrorA+t11aROuJ3XXYcE3xV0nHmPtwTfJXQcF3wforjenmpSvhMGjmzGsZoXV wTt2v3peel56XvbpU1DnCiwC6zLQWgQ++D1FdNcBRWD97jooQ7zP6KiDDHE30pqMdUqrJhLWY0Ax Et58zJBvVkIgkCObyGch4MhDOfKEhjxC/g4/HHmM7JQPRwY8IY6MDzfIE+Tf49aa0UDeP6Xqh/Tw xSF7kbgquBOuYtznPrx8J4al8Mko9cNrWlBTIHjihMhyCDfhHg8z3wlSJKnRMk6EfRatsutIQIlj x7llnpM5zDCN0XR2tH2POIZnw4l5xK4cN4sSNjgZYOW9seaH4ttda8OBORgNdqwZxng0GpfsDaff /Ql8PbPK7eoAAA== --=-=-=-- --==-=-= Content-Type: application/pgp-signature; name="signature.asc" -----BEGIN PGP SIGNATURE----- iIUEARYKAC0WIQRNTknu3zbaMQ2ddzTocYulkRQQdwUCY2RS9g8cbWFyaXVzQGdu dS5vcmcACgkQ6HGLpZEUEHeGbAEAsJskXuHr5Vgs3yLpN7xVoiMuCDmXs3cclgHf 0OYUhgcBALAZhvkMmIjCnT7e/cWeRCyuDUvEIOvC6YIboWDmKbQB =ihvL -----END PGP SIGNATURE----- --==-=-=-- From debbugs-submit-bounces@debbugs.gnu.org Thu Nov 10 05:06:51 2022 Received: (at 58290) by debbugs.gnu.org; 10 Nov 2022 10:06:51 +0000 Received: from localhost ([127.0.0.1]:41951 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1ot4SQ-0007Ir-9I for submit@debbugs.gnu.org; Thu, 10 Nov 2022 05:06:50 -0500 Received: from relay4-d.mail.gandi.net ([217.70.183.196]:53349) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1ot4SN-0007Id-Gf for 58290@debbugs.gnu.org; Thu, 10 Nov 2022 05:06:48 -0500 Received: (Authenticated sender: andrew@trop.in) by mail.gandi.net (Postfix) with ESMTPSA id 84F5CE000F; Thu, 10 Nov 2022 10:06:37 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=trop.in; s=gm1; t=1668074801; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:cc:mime-version:mime-version:content-type:content-type: in-reply-to:in-reply-to:references:references; bh=zmZbfLD4i93CGK3gha5lI+KdcCa4HqSZlxwN1iDFmQg=; b=G1CP2nRJ0VFICM8ExccA0dy9eMSTWBZWlfEiyFYHPg1QYb0Hvbfl/5zuPzpvB9V4DkL8kX 057Rko/6wRPjGuLyHMvhdfux/t0AvHKXKRuAWEZ2PcLbpjwYnBhfdBZj/GBu5L+P3f8wWI XYeMBqTuKdxmybfLRRwlb7Zf5NKjCQtDpOIU/wGiu5fU60JLzohZEJVLnnURuY7q2tQnbV HL9wYAnoyqFFxEA3+yB+u74jtgvO0QbgiVTsvp30A2WhZ+oFDGQjJAESCEMIstzuJ4bUGl Dvs7pp4yz02prxXCR862hb5wrPfdwri2NsrA/HextVaQahCYNfeVmP0fwEdwXw== From: Andrew Tropin To: Marius Bakke , Ludovic =?utf-8?Q?Court=C3=A8s?= Subject: Re: bug#58290: guile ssh error on guix deploy In-Reply-To: <875yfv38jt.fsf@gnu.org> References: <87sfk34zhj.fsf@trop.in> <87bkqm8p5z.fsf@gnu.org> <87o7uec39j.fsf@trop.in> <8735bmsee9.fsf@gnu.org> <87h702uzrb.fsf@gnu.org> <87y1tdkv1d.fsf@gnu.org> <875yfv38jt.fsf@gnu.org> Date: Thu, 10 Nov 2022 14:06:33 +0400 Message-ID: <87h6z75djq.fsf@trop.in> MIME-Version: 1.0 Content-Type: multipart/signed; boundary="=-=-="; micalg=pgp-sha512; protocol="application/pgp-signature" X-Spam-Score: -0.7 (/) X-Debbugs-Envelope-To: 58290 Cc: poptsov.artyom@gmail.com, 58290@debbugs.gnu.org X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -1.7 (-) --=-=-= Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable On 2022-11-04 00:47, Marius Bakke wrote: > Ludovic Court=C3=A8s skriver: > >> Hi, >> >> Marius Bakke skribis: >> >>> I have the same problem. Log messages around failure look something >>> like this (extracted from above message): >>> >>> Oct 4 11:51:49 localhost shepherd[1]: Service sshd-2 has been starte= d.=20 >>> Oct 4 11:51:50 localhost sshd[250]: Accepted publickey for bob from = 185.70.53.164 port 1915 ssh2: RSA SHA256:/X3jyhyMizAOKOjCfXK5cLN3Pa0vmi7dbQ= G+fxK3d3Y >>> Oct 4 11:52:28 localhost sshd[252]: error: no more sessions >>> Oct 4 11:52:28 localhost shepherd[1]: 1 connection still in use afte= r sshd-2 termination.=20 >>> Oct 4 11:52:28 localhost shepherd[1]: Service sshd-2 has been disabl= ed.=20 >>> >>> Then deploy crashes with 'Channel opening failure'. >> >> =E2=80=9Cno more sessions=E2=80=9D comes from this: >> >> --8<---------------cut here---------------start------------->8--- >> int >> session_open(Authctxt *authctxt, int chanid) >> { >> Session *s =3D session_new(); >> debug("session_open: channel %d", chanid); >> if (s =3D=3D NULL) { >> error("no more sessions"); >> return 0; >> } >> >> [...] >> >> } >> --8<---------------cut here---------------end--------------->8--- >> >> Would be interesting to run sshd in verbose/debug mode and see why we >> hit that; it could be because the maximum number of sessions has been >> reached or something. > > I enabled (log-level 'debug) and this is what happens server side: > > Nov 3 21:48:25 capella sshd[26345]: debug1: permanently_set_uid: 0/0 > Nov 3 21:50:27 capella sshd[26115]: debug1: Received SIGCHLD. > Nov 3 21:50:27 capella sshd[26115]: debug1: session_by_pid: pid 26345 > Nov 3 21:50:27 capella sshd[26115]: debug1: session_exit_message: sessio= n 8 channel 8 pid 26345 > Nov 3 21:50:27 capella sshd[26115]: debug1: session_exit_message: releas= e channel 8 > Nov 3 21:50:28 capella sshd[26115]: debug1: server_input_channel_open: c= type session rchan 65 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 0: new [server-sessi= on] > Nov 3 21:50:28 capella sshd[26115]: debug1: session_new: session 0 > Nov 3 21:50:28 capella sshd[26115]: debug1: session_open: channel 0 > Nov 3 21:50:28 capella sshd[26115]: debug1: session_open: session 0: lin= k with channel 0 > Nov 3 21:50:28 capella sshd[26115]: debug1: server_input_channel_open: c= onfirm session > Nov 3 21:50:28 capella sshd[26115]: debug1: server_input_channel_req: ch= annel 0 request exec reply 1 > Nov 3 21:50:28 capella sshd[26115]: debug1: session_by_channel: session = 0 channel 0 > Nov 3 21:50:28 capella sshd[26115]: debug1: session_input_channel_req: s= ession 0 req exec > Nov 3 21:50:28 capella sshd[26535]: debug1: PAM: reinitializing credenti= als > Nov 3 21:50:28 capella sshd[26535]: debug1: permanently_set_uid: 0/0 > Nov 3 21:50:28 capella sshd[26115]: debug1: server_input_channel_open: c= type 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-sess= ion] > 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 ch= annel 10 > Nov 3 21:50:28 capella sshd[26115]: debug1: channel 10: free: server-ses= sion, nchannels 11 > Nov 3 21:50:28 capella sshd[26115]: debug1: server_input_channel_open: f= ailure session > Nov 3 21:50:28 capella sshd[26115]: debug1: channel 0: free: server-sess= ion, nchannels 10 > Nov 3 21:50:28 capella sshd[26115]: debug1: channel 1: free: server-sess= ion, nchannels 9 > Nov 3 21:50:28 capella sshd[26115]: debug1: channel 2: free: server-sess= ion, nchannels 8 > Nov 3 21:50:28 capella sshd[26115]: debug1: channel 3: free: server-sess= ion, nchannels 7 > Nov 3 21:50:28 capella sshd[26115]: debug1: channel 4: free: server-sess= ion, nchannels 6 > Nov 3 21:50:28 capella sshd[26115]: debug1: channel 5: free: server-sess= ion, nchannels 5 > Nov 3 21:50:28 capella sshd[26115]: debug1: channel 6: free: server-sess= ion, nchannels 4 > Nov 3 21:50:28 capella sshd[26115]: debug1: channel 7: free: server-sess= ion, nchannels 3 > Nov 3 21:50:28 capella sshd[26115]: debug1: channel 8: free: server-sess= ion, nchannels 2 > Nov 3 21:50:28 capella sshd[26115]: debug1: channel 9: free: server-sess= ion, nchannels 1 > Nov 3 21:50:28 capella sshd[26115]: debug1: do_cleanup > > I compared this with a successful deploy: > > Nov 3 21:44:22 capella sshd[25842]: debug1: permanently_set_uid: 0/0 > Nov 3 21:46:25 capella sshd[25612]: debug1: Received SIGCHLD. > Nov 3 21:46:25 capella sshd[25612]: debug1: session_by_pid: pid 25842 > Nov 3 21:46:25 capella sshd[25612]: debug1: session_exit_message: sessio= n 6 channel 6 pid 25842 > Nov 3 21:46:25 capella sshd[25612]: debug1: session_exit_message: releas= e channel 6 > Nov 3 21:46:26 capella sshd[25612]: debug1: server_input_channel_open: c= type session rchan 65 win 64000 max 32768 > Nov 3 21:46:26 capella sshd[25612]: debug1: input_session_request > Nov 3 21:46:26 capella sshd[25612]: debug1: channel 0: new [server-sessi= on] > Nov 3 21:46:26 capella sshd[25612]: debug1: session_new: session 0 > Nov 3 21:46:26 capella sshd[25612]: debug1: session_open: channel 0 > Nov 3 21:46:26 capella sshd[25612]: debug1: session_open: session 0: lin= k with channel 0 > Nov 3 21:46:26 capella sshd[25612]: debug1: server_input_channel_open: c= onfirm session > Nov 3 21:46:26 capella sshd[25612]: debug1: server_input_channel_req: ch= annel 0 request exec reply 1 > Nov 3 21:46:26 capella sshd[25612]: debug1: session_by_channel: session = 0 channel 0 > Nov 3 21:46:26 capella sshd[25612]: debug1: session_input_channel_req: s= ession 0 req exec > Nov 3 21:46:26 capella sshd[26032]: debug1: PAM: reinitializing credenti= als > Nov 3 21:46:26 capella sshd[26032]: debug1: permanently_set_uid: 0/0 > Nov 3 21:46:26 capella sshd[25612]: debug1: server_input_channel_open: c= type session rchan 66 win 64000 max 32768 > Nov 3 21:46:26 capella sshd[25612]: debug1: input_session_request > Nov 3 21:46:26 capella sshd[25612]: debug1: channel 8: new [server-sessi= on] > Nov 3 21:46:26 capella sshd[25612]: debug1: session_new: session 8 > Nov 3 21:46:26 capella sshd[25612]: debug1: session_open: channel 8 > Nov 3 21:46:26 capella sshd[25612]: debug1: session_open: session 8: lin= k with channel 8 > Nov 3 21:46:26 capella sshd[25612]: debug1: server_input_channel_open: c= onfirm session > Nov 3 21:46:26 capella sshd[25612]: debug1: server_input_channel_req: ch= annel 8 request exec reply 1 > Nov 3 21:46:26 capella sshd[25612]: debug1: session_by_channel: session = 8 channel 8 > Nov 3 21:46:26 capella sshd[25612]: debug1: session_input_channel_req: s= ession 8 req exec > Nov 3 21:46:26 capella sshd[26043]: debug1: PAM: reinitializing credenti= als > Nov 3 21:46:26 capella sshd[26043]: debug1: permanently_set_uid: 0/0 > Nov 3 21:46:28 capella sshd[25612]: debug1: chan_shutdown_extended_read:= channel 8: (i0 o3 sock -1 wfd -1 efd 13 [read]) > Nov 3 21:46:28 capella sshd[25612]: debug1: server_input_channel_open: c= type session rchan 67 win 64000 max 32768 > Nov 3 21:46:28 capella sshd[25612]: debug1: input_session_request > Nov 3 21:46:28 capella sshd[25612]: debug1: channel 9: new [server-sessi= on] > Nov 3 21:46:28 capella sshd[25612]: debug1: session_new: session 9 > [... more channels and stuffs before graceful shutdown ...] > > I believe the two-minute window before SIGCHLD is waiting for some > Shepherd services to time out (long story..!). > > In my current tests the failure always occur at the > very end of deploy: > > building /gnu/store/19yajyzw4jhnkkz9w0l9gm4az0jxihkc-install-bootloader.s= cm.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: # > > 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. > > I have attached the transcripts of each session (by grepping the PIDs > from /var/log/debug). Grepping for session_open yields some > inconstencies, but haven't studied them in detail yet. > >>> Due to the number of SSH connections made by deploy and frequent >>> occurence of this problem, I was not able to successfully deploy through >>> many attempts. >> >> Ouch. Normally, thanks to memoization, =E2=80=98guix deploy=E2=80=99 op= ens only one >> session per machine. (I think it works well with the 25 local build >> machines behind berlin; it=E2=80=99s also fine for a small set of machin= es I >> take care of at work.) > > Have they been rebooted since the switch to inetd-style sshd? It fails > more often than not for me. > >>> I found that removing the memoizing open-machine-ssh-session* in >>> (gnu machine ssh) works around it and can happily deploy again. >>> >>> (that is, just use 'open-machine-ssh-session' instead) >> >> Interesting. That gives us a hint. Could you add a =E2=80=98pk=E2=80= =99 in >> =E2=80=98open-machine-ssh-session*=E2=80=99 to see how many connections = it opens? > > Indeed it only opens a single connection. The problem seems to be > with multiple "channels" and "sessions" over a single connection. > Very detailed report, thank you for digging in! CCed Artyom Poptsov, author of Guile-SSH. =2D-=20 Best regards, Andrew Tropin --=-=-= Content-Type: application/pgp-signature; name="signature.asc" -----BEGIN PGP SIGNATURE----- iQIzBAEBCgAdFiEEKEGaxlA4dEDH6S/6IgjSCVjB3rAFAmNszSoACgkQIgjSCVjB 3rC+bBAAgcU8svGJMtm7hzefZHQfH0cs2XP/6VFd5ae5AqpQ4Kw2ZENvED+eSIdv BuzmsdXhLwLGITEFJdhyROrDlKtz85IwCsl9NXrWrOa0cNVW9bD9ibqjKnNcCMP8 jMjdoGxo2Khj6DAMdma9l1G7BfJrutTHvxid3MrmnSk3ZEQLK0haEKkkifK7vogq l1s1sLicEyx+9ux4BweZoGbIwuXVl7/dwiRNyS/02xE+8S8YR4dTuOFMoAH5P7Hy 2GlQyif9jyZji58msLhbfwu4WmZf0yiVRIDzjoNA5YtT8ZCJ/0auOCihtQi1ri2o Nwaf44LywmadtO7RpXnp4rVyxvXV3SYcgXajDFyMAZxvKEHqIc8pUkvpcdS/RfkR KLkCOY03Xlf52F8Ien3+9g6zLibDqaXXgUF9GNVfg7FqaxVH2LlTc0EUcBIL7oiQ /TvddMtklO+nMXfVx9OBIiI5RgwT0eW93nxSOO0Ouh2nh9jJDLuD9oQoyeudd/w4 rD0LkWlBSOSqi+8bJ4QkpmbMLELoEIi9IiNa/HpH0W3q8H5DFWLtkZ70XRlMxcky IunQA1sQDXfSBMPWzH798ESk9RfIxwTSdIKdXG3Y02kd4PFIjjvUoSjqUjZ3jDLB 6n6lwWUUZCCxvm3U/WRSOqGCtvJAxZaoTJnuq/aIFw7dr4/LQmI= =/h8b -----END PGP SIGNATURE----- --=-=-=-- From debbugs-submit-bounces@debbugs.gnu.org Thu Jan 12 06:10:35 2023 Received: (at control) by debbugs.gnu.org; 12 Jan 2023 11:10:35 +0000 Received: from localhost ([127.0.0.1]:44823 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1pFvTf-00017y-6Z for submit@debbugs.gnu.org; Thu, 12 Jan 2023 06:10:35 -0500 Received: from mail3-relais-sop.national.inria.fr ([192.134.164.104]:47808) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1pFvTd-00017h-4X for control@debbugs.gnu.org; Thu, 12 Jan 2023 06:10:33 -0500 Authentication-Results: mail3-relais-sop.national.inria.fr; dkim=none (message not signed) header.i=none; spf=SoftFail smtp.mailfrom=ludo@gnu.org; dmarc=fail (p=none dis=none) d=gnu.org X-IronPort-AV: E=Sophos;i="5.96,319,1665439200"; d="scan'208";a="44862937" Received: from 91-160-117-201.subs.proxad.net (HELO ribbon) ([91.160.117.201]) by mail3-relais-sop.national.inria.fr with ESMTP/TLS/ECDHE-RSA-AES256-GCM-SHA384; 12 Jan 2023 12:10:27 +0100 Date: Thu, 12 Jan 2023 12:10:27 +0100 Message-Id: <874jswhuu4.fsf@gnu.org> To: control@debbugs.gnu.org From: =?utf-8?Q?Ludovic_Court=C3=A8s?= Subject: control message for bug #58290 MIME-version: 1.0 Content-type: text/plain; charset=utf-8 Content-Transfer-Encoding: 8bit X-Spam-Score: 1.0 (+) X-Debbugs-Envelope-To: control X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -0.0 (/) severity 58290 important quit From debbugs-submit-bounces@debbugs.gnu.org Thu Jan 12 06:10:55 2023 Received: (at control) by debbugs.gnu.org; 12 Jan 2023 11:10:55 +0000 Received: from localhost ([127.0.0.1]:44826 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1pFvTz-00018a-Di for submit@debbugs.gnu.org; Thu, 12 Jan 2023 06:10:55 -0500 Received: from mail3-relais-sop.national.inria.fr ([192.134.164.104]:47826) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1pFvTx-00018K-Bh for control@debbugs.gnu.org; Thu, 12 Jan 2023 06:10:53 -0500 Authentication-Results: mail3-relais-sop.national.inria.fr; dkim=none (message not signed) header.i=none; spf=SoftFail smtp.mailfrom=ludo@gnu.org; dmarc=fail (p=none dis=none) d=gnu.org X-IronPort-AV: E=Sophos;i="5.96,319,1665439200"; d="scan'208";a="44862972" Received: from 91-160-117-201.subs.proxad.net (HELO ribbon) ([91.160.117.201]) by mail3-relais-sop.national.inria.fr with ESMTP/TLS/ECDHE-RSA-AES256-GCM-SHA384; 12 Jan 2023 12:10:48 +0100 Date: Thu, 12 Jan 2023 12:10:47 +0100 Message-Id: <87358ghutk.fsf@gnu.org> To: control@debbugs.gnu.org From: =?utf-8?Q?Ludovic_Court=C3=A8s?= Subject: control message for bug #58290 MIME-version: 1.0 Content-type: text/plain; charset=utf-8 Content-Transfer-Encoding: 8bit X-Spam-Score: 1.0 (+) X-Debbugs-Envelope-To: control X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -0.0 (/) merge 58290 56709 quit From debbugs-submit-bounces@debbugs.gnu.org Thu Jan 12 07:11:37 2023 Received: (at 58290) by debbugs.gnu.org; 12 Jan 2023 12:11:38 +0000 Received: from localhost ([127.0.0.1]:44911 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1pFwQj-0005AL-GX for submit@debbugs.gnu.org; Thu, 12 Jan 2023 07:11:37 -0500 Received: from eggs.gnu.org ([209.51.188.92]:56958) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1pFwQf-0005A7-UC for 58290@debbugs.gnu.org; Thu, 12 Jan 2023 07:11:36 -0500 Received: from fencepost.gnu.org ([2001:470:142:3::e]) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1pFwQa-0005X1-0f; Thu, 12 Jan 2023 07:11:28 -0500 DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=gnu.org; s=fencepost-gnu-org; h=MIME-Version:In-Reply-To:Date:References:Subject:To: From; bh=+JB/40Dw4tJ7j69KWGMA4qoIJEbtB3r/LvlzM+C57xY=; b=UPcB5UpqPyCEdZtjwAqA qyn0MH5bapKC7fopEnBEFyL03rDl9v2D2kUrDgG0xO1VjTqIRG1e/0W7TlY3Q6YmOL30o3Dj3vWn3 hiIBwTJLKXfF7p93pc68CtIbFjuo9UKg/o33SZl4K6+QQJFTNY9Pd2uUh5PLpNbpLdBF8JMBv8UeA sXjNb6Q7mUH1kIkH4P7jxSbZsY9HgzCYHo2a/VlG2sbZPd3BM/hArSE2Mx2zStpiT0cuLAZvsH32n TpdalHuQeYsv4umDlQX8DF5CoL4AXLaFR8H5PMGnvGO1jQluT8xVQUDnr9JTJgI2wIK1UJHShFyJ2 SUosymFcIxNVzw==; Received: from 91-160-117-201.subs.proxad.net ([91.160.117.201] helo=ribbon) by fencepost.gnu.org with esmtpsa (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1pFwQZ-0004DR-AT; Thu, 12 Jan 2023 07:11:27 -0500 From: =?utf-8?Q?Ludovic_Court=C3=A8s?= To: Marius Bakke Subject: Re: bug#58290: guile ssh error on guix deploy References: <87sfk34zhj.fsf@trop.in> <87bkqm8p5z.fsf@gnu.org> <87o7uec39j.fsf@trop.in> <8735bmsee9.fsf@gnu.org> <87h702uzrb.fsf@gnu.org> <87y1tdkv1d.fsf@gnu.org> <875yfv38jt.fsf@gnu.org> Date: Thu, 12 Jan 2023 13:11:24 +0100 In-Reply-To: <875yfv38jt.fsf@gnu.org> (Marius Bakke's message of "Fri, 04 Nov 2022 00:47:02 +0100") Message-ID: <87v8lcgdg3.fsf@gnu.org> User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/28.2 (gnu/linux) MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-Spam-Score: -2.3 (--) X-Debbugs-Envelope-To: 58290 Cc: "Artyom V. Poptsov" , 58290@debbugs.gnu.org, Andrew Tropin X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -3.3 (---) Hi, Marius Bakke skribis: > Nov 3 21:50:28 capella sshd[26115]: debug1: server_input_channel_open: c= type 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-sess= ion] > 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 ch= annel 10 > Nov 3 21:50:28 capella sshd[26115]: debug1: channel 10: free: server-ses= sion, nchannels 11 > Nov 3 21:50:28 capella sshd[26115]: debug1: server_input_channel_open: f= ailure session > Nov 3 21:50:28 capella sshd[26115]: debug1: channel 0: free: server-sess= ion, nchannels 10 > Nov 3 21:50:28 capella sshd[26115]: debug1: channel 1: free: server-sess= ion, nchannels 9 > Nov 3 21:50:28 capella sshd[26115]: debug1: channel 2: free: server-sess= ion, nchannels 8 > Nov 3 21:50:28 capella sshd[26115]: debug1: channel 3: free: server-sess= ion, nchannels 7 > Nov 3 21:50:28 capella sshd[26115]: debug1: channel 4: free: server-sess= ion, nchannels 6 [...] > In my current tests the failure always occur at the > very end of deploy: > > building /gnu/store/19yajyzw4jhnkkz9w0l9gm4az0jxihkc-install-bootloader.s= cm.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: # > > 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=E2=80=99s 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-coreuti= ls-8.32") %remote) (loop (+ 1 i))) --8<---------------cut here---------------end--------------->8--- It fails after 8 iterations. It looks like we=E2=80=99re leaking SSH chann= els or something. However, in GDB, we can see that =E2=80=98ssh_channel_close=E2=80=99 is ind= eed called after each iteration (via =E2=80=98ptob_close=E2=80=99 in Guile-SSH). Artyom, does that ring a bell? Thanks, Ludo=E2=80=99. From debbugs-submit-bounces@debbugs.gnu.org Thu Jan 12 07:44:56 2023 Received: (at 58290) by debbugs.gnu.org; 12 Jan 2023 12:44:56 +0000 Received: from localhost ([127.0.0.1]:44947 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1pFwwy-0000Bl-EY for submit@debbugs.gnu.org; Thu, 12 Jan 2023 07:44:56 -0500 Received: from eggs.gnu.org ([209.51.188.92]:38372) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1pFwww-0000BL-LI for 58290@debbugs.gnu.org; Thu, 12 Jan 2023 07:44:55 -0500 Received: from fencepost.gnu.org ([2001:470:142:3::e]) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1pFwwq-00040W-Ls; Thu, 12 Jan 2023 07:44:48 -0500 DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=gnu.org; s=fencepost-gnu-org; h=MIME-Version:In-Reply-To:Date:References:Subject:To: From; bh=ShvL+o9jdXAbV+Lo/SYvAWqENClSdFQ6w5ar4H2wDKw=; b=LQWB3plYKpKuYwOk0sbt GzDNO/rHRhilIjMNxsfMPMjOZXtc3ZKNU4hfO9SVpneY0ncN2/URuFQPTM5m/cOX3hPyEz9YM6yF6 V24EFES/yz4ZHGorp/P7YOhl38/v4VIvB3/uOWQPxEpnXUpzlnqTM5O+A+XcWYJec7WhUgKh1w70A HuZjtDbgEg3FNcXpHW4kRf1ZEw4kC16VLPBbeVhKfsfafZaCHYbad2pDXSYYDONXKjTBaN4KQvO/R Py05yqN55wMfoRGBV/ShFAnxghxIy6dQ7l6C1Z7Lx2lLs1tSeJES3mq08giN+43AcURR2py4h9aqc GTDFYpht55GsQQ==; Received: from 91-160-117-201.subs.proxad.net ([91.160.117.201] helo=ribbon) by fencepost.gnu.org with esmtpsa (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1pFwwq-0004uA-1M; Thu, 12 Jan 2023 07:44:48 -0500 From: =?utf-8?Q?Ludovic_Court=C3=A8s?= To: Marius Bakke Subject: Re: bug#58290: guile ssh error on guix deploy References: <87sfk34zhj.fsf@trop.in> <87bkqm8p5z.fsf@gnu.org> <87o7uec39j.fsf@trop.in> <8735bmsee9.fsf@gnu.org> <87h702uzrb.fsf@gnu.org> <87y1tdkv1d.fsf@gnu.org> <875yfv38jt.fsf@gnu.org> <87v8lcgdg3.fsf@gnu.org> Date: Thu, 12 Jan 2023 13:44:45 +0100 In-Reply-To: <87v8lcgdg3.fsf@gnu.org> ("Ludovic =?utf-8?Q?Court=C3=A8s=22'?= =?utf-8?Q?s?= message of "Thu, 12 Jan 2023 13:11:24 +0100") Message-ID: <87o7r3hqgy.fsf@gnu.org> User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/28.2 (gnu/linux) MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-Spam-Score: -2.3 (--) X-Debbugs-Envelope-To: 58290 Cc: "Artyom V. Poptsov" , 58290@debbugs.gnu.org, Andrew Tropin X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -3.3 (---) A simpler reproducer: --8<---------------cut here---------------start------------->8--- (use-modules (ssh session) (ssh popen) (ssh auth) (rnrs io ports)) (define session (make-session #:host "HOST-OF-YOUR-CHOICE")) (session-parse-config! session) (connect! session) (userauth-public-key/auto! session) (let loop ((i 0)) (pk 'loOp i) (let ((pipe (open-remote-pipe session "date" "r"))) (pk 'x (get-string-all pipe)) (close-port pipe) (loop (+ 1 i)))) --8<---------------cut here---------------end--------------->8--- Ludo=E2=80=99. From debbugs-submit-bounces@debbugs.gnu.org Sun Jan 22 15:00:37 2023 Received: (at 58290) by debbugs.gnu.org; 22 Jan 2023 20:00:37 +0000 Received: from localhost ([127.0.0.1]:52676 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1pJgW4-0005KB-Oo for submit@debbugs.gnu.org; Sun, 22 Jan 2023 15:00:37 -0500 Received: from mail-ej1-f48.google.com ([209.85.218.48]:41537) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1pJgW1-0005Jw-7E for 58290@debbugs.gnu.org; Sun, 22 Jan 2023 15:00:35 -0500 Received: by mail-ej1-f48.google.com with SMTP id u19so25719561ejm.8 for <58290@debbugs.gnu.org>; Sun, 22 Jan 2023 12:00:33 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20210112; h=mime-version:user-agent:message-id:in-reply-to:date:references :subject:cc:to:from:from:to:cc:subject:date:message-id:reply-to; bh=dQsADPl5Q+JLBft+ZothL1cfkmqZ2cQ4Ffj66BpVW64=; b=KYv/VXX38MqwHU/H/sbJhTnM8N4tmux7TRCzYtY4RlNlAub8iBTbW/TD95dKLC276+ cJkX6xxrU3FrMM29ES2zYvgHeg6vH2t56SHCz9bcX1GTsMPuY+dj+vmykjrohnaYhaJo 9zo1qnF3xax5Cg3UmFEBKXeJus7s8ULMb92pQPDKlo58eX95Y+KZiibKXrgVCt9y6uWM WdfTu7otC4JvxYn2R2m5lEeXz+LR5H+gkLz0D/7TVPiZPti8n5dlpXI4JsI6ExnAi461 yo2w3OXrEQob0wZYua9HmwR6LDlcgm7KBpyC/xItT6BF+wgdQJUU2etPSvdwDW6XvEd/ sX/g== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=mime-version:user-agent:message-id:in-reply-to:date:references :subject:cc:to:from:x-gm-message-state:from:to:cc:subject:date :message-id:reply-to; bh=dQsADPl5Q+JLBft+ZothL1cfkmqZ2cQ4Ffj66BpVW64=; b=ah3QD85jq83gI0GscEpFF8fQtDoEubNFxwFLXHONvjMFyMVxgnfmzo05fBEIGfvQLb v0AFSWFkAk7VnyIGkvdzUnb2e4H8hOGtH6mqugwAuizq8BqLUoMmw3Q0PeBcXoJrzt2P mW5hN/wC7UOYjFREoJPGTrAUId7xHuEBHiBrRYqsm7Wx7feCT3PbAmVcC9QxBrlrcC3H /vF0Qh3jl7yuZaL3eEu4qVeIbXSX/rwfDOLyMRpS4SVdl0zmuHJpo7wI+qcnoVIg6V/p 82TndOSQl6vz94jvEz+cQadZhrWlf/5dbKDUHtnNsmIgs4GqGncdLIIQt1nUgX2D1SE7 pwGQ== X-Gm-Message-State: AFqh2kruAqxkBgv5oNNFkV9cIZrFWHp+7UXZ+TrEy9+EyrJV8xNavTks sT4tyObdAk6e2cNFVZNKm1E= X-Google-Smtp-Source: AMrXdXuREUmyczBdgV7lbicScEawChne4z+BoOzrqPX6uxHiZTd3o10TiVtIwtPo0Nwll/Bg4BCc7w== X-Received: by 2002:a17:907:8b08:b0:860:c12c:14fd with SMTP id sz8-20020a1709078b0800b00860c12c14fdmr26130094ejc.76.1674417627026; Sun, 22 Jan 2023 12:00:27 -0800 (PST) Received: from elephant ([95.79.5.207]) by smtp.gmail.com with ESMTPSA id ky16-20020a170907779000b007bd0bb6423csm21087810ejc.199.2023.01.22.12.00.25 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Sun, 22 Jan 2023 12:00:26 -0800 (PST) From: "Artyom V. Poptsov" To: Ludovic =?utf-8?Q?Court=C3=A8s?= Subject: Re: bug#58290: guile ssh error on guix deploy References: <87sfk34zhj.fsf@trop.in> <87bkqm8p5z.fsf@gnu.org> <87o7uec39j.fsf@trop.in> <8735bmsee9.fsf@gnu.org> <87h702uzrb.fsf@gnu.org> <87y1tdkv1d.fsf@gnu.org> <875yfv38jt.fsf@gnu.org> <87v8lcgdg3.fsf@gnu.org> <87o7r3hqgy.fsf@gnu.org> Date: Sun, 22 Jan 2023 23:00:20 +0300 In-Reply-To: <87o7r3hqgy.fsf@gnu.org> ("Ludovic =?utf-8?Q?Court=C3=A8s=22'?= =?utf-8?Q?s?= message of "Thu, 12 Jan 2023 13:44:45 +0100") Message-ID: <87zgaaz6ej.fsf@gmail.com> User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/28.2 (gnu/linux) MIME-Version: 1.0 Content-Type: multipart/signed; boundary="=-=-="; micalg=pgp-sha512; protocol="application/pgp-signature" X-Spam-Score: 0.2 (/) X-Debbugs-Envelope-To: 58290 Cc: 58290@debbugs.gnu.org, Andrew Tropin , Marius Bakke X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -0.8 (/) --=-=-= Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable Hello Ludovic, Andrew and all, thank you for reporting the bug! The code for reproducing the bug was very helpful indeed, I just slightly modified the it: =2D-8<---------------cut here---------------start------------->8--- (use-modules (ssh session) (ssh popen) (ssh auth) (ssh log) (rnrs io ports)) (define session (make-session #:host "localhost")) (define (main args) (session-parse-config! session) (connect! session) (userauth-public-key/auto! session) (set-log-verbosity! 'functions) (let loop ((i 0)) (format (current-error-port) "-- ~a --~%" i) (let ((pipe (open-remote-pipe session "date" "r"))) (pk 'x (get-string-all pipe)) (close-port pipe) (loop (+ 1 i))))) =2D-8<---------------cut here---------------end--------------->8--- It seems to me that the reason Guile-SSH fails at least partly lies in changes that were introduced in OpenSSH 5.1. I set "LogLevel" to "DEBUG3" and ran the test code. System logs have shown the following error: =2D-8<---------------cut here---------------start------------->8--- =D1=8F=D0=BD=D0=B2 22 22:40:06 elephant sshd[131488]: debug3: channel 8: wi= ll not send data after close =D1=8F=D0=BD=D0=B2 22 22:40:06 elephant sshd[131488]: debug3: channel 9: wi= ll not send data after close =D1=8F=D0=BD=D0=B2 22 22:40:06 elephant sshd[131488]: debug2: channel 9: rc= vd adjust 1216033 =D1=8F=D0=BD=D0=B2 22 22:40:06 elephant sshd[131488]: debug3: channel 0: wi= ll not send data after close =D1=8F=D0=BD=D0=B2 22 22:40:06 elephant sshd[131488]: debug3: channel 1: wi= ll not send data after close =D1=8F=D0=BD=D0=B2 22 22:40:06 elephant sshd[131488]: debug3: channel 2: wi= ll not send data after close =D1=8F=D0=BD=D0=B2 22 22:40:06 elephant sshd[131488]: debug3: channel 3: wi= ll not send data after close =D1=8F=D0=BD=D0=B2 22 22:40:06 elephant sshd[131488]: debug3: channel 4: wi= ll not send data after close =D1=8F=D0=BD=D0=B2 22 22:40:06 elephant sshd[131488]: debug3: channel 5: wi= ll not send data after close =D1=8F=D0=BD=D0=B2 22 22:40:06 elephant sshd[131488]: debug3: channel 6: wi= ll not send data after close =D1=8F=D0=BD=D0=B2 22 22:40:06 elephant sshd[131488]: debug3: channel 7: wi= ll not send data after close =D1=8F=D0=BD=D0=B2 22 22:40:06 elephant sshd[131488]: debug3: channel 8: wi= ll not send data after close =D1=8F=D0=BD=D0=B2 22 22:40:06 elephant sshd[131488]: debug3: channel 9: wi= ll not send data after close =D1=8F=D0=BD=D0=B2 22 22:40:06 elephant sshd[131488]: debug3: receive packe= t: type 90 =D1=8F=D0=BD=D0=B2 22 22:40:06 elephant sshd[131488]: debug1: server_input_= channel_open: ctype session rchan 53 win 64000 max 32768 =D1=8F=D0=BD=D0=B2 22 22:40:06 elephant sshd[131488]: debug1: input_session= _request =D1=8F=D0=BD=D0=B2 22 22:40:06 elephant sshd[131488]: debug2: channel: expa= nding 20 =D1=8F=D0=BD=D0=B2 22 22:40:06 elephant sshd[131488]: debug1: channel 10: n= ew [server-session] =D1=8F=D0=BD=D0=B2 22 22:40:06 elephant sshd[131488]: debug1: session_open:= channel 10 =D1=8F=D0=BD=D0=B2 22 22:40:06 elephant sshd[131488]: error: no more sessio= ns =2D-8<---------------cut here---------------end--------------->8--- This "no more sessions" error was the key to understanding the problem. Here's an excerpt from OpenSSH 5.1 changelog [1]: =2D-8<---------------cut here---------------start------------->8--- Changes since OpenSSH 5.0 =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D [...] * Added a MaxSessions option to sshd_config(5) to allow control of the number of multiplexed sessions supported over a single TCP connection. This allows increasing the number of allowed sessions above the previous default of 10, disabling connection multiplexing=20 (MaxSessions=3D1) or disallowing login/shell/subsystem sessions entirely (MaxSessions=3D0). =2D-8<---------------cut here---------------end--------------->8--- When I set "MaxSessions" in "/etc/ssh/sshd_config" to 100 and restarted the sshd daemon, the test code fails on the 100th iteration. =2D-8<---------------cut here---------------start------------->8--- [...] ;;; [2023/01/22 22:52:03.246549, 3] ssh_packet_need_rekey: rekey: [data_rek= ey_needed=3D0, out_blocks=3D817, in_blocks=3D1309] ;;; [2023/01/22 22:52:03.246559, 3] ssh_packet_socket_callback: rcv packet = cb (len=3D0, state=3DINIT) ;;; [2023/01/22 22:52:03.246568, 3] ssh_packet_socket_callback: Waiting for= more data (0 < 4) ;;; [2023/01/22 22:52:03.246579, 4] ssh_socket_pollcallback: sending contro= l flow event ;;; [2023/01/22 22:52:03.246587, 4] ssh_packet_socket_controlflow_callback:= sending channel_write_wontblock callback ;;; [2023/01/22 22:52:03.246600, 4] [GSSH DEBUG] read result: 0: # ;;; (x "=D0=92=D1=81 22 =D1=8F=D0=BD=D0=B2 2023 22:52:03 MSK\n") ;;; [2023/01/22 22:52:03.246636, 4] [GSSH DEBUG] the channel is already fre= ed by the closing request from the remote side. =2D- 100 -- ;;; [2023/01/22 22:52:03.246655, 2] channel_open: Creating a channel 143 wi= th 64000 window and 32768 max packet ;;; [2023/01/22 22:52:03.246664, 3] ssh_packet_need_rekey: rekey: [data_rek= ey_needed=3D0, out_blocks=3D820, in_blocks=3D1312] ;;; [2023/01/22 22:52:03.246693, 3] ssh_socket_unbuffered_write: Enabling P= OLLOUT for socket ;;; [2023/01/22 22:52:03.246703, 3] packet_send2: packet: wrote [type=3D90,= len=3D32, padding_size=3D7, comp=3D24, payload=3D24] ;;; [2023/01/22 22:52:03.246712, 3] channel_open: Sent a SSH_MSG_CHANNEL_OP= EN type session for channel 143 ;;; [2023/01/22 22:52:03.246721, 4] ssh_socket_pollcallback: Poll callback = on socket 10 (POLLOUT ), out buffer 0 ;;; [2023/01/22 22:52:03.246732, 4] ssh_socket_pollcallback: sending contro= l flow event ;;; [2023/01/22 22:52:03.246741, 4] ssh_packet_socket_controlflow_callback:= sending channel_write_wontblock callback ;;; [2023/01/22 22:52:03.247437, 4] ssh_socket_pollcallback: Poll callback = on socket 10 (POLLIN ), out buffer 0 ;;; [2023/01/22 22:52:03.247449, 3] ssh_packet_socket_callback: rcv packet = cb (len=3D60, state=3DINIT) ;;; [2023/01/22 22:52:03.247462, 3] ssh_packet_socket_callback: packet: rea= d type 92 [len=3D40,padding=3D11,comp=3D28,payload=3D28] ;;; [2023/01/22 22:52:03.247473, 3] ssh_packet_incoming_filter: Filtering p= acket type 92 ;;; [2023/01/22 22:52:03.247484, 3] ssh_packet_process: Dispatching handler= for packet type 92 ;;; [2023/01/22 22:52:03.247496, 1] ssh_packet_channel_open_fail: Channel o= pening failure: channel 143 error (2) open failed ;;; [2023/01/22 22:52:03.247506, 3] ssh_packet_need_rekey: rekey: [data_rek= ey_needed=3D0, out_blocks=3D820, in_blocks=3D1312] ;;; [2023/01/22 22:52:03.247518, 3] ssh_packet_socket_callback: rcv packet = cb (len=3D0, state=3DINIT) ;;; [2023/01/22 22:52:03.247531, 3] ssh_packet_socket_callback: Waiting for= more data (0 < 4) ;;; [2023/01/22 22:52:03.247545, 4] [GSSH DEBUG] result: -1: # ;;; [2023/01/22 22:52:03.247570, 0] [GSSH ERROR] Channel opening failure: c= hannel 143 error (2) open failed: # Backtrace: In ice-9/boot-9.scm: 1752:10 6 (with-exception-handler _ _ #:unwind? _ # _) In unknown file: 5 (apply-smob/0 #) In ice-9/boot-9.scm: 724:2 4 (call-with-prompt _ _ #) In ice-9/eval.scm: 619:8 3 (_ #(#(#))) In /home/avp/src/projects/guile-ssh/./test.scm: 22:16 2 (main _) In ssh/popen.scm: 64:4 1 (open-remote-pipe _ "date" "r") In unknown file: 0 (channel-open-session #) ERROR: In procedure channel-open-session: Throw to key `guile-ssh-error' with args `("channel-open-session" "Channel = opening failure: channel 143 error (2) open failed" # #f)'. =2D-8<---------------cut here---------------end--------------->8--- I'm not sure if I should deal with this "MaxSessions" error in Guile-SSH code; and if so, what the right thing to do on the Guile-SSH side? I'd love to hear your opinions on that. Thanks, =2D avp References: 1. https://www.openssh.com/txt/release-5.1 =2D-=20 Artyom "avp" Poptsov Home page: https://memory-heap.org/~avp/ CADR Hackerspace co-founder: https://cadrspace.ru/ GPG: D0C2 EAC1 3310 822D 98DE B57C E9C5 A2D9 0898 A02F --=-=-= Content-Type: application/pgp-signature; name="signature.asc" -----BEGIN PGP SIGNATURE----- iQFNBAEBCgA3FiEE0MLqwTMQgi2Y3rV86cWi2QiYoC8FAmPNldQZHHBvcHRzb3Yu YXJ0eW9tQGdtYWlsLmNvbQAKCRDpxaLZCJigLxVnB/45HlrG3M7wGz+x0XBvHmOr Tyy0U+fX7cAsLod5yvLrtDg92X+LW1qoeMEaVKuxhIBerMuR/fvimT9arOHs7TgH soCLEeyaY1YdtPwU5hSRMfgtK4IzW3wltAfJJSCCXXhh+uvuUMeVHIDgtCUT+wlB eWHlHhm2XViQWer2Shr0p2Wvt2QxGGPHteamzO4J8yCmoVa0qCWZWMp0kbHWfBFE /4s7NyxKcNjA5M0XBjSBQTiAL+gcQzPq5VVmiUuz1fNLbROSo8Pau7rafHJ9zrqF n4p3prHojGIL6Gzuju/JT52YfWzhbLksu2fbJXMX2TeKFvKXg22JOe3J0zrlT79b =RAfK -----END PGP SIGNATURE----- --=-=-=-- From debbugs-submit-bounces@debbugs.gnu.org Mon Jan 23 15:14:47 2023 Received: (at 58290) by debbugs.gnu.org; 23 Jan 2023 20:14:47 +0000 Received: from localhost ([127.0.0.1]:55402 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1pK3DK-0003T0-Ny for submit@debbugs.gnu.org; Mon, 23 Jan 2023 15:14:46 -0500 Received: from mail-ed1-f48.google.com ([209.85.208.48]:41496) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1pK3DJ-0003Sk-6U for 58290@debbugs.gnu.org; Mon, 23 Jan 2023 15:14:45 -0500 Received: by mail-ed1-f48.google.com with SMTP id v10so15986026edi.8 for <58290@debbugs.gnu.org>; Mon, 23 Jan 2023 12:14:45 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20210112; h=mime-version:user-agent:message-id:in-reply-to:date:references :subject:cc:to:from:from:to:cc:subject:date:message-id:reply-to; bh=mamQzfARBJdhG+t1pEZSL373OEt/trc8Qprw1IJRT/U=; b=n8N8H9luitJnbBP1HApkpLVk7cWXFdg0ESoFJkd0dH1mN7CSjbp+v8idlg4370ozFK anwp0x3xIxgIB8CdqZ5MtivTqXCNit/IKpaOr8ebbsi/PBq9zQYegOp/nWDhuL/1C/AT 5ZFzYzCShvEnqXSf1dFzvS10OebvF2RfN6cc+r3qY4fq46uCMxiNNq4LwyxBW+6D0LIW +cZxAHPbjKiJ7FIrPR0zWlfLqGti48lxR8bz+Xz51lhwPUuWGeXtnjpMKSyaaRZy0+ox v3WyhBHJNo5oW53ZwV312Ts09+ZWK1QSdGUxAQI0anoYofeAyhu6XkrYfiMqFyelT7/a Fhsg== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=mime-version:user-agent:message-id:in-reply-to:date:references :subject:cc:to:from:x-gm-message-state:from:to:cc:subject:date :message-id:reply-to; bh=mamQzfARBJdhG+t1pEZSL373OEt/trc8Qprw1IJRT/U=; b=kmH4468MiQVfvD1mkgYbfSqbTVblGKFU3cRcFMj2Os3qbSAsCXfoZ/8MDSrhJ5HKiY tNMRqkcEeAAlHQGMkz0s9Dq6hX7IVNt3cyXx+QbxhZDsox9WzH4jfNu7usweea+OJH+G l9XKSG7Z9+TDGyJJJmDzr6+IH/oF/mW7WI0tyWkFGI9BgE06ALbX+QiJoZJxJHSncsU2 8toEP3Kz5y4nNULhv7ymJQiqrhxgaAludMf56exNIYmGDyviokyaHL/gZl4A5EO9DHvE TVXdQzW6LXwa7Ann+/uBQQed3LyfgHUBb8oDhdLDKiN4xgy7EHiy6Pp35opF9GcocDie 5BBQ== X-Gm-Message-State: AFqh2koBDaai/hXxm3SydJ9/8Mm8K/c2/bHOMEunbj6TEOu9jrm6B2t3 aoI12r2vWRZSY4LLfTNlBpU= X-Google-Smtp-Source: AMrXdXu97t1Q4ZTsuO19eCsXrNi9rEWyK3oxnm4fA1kqpPe76sXl4+KtxRn9RWI99vxeCzfpcE003g== X-Received: by 2002:a05:6402:25c9:b0:49e:ed53:d64f with SMTP id x9-20020a05640225c900b0049eed53d64fmr14095350edb.9.1674504879107; Mon, 23 Jan 2023 12:14:39 -0800 (PST) Received: from elephant ([95.79.5.207]) by smtp.gmail.com with ESMTPSA id q28-20020a056402033c00b0048789661fa2sm139049edw.66.2023.01.23.12.14.37 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Mon, 23 Jan 2023 12:14:38 -0800 (PST) From: "Artyom V. Poptsov" To: Ludovic =?utf-8?Q?Court=C3=A8s?= Subject: Re: bug#58290: guile ssh error on guix deploy References: <87sfk34zhj.fsf@trop.in> <87bkqm8p5z.fsf@gnu.org> <87o7uec39j.fsf@trop.in> <8735bmsee9.fsf@gnu.org> <87h702uzrb.fsf@gnu.org> <87y1tdkv1d.fsf@gnu.org> <875yfv38jt.fsf@gnu.org> <87v8lcgdg3.fsf@gnu.org> <87o7r3hqgy.fsf@gnu.org> <87zgaaz6ej.fsf@gmail.com> Date: Mon, 23 Jan 2023 23:14:34 +0300 In-Reply-To: <87zgaaz6ej.fsf@gmail.com> (Artyom V. Poptsov's message of "Sun, 22 Jan 2023 23:00:20 +0300") Message-ID: <87cz752el1.fsf@gmail.com> User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/28.2 (gnu/linux) MIME-Version: 1.0 Content-Type: multipart/signed; boundary="=-=-="; micalg=pgp-sha512; protocol="application/pgp-signature" X-Spam-Score: 0.2 (/) X-Debbugs-Envelope-To: 58290 Cc: 58290@debbugs.gnu.org, Andrew Tropin , Marius Bakke X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -0.8 (/) --=-=-= Content-Type: text/plain Content-Transfer-Encoding: quoted-printable Hello, I figured out how to fix Guile-SSH channel "leak", so to say, that lead to the OpenSSH "no more sessions" problem. Please run your tests with this branch and let me know if it works for you (including all the edge cases): https://github.com/artyom-poptsov/guile-ssh/tree/wip-fix-channel-leak Thanks, =2D avp =2D-=20 Artyom "avp" Poptsov Home page: https://memory-heap.org/~avp/ CADR Hackerspace co-founder: https://cadrspace.ru/ GPG: D0C2 EAC1 3310 822D 98DE B57C E9C5 A2D9 0898 A02F --=-=-= Content-Type: application/pgp-signature; name="signature.asc" -----BEGIN PGP SIGNATURE----- iQFNBAEBCgA3FiEE0MLqwTMQgi2Y3rV86cWi2QiYoC8FAmPO6qoZHHBvcHRzb3Yu YXJ0eW9tQGdtYWlsLmNvbQAKCRDpxaLZCJigL922B/oC4M1PztxusrbrkGrOht4P uIIvw6e3xfWTTmxsPhC1/1mjHXpo5EYShjd1LlItKbHulJ03Isk4UD7i2OGHt9Nw BP8RAZZzJyhv0afK/HXXA9HgLynkEdfMlFbun2fU3+KqFSK5Jn8hfFW4U9qp7Sab ICucmVU+0nP86bOUPyr4ZSDrcVVXf0RuR8OQPwGshZzQdNFbda+KKFEVfn6AaHOu rO26VdZz3zvLclAOzOiNWzBwhfTjuRm5DGvKgH/EKuLjEL0MKQkzDJr/3Lzh5W3w 5/2Umd5/t1piUHRwVRf0N9BCrF1Tszq1lR12/GJqPSxKNvmFpkCE183qNk84jqgl =96bl -----END PGP SIGNATURE----- --=-=-=-- From debbugs-submit-bounces@debbugs.gnu.org Mon Jan 23 16:50:59 2023 Received: (at 58290) by debbugs.gnu.org; 23 Jan 2023 21:50:59 +0000 Received: from localhost ([127.0.0.1]:55482 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1pK4iR-0002Iw-2E for submit@debbugs.gnu.org; Mon, 23 Jan 2023 16:50:59 -0500 Received: from eggs.gnu.org ([209.51.188.92]:58712) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1pK4iP-0002Ij-5h for 58290@debbugs.gnu.org; Mon, 23 Jan 2023 16:50:57 -0500 Received: from fencepost.gnu.org ([2001:470:142:3::e]) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1pK4iJ-0005Ks-4M; Mon, 23 Jan 2023 16:50:51 -0500 DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=gnu.org; s=fencepost-gnu-org; h=MIME-Version:In-Reply-To:Date:References:Subject:To: From; bh=Ww5Z0xQ763KZNoFOflRBuQCkF04OKamrfEqDaan4aQI=; b=K0bQDLpLeQO++OnU9g99 YrpevdPaHTpCgd5xLxz7FWGs0ZOrIrMkTluLeechrU9iG98UnoOebNoqO3y0/cTQnfwjV9Vk0pUw5 aq7jrB9xBObx+ggT2RyO/jI3ZU8vflsEKWEhMPoWhUgmYmDq6U+OgqUDqRwtXufBT5XXgAPbWcjfP LDbJrOhGcQPV/2wzOFHPgGvBRiTKYoku+lrN/pXR7/OTLgPKXSHO5du7L8vWh+hswxlmJF0S4sN4f i5APGs3eaWMM3ZFLSXHSfZPqr07hFpRJPHLZ5q4wIWcTWnjwAsrz8hszP9mwJSCbarIhXCWfJ08nt sSDqAZXYk8KETg==; Received: from 91-160-117-201.subs.proxad.net ([91.160.117.201] helo=ribbon) by fencepost.gnu.org with esmtpsa (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1pK4iI-0002dh-N3; Mon, 23 Jan 2023 16:50:50 -0500 From: =?utf-8?Q?Ludovic_Court=C3=A8s?= To: "Artyom V. Poptsov" Subject: Re: bug#58290: guile ssh error on guix deploy References: <87sfk34zhj.fsf@trop.in> <87bkqm8p5z.fsf@gnu.org> <87o7uec39j.fsf@trop.in> <8735bmsee9.fsf@gnu.org> <87h702uzrb.fsf@gnu.org> <87y1tdkv1d.fsf@gnu.org> <875yfv38jt.fsf@gnu.org> <87v8lcgdg3.fsf@gnu.org> <87o7r3hqgy.fsf@gnu.org> <87zgaaz6ej.fsf@gmail.com> <87cz752el1.fsf@gmail.com> X-URL: http://www.fdn.fr/~lcourtes/ X-Revolutionary-Date: Quartidi 4 =?utf-8?Q?Pluvi=C3=B4se?= an 231 de la =?utf-8?Q?R=C3=A9volution=2C?= jour du Perce-neige X-PGP-Key-ID: 0x090B11993D9AEBB5 X-PGP-Key: http://www.fdn.fr/~lcourtes/ludovic.asc X-PGP-Fingerprint: 3CE4 6455 8A84 FDC6 9DB4 0CFB 090B 1199 3D9A EBB5 X-OS: x86_64-pc-linux-gnu Date: Mon, 23 Jan 2023 22:50:48 +0100 In-Reply-To: <87cz752el1.fsf@gmail.com> (Artyom V. Poptsov's message of "Mon, 23 Jan 2023 23:14:34 +0300") Message-ID: <87r0vkzzrb.fsf@gnu.org> User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/28.2 (gnu/linux) MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-Spam-Score: -2.3 (--) X-Debbugs-Envelope-To: 58290 Cc: 58290@debbugs.gnu.org, Andrew Tropin , Marius Bakke X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -3.3 (---) Hi Artyom, "Artyom V. Poptsov" skribis: > I figured out how to fix Guile-SSH channel "leak", so to say, that lead > to the OpenSSH "no more sessions" problem. > > Please run your tests with this branch and let me know if it works for > you (including all the edge cases): > https://github.com/artyom-poptsov/guile-ssh/tree/wip-fix-channel-leak It works! Specifically, I ran: guix shell guile guile-ssh \ --with-branch=3Dguile-ssh=3Dwip-fix-channel-leak -- \ guile ssh-channels.scm and the script (same one as before) ran several hundreds of iterations just fine. I had looked at =E2=80=98ptob_close=E2=80=99 and related code but didn=E2= =80=99t see this issue; good catch! If you plan to push a new release, we=E2=80=99ll just upgrade in Guix; othe= rwise we can apply the patch locally. Thank you! Ludo=E2=80=99. From debbugs-submit-bounces@debbugs.gnu.org Tue Jan 24 10:53:29 2023 Received: (at 58290) by debbugs.gnu.org; 24 Jan 2023 15:53:29 +0000 Received: from localhost ([127.0.0.1]:57442 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1pKLc1-0000Gb-0c for submit@debbugs.gnu.org; Tue, 24 Jan 2023 10:53:29 -0500 Received: from relay11.mail.gandi.net ([217.70.178.231]:32785) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1pKLby-0000GM-JT for 58290@debbugs.gnu.org; Tue, 24 Jan 2023 10:53:27 -0500 Received: (Authenticated sender: andrew@trop.in) by mail.gandi.net (Postfix) with ESMTPSA id AE414100005; Tue, 24 Jan 2023 15:53:16 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=trop.in; s=gm1; t=1674575600; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:cc:mime-version:mime-version:content-type:content-type: in-reply-to:in-reply-to:references:references; bh=PHlf/u6D0pHWHW2k/+kfVJpcrg4MjUuO37kvpmjAZcY=; b=nZYoo8Iw2wKdtnDPzekELmKff9J4Bu7HRubclEaIefnLFQc5awhZfJ7f8tIMx/DX7yYR6C teL9f9hUkZmYm5rztUHaYuUwlafe9AXGnmCz/2hJQiySQ+PP7jA28hgFvw0DLngXp8DwOT qb9CDxQgyJ0/7/KP9Aluht6p7q/CsjbvvUn4QfT7/tI6mNzBb80jYvF2Aojrd5ukD2bh31 jZTrrvBBVrjq5QH4bZ1tw1Ng931e/JZTgLtRC/2tV0k1JZrtqiJHPXBxWOR8a9m8exBfCL PS3UXACjfP9Hzp3nLsmeSsbsm07O9jl8lSFLKAVZRG1/WkYKrYdcdR3ZFG8k8A== From: Andrew Tropin To: Ludovic =?utf-8?Q?Court=C3=A8s?= , "Artyom V. Poptsov" Subject: Re: bug#58290: guile ssh error on guix deploy In-Reply-To: <87r0vkzzrb.fsf@gnu.org> References: <87sfk34zhj.fsf@trop.in> <87bkqm8p5z.fsf@gnu.org> <87o7uec39j.fsf@trop.in> <8735bmsee9.fsf@gnu.org> <87h702uzrb.fsf@gnu.org> <87y1tdkv1d.fsf@gnu.org> <875yfv38jt.fsf@gnu.org> <87v8lcgdg3.fsf@gnu.org> <87o7r3hqgy.fsf@gnu.org> <87zgaaz6ej.fsf@gmail.com> <87cz752el1.fsf@gmail.com> <87r0vkzzrb.fsf@gnu.org> Date: Tue, 24 Jan 2023 19:53:12 +0400 Message-ID: <87mt68udxz.fsf@trop.in> MIME-Version: 1.0 Content-Type: multipart/signed; boundary="=-=-="; micalg=pgp-sha512; protocol="application/pgp-signature" X-Spam-Score: -0.7 (/) X-Debbugs-Envelope-To: 58290 Cc: 58290@debbugs.gnu.org, Marius Bakke X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -1.7 (-) --=-=-= Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable On 2023-01-23 22:50, Ludovic Court=C3=A8s wrote: > Hi Artyom, > > "Artyom V. Poptsov" skribis: > >> I figured out how to fix Guile-SSH channel "leak", so to say, that lead >> to the OpenSSH "no more sessions" problem. >> >> Please run your tests with this branch and let me know if it works for >> you (including all the edge cases): >> https://github.com/artyom-poptsov/guile-ssh/tree/wip-fix-channel-leak > > It works! Specifically, I ran: > > guix shell guile guile-ssh \ > --with-branch=3Dguile-ssh=3Dwip-fix-channel-leak -- \ > guile ssh-channels.scm > > and the script (same one as before) ran several hundreds of iterations > just fine. Can confirm the same, works on my machine :) Thank you very much. > > I had looked at =E2=80=98ptob_close=E2=80=99 and related code but didn=E2= =80=99t see this issue; > good catch! > > If you plan to push a new release, we=E2=80=99ll just upgrade in Guix; ot= herwise > we can apply the patch locally. > > Thank you! > > Ludo=E2=80=99. =2D-=20 Best regards, Andrew Tropin --=-=-= Content-Type: application/pgp-signature; name="signature.asc" -----BEGIN PGP SIGNATURE----- iQIzBAEBCgAdFiEEKEGaxlA4dEDH6S/6IgjSCVjB3rAFAmPP/ugACgkQIgjSCVjB 3rDf8RAAjjLmF3cKMMrbC0dAXUIotR3ikIEK2g2yI8IVVGlQPAmO8qZHh97GB8Fo 8EkBIKjpztk1NcB6KoAdJoXfzfkE706aJBfERYTtdsXESAtKtnA6ChyeEQXFjIRK n2fgk1gqoK8455UCFhwiE2WldQQOPIEadh3aNNdK2QdNAnDTDjo1IIgz59NoiXNA OzwFpsqzHH6ZivM+V8RwibT2MWDlR/tyaMMeFpp3RDSLz2kkPhoNxps0b4ZY5YWd gn8bq3CWuvZjz/pfqnPuuz19Kc9SPumOFaKMKP3ZdXwc0tSHY7vS8Lm0tECXkRrR l7HNhierBe3fxQTt5vzgyyMsQDXx/HM25UjZ2ZJ7tBcIlpD+e+kiib3pYs/AHOhg 31LT1/heM9KnQe29BGQ66aqTpABVIBr6BmYBOF3KkuFojkJ2sof8qiIER4oCmi07 khTi3r7Aef7e1otUJ38crnjr0h/ZlRtJ93YO5N/PcGkVj2uFgVQJOkzn7qyBMXo3 SM6Tnx9EdT0byj9/AwsAbMuHASV7Eot8XnE/nllkx6HIU3JLM3GJFlOMHDa2J5Sa DAycHoCttk313fPnW/PkU1aybfcbRC9FDaxhW4rhcepzzRJuIbVfxV9eLnNlcELx nP/xH/ELxcA23MLJkqa7e4owxMby9QmOSq2KlUY8XPxfSw9c71w= =kQM5 -----END PGP SIGNATURE----- --=-=-=-- From debbugs-submit-bounces@debbugs.gnu.org Mon Jan 30 17:53:27 2023 Received: (at 58290-done) by debbugs.gnu.org; 30 Jan 2023 22:53:27 +0000 Received: from localhost ([127.0.0.1]:50858 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1pMd1i-0001QY-Rc for submit@debbugs.gnu.org; Mon, 30 Jan 2023 17:53:27 -0500 Received: from eggs.gnu.org ([209.51.188.92]:34322) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1pMd1g-0001QL-SY for 58290-done@debbugs.gnu.org; Mon, 30 Jan 2023 17:53:25 -0500 Received: from fencepost.gnu.org ([2001:470:142:3::e]) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1pMd1b-0001sK-HW; Mon, 30 Jan 2023 17:53:19 -0500 DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=gnu.org; s=fencepost-gnu-org; h=MIME-Version:In-Reply-To:Date:References:Subject:To: From; bh=Vq3Uk/wh63ZdXPqM9W5gSwGPp3MTyZDnQoJmhTer9w4=; b=U1iQyZbB1qsSgBDjqGVw EgjvGF9Fl/nlOvWbWgY3RyZCW4FtFFm37glRWLgL8YnsmoJBT2WdObNq7/Kb+fu+CWgogExeeBJjr qdmLYKu95rOgMFZqCtDUX1sR5lkVGVhelEzRrtQX/eA6lbRsci/PyxZBADH5ecKSCPEdvKCMgCNXb X1wOovix7cDsrH9GJy0ocQyH0QA7VAmoLkAUrQoNPkbqDC6XOh1wVb1EwjzAZeuJyOMvua6FDTa+G ICgD9inUmyeRmDBp/vhs1kz4PNXoKEia1hdC2szG8ULZ2xb1/eis+w+QkJCZ5w0GJWIEpQvVe/lNA W4xUdipokbO+Uw==; Received: from 91-160-117-201.subs.proxad.net ([91.160.117.201] helo=ribbon) by fencepost.gnu.org with esmtpsa (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1pMd1b-0007l3-3D; Mon, 30 Jan 2023 17:53:19 -0500 From: =?utf-8?Q?Ludovic_Court=C3=A8s?= To: Andrew Tropin Subject: Re: bug#58290: guile ssh error on guix deploy References: <87sfk34zhj.fsf@trop.in> <87bkqm8p5z.fsf@gnu.org> <87o7uec39j.fsf@trop.in> <8735bmsee9.fsf@gnu.org> <87h702uzrb.fsf@gnu.org> <87y1tdkv1d.fsf@gnu.org> <875yfv38jt.fsf@gnu.org> <87v8lcgdg3.fsf@gnu.org> <87o7r3hqgy.fsf@gnu.org> <87zgaaz6ej.fsf@gmail.com> <87cz752el1.fsf@gmail.com> <87r0vkzzrb.fsf@gnu.org> <87mt68udxz.fsf@trop.in> Date: Mon, 30 Jan 2023 23:53:16 +0100 In-Reply-To: <87mt68udxz.fsf@trop.in> (Andrew Tropin's message of "Tue, 24 Jan 2023 19:53:12 +0400") Message-ID: <87wn53vdlv.fsf@gnu.org> User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/28.2 (gnu/linux) MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-Spam-Score: -2.3 (--) X-Debbugs-Envelope-To: 58290-done Cc: "Artyom V. Poptsov" , 58290-done@debbugs.gnu.org, Marius Bakke X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -3.3 (---) Hi, The bug should be fixed with the upgrade to Guile-SSH 0.16.3 in commit e6f557dd23fbb298afa92dba3133ed985e560699. Thanks Artyom for the prompt fix & release! Ludo=E2=80=99. From unknown Sat Aug 09 09:35:54 2025 Received: (at fakecontrol) by fakecontrolmessage; To: internal_control@debbugs.gnu.org From: Debbugs Internal Request Subject: Internal Control Message-Id: bug archived. Date: Tue, 28 Feb 2023 12:24:05 +0000 User-Agent: Fakemail v42.6.9 # This is a fake control message. # # The action: # bug archived. thanks # This fakemail brought to you by your local debbugs # administrator