yashasvirajpant opened a new issue, #623:
URL: https://github.com/apache/mina-sshd/issues/623
### Version
sshd-core-2.14.0
### Bug description
I'm facing an issue while trying to authenticate an SSH session using the
Apache Mina SSHD library in Java in a spring boot microservice project. I have
a working implementation using JSch that connects successfully with a private
key, but the equivalent code in Apache Mina SSHD fails with the error:
```
org.apache.sshd.common.SshException: Session is being closed
at
org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:141)
~[sshd-common-2.10.0.jar:2.10.0]
at
org.apache.sshd.client.future.DefaultAuthFuture.verify(DefaultAuthFuture.java:56)
~[sshd-core-2.10.0.jar:2.10.0]
at
org.apache.sshd.client.future.DefaultAuthFuture.verify(DefaultAuthFuture.java:35)
~[sshd-core-2.10.0.jar:2.10.0]
```
or sometime:
```
org.apache.sshd.common.SshException: Invalid packet length: 1096041266
at
org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:141)
~[sshd-common-2.10.0.jar:2.10.0]
at
org.apache.sshd.client.future.DefaultAuthFuture.verify(DefaultAuthFuture.java:56)
~[sshd-core-2.10.0.jar:2.10.0]
at
org.apache.sshd.client.future.DefaultAuthFuture.verify(DefaultAuthFuture.java:35)
~[sshd-core-2.10.0.jar:2.10.0]
```
Here is the code implementation:
```
try (SshClient sshClient = SshClient.setUpDefaultClient()) {
// Enable DSA signatures (which is disabled by default) (for ssh-dss
key type)
sshClient.setSignatureFactories(List.of(BuiltinSignatures.dsa));
// Enable diffie-hellman-group1-sha1 key exchange algorithm for older
devices
sshClient.setKeyExchangeFactories(
NamedFactory.setUpTransformedFactories(
false, BuiltinDHFactories.VALUES, ClientBuilder.DH2KEX));
sshClient.start();
try (ClientSession session =
sshClient.connect(user, host, port).verify(ftpTimeOutInSeconds *
1000L).getSession()) {
// Parse the private key string
StringReader stringReader = new StringReader(privateKeyInString);
PEMParser pemParser = new PEMParser(stringReader);
JcaPEMKeyConverter converter = new
JcaPEMKeyConverter().setProvider("BC");
KeyPair keyPair = converter.getKeyPair((PEMKeyPair)
pemParser.readObject());
// Add the private key to the session
session.addPublicKeyIdentity(keyPair);
session.auth().verify(ftpTimeOutInSeconds * 1000L);
LOGGER.info("Session authenticated successfully!");
}
catch (IOException e) {
LOGGER.error("I/O Exception occurred: " + e.getMessage());
} catch (Exception e) {
LOGGER.error("General Exception occurred: " + e.getMessage());
}
}
```
The error occurs in the code line
`session.auth().verify(ftpTimeOutInSeconds * 1000L);
`
What could be the reason for the authentication failure in the Apache Mina
SSHD implementation, and how can I resolve this issue? Any insights or
recommendations for debugging further would be greatly appreciated!
### Actual behavior
Not able to connect to SSH using Apache Mina SSHD
### Expected behavior
We should get SSH connection correct as it can be connected with JSch
### Relevant log output
```Shell
2024-10-11 13:02:42.113 DEBUG 1 --- [ol-39-thread-39]
c.c.h.DefaultConfigFileHostEntryResolver :
resolveEffectiveHost(user@<ip>:<port>/null) => null
2024-10-11 13:02:42.113 DEBUG 1 --- [ol-39-thread-39]
org.apache.sshd.client.SshClient : connect(user@<ip>:<port>) no
overrides
2024-10-11 13:02:42.113 DEBUG 1 --- [ol-39-thread-39]
o.a.sshd.common.io.nio2.Nio2Connector : Connecting to /<ip>:<port>
2024-10-11 13:02:42.114 DEBUG 1 --- [ol-39-thread-39]
o.a.sshd.common.io.nio2.Nio2Connector : setOption(SO_REUSEADDR)[true] from
property=Property[socket-reuseaddr](Boolean]
2024-10-11 13:02:42.114 DEBUG 1 --- [resume-thread-1]
o.a.sshd.common.io.nio2.Nio2Connector : connect(/<ip>:<port>): waiting for
connection (timeout=60000ms)
2024-10-11 13:02:42.154 DEBUG 1 --- [resume-thread-1]
o.a.sshd.common.io.nio2.Nio2Session : Creating IoSession on
/<internal_ip>:<internal_port> from /<ip>:<port> via null
2024-10-11 13:02:42.154 DEBUG 1 --- [resume-thread-1]
o.a.s.client.session.ClientSessionImpl : Client session created:
Nio2Session[local=/<internal_ip>:44140, remote=/<ip>:<port>]
2024-10-11 13:02:42.154 DEBUG 1 --- [resume-thread-1]
o.a.s.c.session.ClientUserAuthService :
ClientUserAuthService(ClientSessionImpl[null@/<ip>:<port>]) client methods:
[publickey, keyboard-interactive, password]
2024-10-11 13:02:42.154 DEBUG 1 --- [resume-thread-1]
o.a.s.c.s.h.SessionTimeoutListener :
sessionCreated(ClientSessionImpl[null@/<ip>:<port>]) tracking
2024-10-11 13:02:42.154 DEBUG 1 --- [resume-thread-1]
o.a.s.client.session.ClientSessionImpl :
initializeProxyConnector(ClientSessionImpl[null@/<ip>:<port>]) no proxy to
initialize
2024-10-11 13:02:42.155 DEBUG 1 --- [resume-thread-1]
o.a.s.client.session.ClientSessionImpl :
sendIdentification(ClientSessionImpl[null@/<ip>:<port>]):
SSH-2.0-APACHE-SSHD-2.10.0
2024-10-11 13:02:42.155 DEBUG 1 --- [resume-thread-1]
o.a.sshd.common.io.nio2.Nio2Session :
writeBuffer(Nio2Session[local=/<internal_ip>:44140, remote=/<ip>:<port>])
writing 28 bytes
2024-10-11 13:02:42.155 DEBUG 1 --- [resume-thread-1]
o.a.s.client.session.ClientSessionImpl :
sendKexInit(ClientSessionImpl[null@/<ip>:<port>]) Send SSH_MSG_KEXINIT
2024-10-11 13:02:42.159 DEBUG 1 --- [resume-thread-1]
o.a.s.client.session.ClientSessionImpl :
encode(ClientSessionImpl[null@/<ip>:<port>]) packet #0 sending
command=20[SSH_MSG_KEXINIT] len=1012
2024-10-11 13:02:42.160 DEBUG 1 --- [resume-thread-1]
o.a.sshd.common.io.nio2.Nio2Session :
writeBuffer(Nio2Session[local=/<internal_ip>:44140, remote=/<ip>:<port>])
writing 1032 bytes
2024-10-11 13:02:42.160 DEBUG 1 --- [resume-thread-1]
org.apache.sshd.client.SshClient :
setupDefaultSessionIdentities(ClientSessionImpl[user@/<ip>:<port>]) key
identity provider override in session listener
2024-10-11 13:02:42.160 DEBUG 1 --- [ol-39-thread-39]
o.a.s.c.future.DefaultConnectFuture : Connected to /<ip>:<port> after
45881332 nanos
2024-10-11 13:02:42.161 DEBUG 1 --- [ol-39-thread-39]
o.a.s.client.session.ClientSessionImpl :
addPublicKeyIdentity(ClientSessionImpl[user@/<ip>:<port>]) ssh-dss-SHA256:<key>
2024-10-11 13:02:42.221 DEBUG 1 --- []-nio2-thread-3]
o.a.s.client.session.ClientSessionImpl :
doReadIdentification(ClientSessionImpl[user@/<ip>:<port>])
line='SSH-2.0-dropbear_2014.63'
2024-10-11 13:02:42.221 DEBUG 1 --- []-nio2-thread-3]
o.a.s.client.session.ClientSessionImpl :
readIdentification(ClientSessionImpl[user@/<ip>:<port>]) Server version string:
SSH-2.0-dropbear_2014.63
2024-10-11 13:02:42.221 DEBUG 1 --- []-nio2-thread-3]
o.a.s.client.session.ClientSessionImpl :
doHandleMessage(ClientSessionImpl[user@/<ip>:<port>]) process #0 SSH_MSG_KEXINIT
2024-10-11 13:02:42.221 DEBUG 1 --- []-nio2-thread-3]
o.a.s.client.session.ClientSessionImpl :
handleKexInit(ClientSessionImpl[user@/<ip>:<port>]) SSH_MSG_KEXINIT
2024-10-11 13:02:42.221 DEBUG 1 --- []-nio2-thread-3]
o.a.s.client.session.ClientSessionImpl :
setNegotiationResult(ClientSessionImpl[user@/<ip>:<port>]) Kex: kex algorithms
= diffie-hellman-group1-sha1
2024-10-11 13:02:42.221 DEBUG 1 --- []-nio2-thread-3]
o.a.s.client.session.ClientSessionImpl :
setNegotiationResult(ClientSessionImpl[user@/<ip>:<port>]) Kex: server host key
algorithms = ssh-dss
2024-10-11 13:02:42.221 DEBUG 1 --- []-nio2-thread-3]
o.a.s.client.session.ClientSessionImpl :
setNegotiationResult(ClientSessionImpl[user@/<ip>:<port>]) Kex: encryption
algorithms (client to server) = aes128-ctr
2024-10-11 13:02:42.221 DEBUG 1 --- []-nio2-thread-3]
o.a.s.client.session.ClientSessionImpl :
setNegotiationResult(ClientSessionImpl[user@/<ip>:<port>]) Kex: encryption
algorithms (server to client) = aes128-ctr
2024-10-11 13:02:42.221 DEBUG 1 --- []-nio2-thread-3]
o.a.s.client.session.ClientSessionImpl :
setNegotiationResult(ClientSessionImpl[user@/<ip>:<port>]) Kex: mac algorithms
(client to server) = hmac-sha1
2024-10-11 13:02:42.221 DEBUG 1 --- []-nio2-thread-3]
o.a.s.client.session.ClientSessionImpl :
setNegotiationResult(ClientSessionImpl[user@/<ip>:<port>]) Kex: mac algorithms
(server to client) = hmac-sha1
2024-10-11 13:02:42.221 DEBUG 1 --- []-nio2-thread-3]
o.a.s.client.session.ClientSessionImpl :
setNegotiationResult(ClientSessionImpl[user@/<ip>:<port>]) Kex: compression
algorithms (client to server) = none
2024-10-11 13:02:42.221 DEBUG 1 --- []-nio2-thread-3]
o.a.s.client.session.ClientSessionImpl :
setNegotiationResult(ClientSessionImpl[user@/<ip>:<port>]) Kex: compression
algorithms (server to client) = none
2024-10-11 13:02:42.224 DEBUG 1 --- []-nio2-thread-3]
org.apache.sshd.client.kex.DHGClient :
init(DHGClient[diffie-hellman-group1-sha1])[ClientSessionImpl[user@/<ip>:<port>]]
Send SSH_MSG_KEXDH_INIT
2024-10-11 13:02:42.224 DEBUG 1 --- []-nio2-thread-3]
o.a.s.client.session.ClientSessionImpl :
encode(ClientSessionImpl[user@/<ip>:<port>]) packet #1 sending command=30[30]
len=133
2024-10-11 13:02:42.224 DEBUG 1 --- []-nio2-thread-3]
o.a.sshd.common.io.nio2.Nio2Session :
writeBuffer(Nio2Session[local=/<internal_ip>:44140, remote=/<ip>:<port>])
writing 152 bytes
2024-10-11 13:02:45.858 DEBUG 1 --- []-nio2-thread-4]
o.a.sshd.common.io.nio2.Nio2Session :
handleReadCycleCompletion(Nio2Session[local=/<internal_ip>:44140,
remote=/<ip>:<port>]) Socket has been disconnected (result=-1), closing
IoSession now
2024-10-11 13:02:45.858 DEBUG 1 --- []-nio2-thread-4]
o.a.sshd.common.io.nio2.Nio2Session :
close(Nio2Session[local=/<internal_ip>:44140, remote=/<ip>:<port>]) Closing
immediately
2024-10-11 13:02:45.858 DEBUG 1 --- []-nio2-thread-4]
o.a.sshd.common.io.nio2.Nio2Session :
doCloseImmediately(Nio2Session[local=/<internal_ip>:44140,
remote=/<ip>:<port>]) closing
socket=sun.nio.ch.UnixAsynchronousSocketChannelImpl[connected
local=/<internal_ip>:44140 remote=/<ip>:<port>]
2024-10-11 13:02:45.858 DEBUG 1 --- []-nio2-thread-4]
o.a.sshd.common.io.nio2.Nio2Session :
doCloseImmediately(Nio2Session[local=/<internal_ip>:44140,
remote=/<ip>:<port>])
socket=sun.nio.ch.UnixAsynchronousSocketChannelImpl[closed] closed
2024-10-11 13:02:45.858 DEBUG 1 --- []-nio2-thread-4]
o.a.sshd.common.io.nio2.Nio2Connector : unmapSession(id=107):
Nio2Session[local=/<internal_ip>:44140, remote=/<ip>:<port>]
2024-10-11 13:02:45.858 DEBUG 1 --- []-nio2-thread-4]
o.a.s.client.session.ClientSessionImpl :
close(ClientSessionImpl[user@/<ip>:<port>]) Closing immediately
2024-10-11 13:02:45.858 DEBUG 1 --- []-nio2-thread-4]
o.a.s.client.session.ClientSessionImpl :
signalAuthFailure(ClientSessionImpl[user@/<ip>:<port>]) type=SshException,
signalled=true, first=false: Session is being closed
2024-10-11 13:02:45.858 DEBUG 1 --- []-nio2-thread-4]
o.a.s.c.s.h.SessionTimeoutListener :
sessionClosed(ClientSessionImpl[user@/<ip>:<port>]) un-tracked
2024-10-11 13:02:45.858 DEBUG 1 --- [ol-39-thread-39]
org.apache.sshd.client.SshClient : close(SshClient[1bacb075]) Closing
immediately
2024-10-11 13:02:45.858 DEBUG 1 --- []-nio2-thread-4]
o.a.s.c.session.ClientUserAuthService :
close(org.apache.sshd.client.session.ClientUserAuthService@1294c333) Closing
immediately
2024-10-11 13:02:45.858 DEBUG 1 --- []-nio2-thread-4]
o.a.s.c.session.ClientUserAuthService :
close(org.apache.sshd.client.session.ClientUserAuthService@1294c333)[Immediately]
closed
2024-10-11 13:02:45.858 DEBUG 1 --- [ol-39-thread-39]
o.a.sshd.common.io.nio2.Nio2Connector :
close(org.apache.sshd.common.io.nio2.Nio2Connector@77d9db15) Closing immediately
2024-10-11 13:02:45.858 DEBUG 1 --- [ol-39-thread-39]
o.a.sshd.common.io.nio2.Nio2Connector :
close(org.apache.sshd.common.io.nio2.Nio2Connector@77d9db15)[Immediately] closed
2024-10-11 13:02:45.858 DEBUG 1 --- []-nio2-thread-4]
o.a.s.c.session.ClientConnectionService :
close(ClientConnectionService[ClientSessionImpl[user@/<ip>:<port>]]) Closing
immediately
2024-10-11 13:02:45.858 DEBUG 1 --- [ol-39-thread-39]
o.a.s.common.io.nio2.Nio2ServiceFactory :
close(org.apache.sshd.common.io.nio2.Nio2ServiceFactory@988f283) Closing
immediately
2024-10-11 13:02:45.858 DEBUG 1 --- []-nio2-thread-4]
o.a.s.c.session.ClientConnectionService :
stopHeartBeat(ClientSessionImpl[user@/<ip>:<port>]) no heartbeat to stop
2024-10-11 13:02:45.858 DEBUG 1 --- [ol-39-thread-39]
o.a.s.common.io.nio2.Nio2ServiceFactory : Shutdown group
2024-10-11 13:02:45.858 DEBUG 1 --- []-nio2-thread-4]
o.a.s.c.session.ClientConnectionService :
close(ClientConnectionService[ClientSessionImpl[user@/<ip>:<port>]])[Immediately]
closed
2024-10-11 13:02:45.859 DEBUG 1 --- []-nio2-thread-4]
o.a.sshd.common.io.nio2.Nio2Session :
close(Nio2Session[local=/<internal_ip>:44140,
remote=/<ip>:<port>])[Immediately] state already Closed
2024-10-11 13:02:45.859 DEBUG 1 --- []-nio2-thread-4]
o.a.s.c.u.closeable.SequentialCloseable :
doClose(org.apache.sshd.common.util.closeable.SequentialCloseable$1@1c532f11)
signal close complete immediately=true
2024-10-11 13:02:45.859 DEBUG 1 --- []-nio2-thread-4]
o.a.s.client.session.ClientSessionImpl :
close(ClientSessionImpl[user@/<ip>:<port>])[Immediately] closed
2024-10-11 13:02:45.859 DEBUG 1 --- []-nio2-thread-4]
o.a.sshd.common.io.nio2.Nio2Session :
close(Nio2Session[local=/<internal_ip>:44140,
remote=/<ip>:<port>])[Immediately] closed
2024-10-11 13:02:45.859 DEBUG 1 --- [ol-39-thread-39]
o.a.s.common.io.nio2.Nio2ServiceFactory : Group successfully shut down
2024-10-11 13:02:45.859 DEBUG 1 --- [ol-39-thread-39]
o.a.s.common.io.nio2.Nio2ServiceFactory : Shutdown executor
2024-10-11 13:02:45.859 DEBUG 1 --- [ol-39-thread-39]
o.a.s.common.io.nio2.Nio2ServiceFactory : Shutdown complete
2024-10-11 13:02:45.859 DEBUG 1 --- [ol-39-thread-39]
o.a.s.common.io.nio2.Nio2ServiceFactory :
close(org.apache.sshd.common.io.nio2.Nio2ServiceFactory@988f283)[Immediately]
closed
2024-10-11 13:02:45.859 DEBUG 1 --- [ol-39-thread-39]
o.a.s.c.u.closeable.SequentialCloseable :
doClose(org.apache.sshd.common.util.closeable.SequentialCloseable$1@42f6f160)
signal close complete immediately=true
2024-10-11 13:02:45.859 DEBUG 1 --- [ol-39-thread-39]
org.apache.sshd.client.SshClient :
close(SshClient[1bacb075])[Immediately] closed
org.apache.sshd.common.SshException: Session is being closed
at
org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:141)
~[sshd-common-2.10.0.jar:2.10.0]
at
org.apache.sshd.client.future.DefaultAuthFuture.verify(DefaultAuthFuture.java:56)
~[sshd-core-2.10.0.jar:2.10.0]
at
org.apache.sshd.client.future.DefaultAuthFuture.verify(DefaultAuthFuture.java:35)
~[sshd-core-2.10.0.jar:2.10.0]
```
### Other information
_No response_
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
