Received SSH_MSG_UNIMPLEMENTED while exchanging keys with KeepAlive Enabled #810
Description
Starting several SSH connections across multiple threads can result in an SSH server sending SSH_MSG_UNIMPLEMENTED during key exchange as shown in the follow error log:
ERROR net.schmizz.sshj.transport.TransportImpl - Dying because - Received SSH_MSG_UNIMPLEMENTED while exchanging keys
net.schmizz.sshj.transport.TransportException: Received SSH_MSG_UNIMPLEMENTED while exchanging keys
at net.schmizz.sshj.transport.TransportImpl.gotUnimplemented(TransportImpl.java:565)
at net.schmizz.sshj.transport.TransportImpl.handle(TransportImpl.java:495)
at net.schmizz.sshj.transport.Decoder.decode(Decoder.java:113)
at net.schmizz.sshj.transport.Decoder.received(Decoder.java:200)
at net.schmizz.sshj.transport.Reader.run(Reader.java:60)
This appears to occur more frequently in SSHJ 0.33.0 and 0.34.0 with SSH KeepAlive enabled. These versions include changes in pull request #752, which start the KeepAlive Thread in SSHClient.onConnect().
The underlying problem appears to be related to the timing of sending and receiving SSH_MSG_KEXINIT packets. Sending an SSH_MSG_KEXINIT packet can be initiated from different locations. The SSHClient.onConnect() method calls Transport.doKex(), which calls KeyExchanger.startKex(). KexExchange.handle() can also call KeyExchanger.startKex() when receiving an SSH_MSG_KEXINIT packet. This can cause problems with multiple connections due to different threads calling KeyExchanger.startKex() at different times.
When an OpenSSH server receives an unexpected SSH_MSG_KEXINIT packet, it sends an SSH_MSG_UNIMPLEMENTED packet and logs the following error:
dispatch_protocol_error: type 20 seq 3 [preauth]
The atmoz/sftp Docker image provides a standard OpenSSH server for testing, but this issue should be reproducible with any recent version of OpenSSH server.
The nature of the problem makes it difficult to reproduce in a unit test, but the following class is capable of causing the error in the process of initiating multiple connection attempts using a pool of threads. The class attempts up to 1000 connections using a pool of four threads. It is not necessary to authenticate to the SSH server since the problem occurs during initial connection key exchange. The class relies of slf4j-simple and Java System properties for console logging. The connect method calls System.exit() at the first error encountered.
import net.schmizz.keepalive.KeepAliveProvider;
import net.schmizz.sshj.DefaultConfig;
import net.schmizz.sshj.SSHClient;
import net.schmizz.sshj.transport.verification.PromiscuousVerifier;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;
import java.util.concurrent.TimeUnit;
public class SshConnectCommand {
static {
System.setProperty("org.slf4j.simpleLogger.defaultLogLevel", "DEBUG");
System.setProperty("org.slf4j.simpleLogger.showDateTime", "true");
System.setProperty("org.slf4j.simpleLogger.dateTimeFormat", "yyyy-MM-dd HH:mm:ss.SSS");
}
private static final String SSH_SERVER = "127.0.0.1";
private static final int SSH_PORT = 2222;
private static final int KEEP_ALIVE_INTERVAL = 5;
private static final int POOL_SIZE = 4;
private static final int CONNECTIONS = 1000;
private static final int EXECUTION_TIME = 10;
private static final Logger logger = LoggerFactory.getLogger(SshConnectCommand.class);
public static void main(String[] args) throws Exception {
final ExecutorService executorService = Executors.newFixedThreadPool(POOL_SIZE);
for (int i = 1; i <= CONNECTIONS; i++) {
final int counter = i;
executorService.execute(() -> {
connect(counter);
});
}
executorService.awaitTermination(EXECUTION_TIME, TimeUnit.SECONDS);
executorService.shutdown();
logger.info("Completed Connections [{}]", CONNECTIONS);
}
private static void connect(int counter) {
try (final SSHClient sshClient = createClient()) {
logger.info("Connection Starting [{}]", counter);
sshClient.connect(SSH_SERVER, SSH_PORT);
} catch (final Exception e) {
logger.error("Connection Failed [{}]", counter, e);
System.exit(1);
} finally {
logger.info("Connection Completed [{}]", counter);
}
}
private static SSHClient createClient() {
final DefaultConfig config = new DefaultConfig();
config.setKeepAliveProvider(KeepAliveProvider.KEEP_ALIVE);
final SSHClient sshClient = new SSHClient(config);
sshClient.getConnection().getKeepAlive().setKeepAliveInterval(KEEP_ALIVE_INTERVAL);
sshClient.addHostKeyVerifier(new PromiscuousVerifier());
return sshClient;
}
}