Issue
During the course of an ssh session with an agent either the server or the client can request a rekey, and openssh servers on linux have a setting for triggering a re-key event that is typically defaulted to every hour. This process typically goes on in the background unnoticed and uneventful:
SSH rekeying is the process of exchanging the session keys at a configured interval, based on a time limit or a data limit for the SSH session. SSH rekeying is triggered when the time limit (maximum minutes) or the data limit has been reached for the session. Rekey can be initiated by either the client or the server.
During the re-key process there is a key exchange (KEX) and the client and server negotiate on a set of ciphers and algorithms they support to continue the session. We traced, and reported, a bug in this procedure to a change in the Apache Mina-SSHd project - SSHD-1264 which our own CloudBees SSH Build Agents Plugin
relies on.
This issue affects CloudBees SSH Build Agents Plugin version 2.16.
Symptoms
While using CloudBees SSH Build Agents Plugin, you encounter a disconnect every hour and see in your controller log files:
Apr 1, 2022 9:36:01 AM [ssh] Connection established in 3.238 seconds.
Apr 1, 2022 10:36:00 AM [ssh] Verifying server host key...
Apr 1, 2022 10:36:00 AM [ssh] RSA key fingerprint is SHA256:bjuNUryRnpHMO5qOFr9FfSHOv7gcaw62m+UorIxOZmU
Apr 1, 2022 10:36:00 AM [ssh] Server host key rejected
ERROR: Connection terminated
java.io.IOException: Pipe closed after 0 cycles
at org.apache.sshd.common.channel.ChannelPipedInputStream.read(ChannelPipedInputStream.java:126)
at org.apache.sshd.common.channel.ChannelPipedInputStream.read(ChannelPipedInputStream.java:105)
at hudson.remoting.FlightRecorderInputStream.read(FlightRecorderInputStream.java:93)
at hudson.remoting.ChunkedInputStream.readHeader(ChunkedInputStream.java:74)
at hudson.remoting.ChunkedInputStream.readUntilBreak(ChunkedInputStream.java:104)
at hudson.remoting.ChunkedCommandTransport.readBlock(ChunkedCommandTransport.java:39)
at hudson.remoting.AbstractSynchronousByteArrayCommandTransport.read(AbstractSynchronousByteArrayCommandTransport.java:34)
at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:61)
ERROR: 4/1/22 10:36 AM agent was terminated
java.io.IOException: Pipe closed after 0 cycles
at org.apache.sshd.common.channel.ChannelPipedInputStream.read(ChannelPipedInputStream.java:126)
at org.apache.sshd.common.channel.ChannelPipedInputStream.read(ChannelPipedInputStream.java:105)
at hudson.remoting.FlightRecorderInputStream.read(FlightRecorderInputStream.java:93)
at hudson.remoting.ChunkedInputStream.readHeader(ChunkedInputStream.java:74)
at hudson.remoting.ChunkedInputStream.readUntilBreak(ChunkedInputStream.java:104)
at hudson.remoting.ChunkedCommandTransport.readBlock(ChunkedCommandTransport.java:39)
at hudson.remoting.AbstractSynchronousByteArrayCommandTransport.read(AbstractSynchronousByteArrayCommandTransport.java:34)
at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:61)
Apr 1, 2022 10:37:58 AM [ssh] Opening connection to 10.227.198.157:22 as joel/****** (joel)
Apr 1, 2022 10:37:58 AM [ssh] Authenticating...
Apr 1, 2022 10:37:58 AM [ssh] Verifying server host key...
Apr 1, 2022 10:37:58 AM [ssh] ECDSA key fingerprint is SHA256:bhp3clzbDy1rglrEk/3KH9elIHRh3kaD4qD0KOY++fE
Apr 1, 2022 10:37:58 AM [ssh] Server host key verified
Apr 1, 2022 10:37:58 AM [ssh] Authentication successful.
Apr 1, 2022 10:37:58 AM [ssh] Checking for header junk...
Apr 1, 2022 10:37:58 AM [ssh] No header junk found.
Apr 1, 2022 10:37:58 AM [ssh] Inspecting operating system...
Apr 1, 2022 10:37:58 AM [ssh] Operating system: LINUX
Apr 1, 2022 10:37:58 AM [ssh] Remote SSH server: SSH-2.0-OpenSSH_7.4
Apr 1, 2022 10:37:58 AM [ssh] Verifying Java...
Apr 1, 2022 10:37:58 AM [ssh] Trying 'java' as a java command...
java -version returned 1.8.0.
Apr 1, 2022 10:37:58 AM [ssh] Verifying agent.jar...
Apr 1, 2022 10:37:59 AM [ssh] agent.jar verified, MD5: 0ecc112158d161e4017a98119d137d68
Apr 1, 2022 10:37:59 AM [ssh] $ cd '/cbci' && java -jar agent.jar
<===[JENKINS REMOTING CAPACITY]===>channel started
Remoting version: 4.11.2
This is a Unix agent
Evacuated stdout
Agent successfully connected and online
Apr 1, 2022 10:38:02 AM [ssh] Connection established in 3.798 seconds.
Environment
- CloudBees CI (CloudBees Core)
- CloudBees CI (CloudBees Core) on modern cloud platforms - Managed Controller
- CloudBees CI (CloudBees Core) on modern cloud platforms - Operations Center
- CloudBees CI (CloudBees Core) on traditional platforms - Client Controller
- CloudBees CI (CloudBees Core) on traditional platforms - Operations Center
- CloudBees Jenkins Platform - Client Controller
- CloudBees Jenkins Platform - Operations Center
Resolution
The sshd fix is coming via https://issues.apache.org/jira/browse/SSHD-1264
Workaround
The recommended resolution and workaround is to start using the SSH Build Agents Plugin to configure your ssh connected build agents.
0 Comments