apache / mina-sshd

Apache MINA sshd is a comprehensive Java library for client- and server-side SSH.
https://mina.apache.org/sshd-project/
Apache License 2.0
847 stars 353 forks source link

AuthTimeout when connecting to SFTP server #484

Closed yaroslavambrozyak closed 1 month ago

yaroslavambrozyak commented 2 months ago

Version

2.9.2

Bug description

Hi, I recently migrated a project to Spring Boot 3 and faced an issue connecting to a remote SFTP server. I get a timeout during auth, this is what I see in logs

Disconnecting(ClientSessionImpl[someuser@somehost/0.0.0.0:22]): SSH2_DISCONNECT_PROTOCOL_ERROR - Detected AuthTimeout after 120823/120000 ms.

If I spawn an SFTP docker container on my local then I can connect to my local SFTP, also I can connect to the remote server if I use Spring Boot 2.x version.

Can I run it in verbose or debug mode to see some additional information? I really appreciate any help you can provide.

Actual behavior

I have tried to connect to a remote server using simple code

SshClient sshClient = SshClient.setUpDefaultClient();

sshClient.start();
ConnectFuture connect = sshClient.connect("username", "host", 22);
ClientSession clientSession = connect.verify().getClientSession();
clientSession.addPasswordIdentity("pass");

AuthFuture authFuture = clientSession.auth().verify();

so it hangs on the last line and after some time prints a log I mentioned above The same code is working if I try to connect to my local SFTP server (it does not throw any timeout exception)

Expected behavior

Be able to connect to the server

Relevant log output

2024-04-15T17:30:02.807+03:00  INFO 35672 --- [           main] o.a.s.c.i.DefaultIoServiceFactoryFactory : No detected/configured IoServiceFactoryFactory; using Nio2ServiceFactoryFactory
2024-04-15T17:30:02.833+03:00  INFO 35672 --- [           main] c.c.h.DefaultConfigFileHostEntryResolver : resolveEffectiveResolver(<some_host>) no configuration file at C:\Users\User1\.ssh\config

2024-04-15T17:30:03.134+03:00  WARN 35672 --- []-nio2-thread-6] o.a.s.c.k.AcceptAllServerKeyVerifier     : Server at <some_host> presented unverified RSA key: SHA256:vT...n+w
2024-04-15T17:32:03.807+03:00  INFO 35672 --- [-timer-thread-1] o.a.s.client.session.ClientSessionImpl   : Disconnecting(ClientSessionImpl[<some_host>]): SSH2_DISCONNECT_PROTOCOL_ERROR - Detected AuthTimeout after 120823/120000 ms.

org.apache.sshd.common.SshException: Session is being closed
    at org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:141)
    at org.apache.sshd.client.future.DefaultAuthFuture.verify(DefaultAuthFuture.java:56)
    at org.apache.sshd.client.future.DefaultAuthFuture.verify(DefaultAuthFuture.java:35)
    at org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43)
    at com.example.sftpdebug.SftpdebugApplication.main(SftpdebugApplication.java:31)
Caused by: org.apache.sshd.common.SshException: Session is being closed
    at org.apache.sshd.client.session.ClientSessionImpl.preClose(ClientSessionImpl.java:169)
    at org.apache.sshd.common.util.closeable.AbstractCloseable.close(AbstractCloseable.java:94)
    at org.apache.sshd.common.session.helpers.SessionHelper.lambda$disconnect$9(SessionHelper.java:1213)
    at org.apache.sshd.common.future.AbstractSshFuture.lambda$notifyListener$3(AbstractSshFuture.java:178)
    at org.apache.sshd.common.util.threads.ThreadUtils.runAsInternal(ThreadUtils.java:68)
    at org.apache.sshd.common.future.AbstractSshFuture.notifyListener(AbstractSshFuture.java:177)
    at org.apache.sshd.common.future.DefaultSshFuture.addListener(DefaultSshFuture.java:214)
    at org.apache.sshd.common.session.helpers.SessionHelper.disconnect(SessionHelper.java:1197)
    at org.apache.sshd.common.session.helpers.SessionHelper.checkForTimeouts(SessionHelper.java:301)
    at org.apache.sshd.common.session.helpers.SessionTimeoutListener.run(SessionTimeoutListener.java:84)
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
    at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305)
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    at java.base/java.lang.Thread.run(Thread.java:833)

Other information

No response

tomaswolf commented 2 months ago

No idea. Try enabling debug logging and see if the log gives any hints.

yaroslavambrozyak commented 2 months ago

In the logs, I can see it is trying to use keyboard-interactive auth method

tryNext(ClientSessionImpl[u@h/0.0.0.0:0]) attempting method=keyboard-interactive

and then it prints

getUserResponses(ClientSessionImpl[u@h/0.0.0.0:0]) no user interaction for name=Password authentication

Shouldn`t it be a password method? I set a password like this and even tried to set a preferred auth factory. Do I miss something?

clientSession.addPasswordIdentity("pass");
clientSession.setUserAuthFactories(Collections.singletonList(UserAuthPasswordFactory.INSTANCE));

full log

[           main] o.a.s.c.i.DefaultIoServiceFactoryFactory : No detected/configured IoServiceFactoryFactory; using Nio2ServiceFactoryFactory
[           main] c.c.h.DefaultConfigFileHostEntryResolver : resolveEffectiveResolver(u@h:0000/null) no configuration file at C:\Users\NX01S\.ssh\config
[           main] c.c.h.DefaultConfigFileHostEntryResolver : resolveEffectiveHost(u@h:0000/null) => null
[           main] org.apache.sshd.client.SshClient         : connect(u@h:0000) no overrides
[           main] o.a.sshd.common.io.nio2.Nio2Connector    : Connecting to u@h:0000
[           main] o.a.sshd.common.io.nio2.Nio2Connector    : setOption(SO_REUSEADDR)[true] from property=Property[socket-reuseaddr](Boolean]
[resume-thread-1] o.a.sshd.common.io.nio2.Nio2Connector    : connect(u@h:0000): waiting for connection (timeout=60000ms)
[resume-thread-1] o.a.sshd.common.io.nio2.Nio2Session      : Creating IoSession on /[0:0:0:0:0:0:0:0]:51397 from u@h:0000 via null
[resume-thread-1] o.a.s.client.session.ClientSessionImpl   : Client session created: Nio2Session[local=/[0:0:0:0:0:0:0:0]:51397, remote=u@h:0000]
[resume-thread-1] o.a.s.c.session.ClientUserAuthService    : ClientUserAuthService(ClientSessionImpl[null@u@h:0000]) client methods: [publickey, keyboard-interactive, password]
[resume-thread-1] o.a.s.c.s.h.SessionTimeoutListener       : sessionCreated(ClientSessionImpl[null@u@h:0000]) tracking
[resume-thread-1] o.a.s.client.session.ClientSessionImpl   : initializeProxyConnector(ClientSessionImpl[null@u@h:0000]) no proxy to initialize
[resume-thread-1] o.a.s.client.session.ClientSessionImpl   : sendIdentification(ClientSessionImpl[null@u@h:0000]): SSH-2.0-APACHE-SSHD-2.12.1
[resume-thread-1] o.a.sshd.common.io.nio2.Nio2Session      : writeBuffer(Nio2Session[local=/[0:0:0:0:0:0:0:0]:51397, remote=u@h:0000]) writing 28 bytes
[resume-thread-1] o.a.s.client.session.ClientSessionImpl   : sendKexInit(ClientSessionImpl[null@u@h:0000]) Send SSH_MSG_KEXINIT
[resume-thread-1] o.a.s.client.session.ClientSessionImpl   : encode(ClientSessionImpl[null@u@h:0000]) packet #0 sending command=20[SSH_MSG_KEXINIT] len=1263
[resume-thread-1] o.a.sshd.common.io.nio2.Nio2Session      : writeBuffer(Nio2Session[local=/[0:0:0:0:0:0:0:0]:51397, remote=u@h:0000]) writing 1280 bytes
[resume-thread-1] org.apache.sshd.client.SshClient         : setupDefaultSessionIdentities(ClientSessionImpl[u@h/0.0.0.0:0000]) key identity provider override in session listener
[           main] o.a.s.c.future.DefaultConnectFuture      : Connected to u@h:0000 after 120555500 nanos
[]-nio2-thread-3] o.a.s.client.session.ClientSessionImpl   : doReadIdentification(ClientSessionImpl[u@h/0.0.0.0:0000]) line='SSH-2.0-Non Prod'
[]-nio2-thread-3] o.a.s.client.session.ClientSessionImpl   : readIdentification(ClientSessionImpl[u@h/0.0.0.0:0000]) Server version string: SSH-2.0-Non Prod
[           main] o.a.s.client.session.ClientSessionImpl   : addPasswordIdentity(ClientSessionImpl[u@h/0.0.0.0:0000]) SHA256:LvaGli54SHl/MkK56R689OKpHgVSQZRJZNOG+N+Z2UY
[]-nio2-thread-4] o.a.s.client.session.ClientSessionImpl   : doHandleMessage(ClientSessionImpl[u@h/0.0.0.0:0000]) process #0 SSH_MSG_KEXINIT
[]-nio2-thread-4] o.a.s.client.session.ClientSessionImpl   : handleKexInit(ClientSessionImpl[u@h/0.0.0.0:0000]) SSH_MSG_KEXINIT
[]-nio2-thread-4] o.a.s.client.session.ClientSessionImpl   : negotiate(ClientSessionImpl[u@h/0.0.0.0:0000]) strict KEX=false client=true server=false
[]-nio2-thread-4] o.a.s.client.session.ClientSessionImpl   : setNegotiationResult(ClientSessionImpl[u@h/0.0.0.0:0000]) Kex: kex algorithms = curve25519-sha256@libssh.org
[]-nio2-thread-4] o.a.s.client.session.ClientSessionImpl   : setNegotiationResult(ClientSessionImpl[u@h/0.0.0.0:0000]) Kex: server host key algorithms = ssh-rsa
[]-nio2-thread-4] o.a.s.client.session.ClientSessionImpl   : setNegotiationResult(ClientSessionImpl[u@h/0.0.0.0:0000]) Kex: encryption algorithms (client to server) = aes128-ctr
[]-nio2-thread-4] o.a.s.client.session.ClientSessionImpl   : setNegotiationResult(ClientSessionImpl[u@h/0.0.0.0:0000]) Kex: encryption algorithms (server to client) = aes128-ctr
[]-nio2-thread-4] o.a.s.client.session.ClientSessionImpl   : setNegotiationResult(ClientSessionImpl[u@h/0.0.0.0:0000]) Kex: mac algorithms (client to server) = hmac-sha2-256
[]-nio2-thread-4] o.a.s.client.session.ClientSessionImpl   : setNegotiationResult(ClientSessionImpl[u@h/0.0.0.0:0000]) Kex: mac algorithms (server to client) = hmac-sha2-256
[]-nio2-thread-4] o.a.s.client.session.ClientSessionImpl   : setNegotiationResult(ClientSessionImpl[u@h/0.0.0.0:0000]) Kex: compression algorithms (client to server) = none
[]-nio2-thread-4] o.a.s.client.session.ClientSessionImpl   : setNegotiationResult(ClientSessionImpl[u@h/0.0.0.0:0000]) Kex: compression algorithms (server to client) = none
[]-nio2-thread-4] org.apache.sshd.client.kex.DHGClient     : init(DHGClient[curve25519-sha256@libssh.org])[ClientSessionImpl[u@h/0.0.0.0:0000]] Send SSH_MSG_KEXDH_INIT
[]-nio2-thread-4] o.a.s.client.session.ClientSessionImpl   : encode(ClientSessionImpl[u@h/0.0.0.0:0000]) packet #1 sending command=30[30] len=37
[]-nio2-thread-4] o.a.sshd.common.io.nio2.Nio2Session      : writeBuffer(Nio2Session[local=/[0:0:0:0:0:0:0:0]:51397, remote=u@h:0000]) writing 56 bytes
[]-nio2-thread-6] o.a.s.client.session.ClientSessionImpl   : doHandleMessage(ClientSessionImpl[u@h/0.0.0.0:0000]) process #1 31
[]-nio2-thread-6] org.apache.sshd.client.kex.DHGClient     : next(DHGClient[curve25519-sha256@libssh.org])[ClientSessionImpl[u@h/0.0.0.0:0000]] process command=SSH_MSG_KEXDH_REPLY
[]-nio2-thread-6] o.a.s.client.session.ClientSessionImpl   : setServerKey(ClientSessionImpl[u@h/0.0.0.0:0000]) keyType=ssh-rsa, digest=SHA256:vTnNRJDvfSPi0q8pqZ8aXj9xFwA1F6uVaYYQHhX2n+w
[]-nio2-thread-6] o.a.s.client.session.ClientSessionImpl   : handleKexMessage(ClientSessionImpl[u@h/0.0.0.0:0000])[curve25519-sha256@libssh.org] KEX processing complete after cmd=31
[]-nio2-thread-6] o.a.s.c.k.AcceptAllServerKeyVerifier     : Server at u@h:0000 presented unverified RSA key: SHA256:vTnNRJDvfSPi0q8pqZ8aXj9xFwA1F6uVaYYQHhX2n+w
[]-nio2-thread-6] o.a.s.client.session.ClientSessionImpl   : checkKeys(ClientSessionImpl[u@h/0.0.0.0:0000]) key=ssh-rsa-SHA256:vTnNRJDvfSPi0q8pqZ8aXj9xFwA1F6uVaYYQHhX2n+w, verified=true
[]-nio2-thread-6] o.a.s.client.session.ClientSessionImpl   : sendNewKeys(ClientSessionImpl[u@h/0.0.0.0:0000]) Send SSH_MSG_NEWKEYS
[]-nio2-thread-6] o.a.s.client.session.ClientSessionImpl   : prepareNewKeys(ClientSessionImpl[u@h/0.0.0.0:0000]) session ID=1c:63:44:83:5f:79:16:3a:f5:d7:ee:dd:de:44:75:6b:ff:32:1d:70:f0:f5:34:e5:c5:d5:bd:87:c2:59:a8:95
[]-nio2-thread-6] o.a.s.client.session.ClientSessionImpl   : encode(ClientSessionImpl[u@h/0.0.0.0:0000]) packet #2 sending command=21[SSH_MSG_NEWKEYS] len=1
[]-nio2-thread-6] o.a.sshd.common.io.nio2.Nio2Session      : writeBuffer(Nio2Session[local=/[0:0:0:0:0:0:0:0]:51397, remote=u@h:0000]) writing 16 bytes
[]-nio2-thread-6] o.a.s.client.session.ClientSessionImpl   : setOutputEncoding(ClientSessionImpl[u@h/0.0.0.0:0000]): cipher BaseCipher[AES, ivSize=16, kdfSize=16,AES/CTR/NoPadding, blkSize=16]; mac BaseMac[HmacSHA256] -  block=32/32 bytes, encrypt-then-mac=false; compression none[Deflater/-1]; blocks limit 134217728
[]-nio2-thread-6] o.a.s.client.session.ClientSessionImpl   : handleNewKeys(ClientSessionImpl[u@h/0.0.0.0:0000]) No pending packets to flush at end of KEX
[]-nio2-thread-8] o.a.s.client.session.ClientSessionImpl   : doHandleMessage(ClientSessionImpl[u@h/0.0.0.0:0000]) process #2 SSH_MSG_NEWKEYS
[]-nio2-thread-8] o.a.s.client.session.ClientSessionImpl   : handleNewKeys(ClientSessionImpl[u@h/0.0.0.0:0000]) SSH_MSG_NEWKEYS command=SSH_MSG_NEWKEYS
[]-nio2-thread-8] o.a.s.client.session.ClientSessionImpl   : setInputEncoding(ClientSessionImpl[u@h/0.0.0.0:0000]): cipher BaseCipher[AES, ivSize=16, kdfSize=16,AES/CTR/NoPadding, blkSize=16]; mac BaseMac[HmacSHA256] -  block=32/32 bytes, encrypt-then-mac=false; compression none[Inflater/-1]; blocks limit 4294967296
[]-nio2-thread-8] o.a.s.client.session.ClientSessionImpl   : sendInitialServiceRequest(ClientSessionImpl[u@h/0.0.0.0:0000]) Send SSH_MSG_SERVICE_REQUEST for ssh-userauth
[]-nio2-thread-8] o.a.s.client.session.ClientSessionImpl   : encode(ClientSessionImpl[u@h/0.0.0.0:0000]) packet #3 sending command=5[SSH_MSG_SERVICE_REQUEST] len=17
[]-nio2-thread-8] o.a.sshd.common.io.nio2.Nio2Session      : writeBuffer(Nio2Session[local=/[0:0:0:0:0:0:0:0]:51397, remote=u@h:0000]) writing 80 bytes
[]-nio2-thread-8] o.a.s.c.session.ClientUserAuthService    : auth(ClientSessionImpl[u@h/0.0.0.0:0000])[ssh-connection] send SSH_MSG_USERAUTH_REQUEST for 'none'
[]-nio2-thread-8] o.a.s.client.session.ClientSessionImpl   : encode(ClientSessionImpl[u@h/0.0.0.0:0000]) packet #4 sending command=50[SSH_MSG_USERAUTH_REQUEST] len=46
[]-nio2-thread-8] o.a.sshd.common.io.nio2.Nio2Session      : writeBuffer(Nio2Session[local=/[0:0:0:0:0:0:0:0]:51397, remote=u@h:0000]) writing 112 bytes
[]-nio2-thread-2] o.a.s.client.session.ClientSessionImpl   : doHandleMessage(ClientSessionImpl[u@h/0.0.0.0:0000]) process #3 SSH_MSG_SERVICE_ACCEPT
[]-nio2-thread-2] o.a.s.client.session.ClientSessionImpl   : handleServiceAccept(ClientSessionImpl[u@h/0.0.0.0:0000]) SSH_MSG_SERVICE_ACCEPT service=ssh-userauth
[]-nio2-thread-3] o.a.s.client.session.ClientSessionImpl   : doHandleMessage(ClientSessionImpl[u@h/0.0.0.0:0000]) process #4 SSH_MSG_USERAUTH_FAILURE
[]-nio2-thread-3] o.a.s.c.session.ClientUserAuthService    : processUserAuth(ClientSessionImpl[u@h/0.0.0.0:0000]) Received SSH_MSG_USERAUTH_FAILURE - partial=false, methods=password,keyboard-interactive
[]-nio2-thread-3] o.a.s.c.session.ClientUserAuthService    : tryNext(ClientSessionImpl[u@h/0.0.0.0:0000]) starting authentication mechanisms: client=[publickey, keyboard-interactive, password], server=[password, keyboard-interactive]
[]-nio2-thread-3] o.a.s.c.session.ClientUserAuthService    : tryNext(ClientSessionImpl[u@h/0.0.0.0:0000]) attempting method=keyboard-interactive
[]-nio2-thread-3] o.a.s.c.a.k.UserAuthKeyboardInteractive  : verifyTrialsCount(ClientSessionImpl[u@h/0.0.0.0:0000])[ssh-connection] cmd=SSH_MSG_USERAUTH_REQUEST - 1 out of 3
[]-nio2-thread-3] o.a.s.c.a.k.UserAuthKeyboardInteractive  : sendAuthDataRequest(ClientSessionImpl[u@h/0.0.0.0:0000])[ssh-connection] send SSH_MSG_USERAUTH_REQUEST for keyboard-interactive: lang=, methods=
[]-nio2-thread-3] o.a.s.client.session.ClientSessionImpl   : encode(ClientSessionImpl[u@h/0.0.0.0:0000]) packet #5 sending command=50[SSH_MSG_USERAUTH_REQUEST] len=70
[]-nio2-thread-3] o.a.sshd.common.io.nio2.Nio2Session      : writeBuffer(Nio2Session[local=/[0:0:0:0:0:0:0:0]:51397, remote=u@h:0000]) writing 128 bytes
[]-nio2-thread-3] o.a.s.c.session.ClientUserAuthService    : tryNext(ClientSessionImpl[u@h/0.0.0.0:0000]) successfully processed initial buffer by method=keyboard-interactive
[]-nio2-thread-5] o.a.s.client.session.ClientSessionImpl   : doHandleMessage(ClientSessionImpl[u@h/0.0.0.0:0000]) process #5 60
[]-nio2-thread-5] o.a.s.c.session.ClientUserAuthService    : processUserAuth(ClientSessionImpl[u@h/0.0.0.0:0000]) delegate processing of 60 to keyboard-interactive
[]-nio2-thread-5] o.a.s.c.a.k.UserAuthKeyboardInteractive  : processAuthDataRequest(ClientSessionImpl[u@h/0.0.0.0:0000])[ssh-connection] SSH_MSG_USERAUTH_INFO_REQUEST name=Password authentication, instruction=, language=, num-prompts=1
[]-nio2-thread-5] o.a.s.c.a.k.UserAuthKeyboardInteractive  : getUserResponses(ClientSessionImpl[u@h/0.0.0.0:0000]) no user interaction for name=Password authentication
[]-nio2-thread-5] o.a.s.c.a.k.UserAuthKeyboardInteractive  : processAuthDataRequest(ClientSessionImpl[u@h/0.0.0.0:0000])[ssh-connection] no responses for Password authentication
[]-nio2-thread-5] o.a.s.c.a.k.UserAuthKeyboardInteractive  : verifyTrialsCount(ClientSessionImpl[u@h/0.0.0.0:0000])[ssh-connection] cmd=SSH_MSG_USERAUTH_REQUEST - 2 out of 3
[]-nio2-thread-5] o.a.s.c.a.k.UserAuthKeyboardInteractive  : sendAuthDataRequest(ClientSessionImpl[u@h/0.0.0.0:0000])[ssh-connection] send SSH_MSG_USERAUTH_REQUEST for keyboard-interactive: lang=, methods=
[]-nio2-thread-5] o.a.s.client.session.ClientSessionImpl   : encode(ClientSessionImpl[u@h/0.0.0.0:0000]) packet #6 sending command=50[SSH_MSG_USERAUTH_REQUEST] len=70
[]-nio2-thread-5] o.a.sshd.common.io.nio2.Nio2Session      : writeBuffer(Nio2Session[local=/[0:0:0:0:0:0:0:0]:51397, remote=u@h:0000]) writing 128 bytes
[]-nio2-thread-5] o.a.s.c.session.ClientUserAuthService    : tryNext(ClientSessionImpl[u@h/0.0.0.0:0000]) successfully processed initial buffer by method=keyboard-interactive
[-timer-thread-1] o.a.s.client.session.ClientSessionImpl   : checkForTimeouts(ClientSessionImpl[u@h/0.0.0.0:0000]) disconnect - reason=TimeoutIndicator[status=AuthTimeout, threshold=120000, expired=120800]
[-timer-thread-1] o.a.s.client.session.ClientSessionImpl   : Disconnecting(ClientSessionImpl[u@h/0.0.0.0:0000]): SSH2_DISCONNECT_PROTOCOL_ERROR - Detected AuthTimeout after 120800/120000 ms.
[-timer-thread-1] o.a.s.client.session.ClientSessionImpl   : encode(ClientSessionImpl[u@h/0.0.0.0:0000]) packet #7 sending command=1[SSH_MSG_DISCONNECT] len=57
[-timer-thread-1] o.a.sshd.common.io.nio2.Nio2Session      : writeBuffer(Nio2Session[local=/[0:0:0:0:0:0:0:0]:51397, remote=u@h:0000]) writing 112 bytes
[-timer-thread-1] o.a.s.client.session.ClientSessionImpl   : disconnect(ClientSessionImpl[u@h/0.0.0.0:0000]) operation successfully completed for reason=SSH2_DISCONNECT_PROTOCOL_ERROR [Detected AuthTimeout after 120800/120000 ms.]
[-timer-thread-1] o.a.s.client.session.ClientSessionImpl   : close(ClientSessionImpl[u@h/0.0.0.0:0000]) Closing immediately
[-timer-thread-1] o.a.s.client.session.ClientSessionImpl   : signalAuthFailure(ClientSessionImpl[u@h/0.0.0.0:0000]) type=SshException, signalled=true, first=false: Session is being closed
[-timer-thread-1] o.a.s.c.s.h.SessionTimeoutListener       : sessionClosed(ClientSessionImpl[u@h/0.0.0.0:0000]) un-tracked
[-timer-thread-1] o.a.s.c.session.ClientUserAuthService    : close(org.apache.sshd.client.session.ClientUserAuthService@4536c813) Closing immediately
org.apache.sshd.common.SshException: Session is being closed
    at org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:141)
    at org.apache.sshd.client.future.DefaultAuthFuture.verify(DefaultAuthFuture.java:56)
    at org.apache.sshd.client.future.DefaultAuthFuture.verify(DefaultAuthFuture.java:35)
    at org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43)
    at com.example.sftpdebug.SftpdebugApplication.main(SftpdebugApplication.java:42)
Caused by: org.apache.sshd.common.SshException: Session is being closed
    at org.apache.sshd.client.session.ClientSessionImpl.preClose(ClientSessionImpl.java:169)
    at org.apache.sshd.common.util.closeable.AbstractCloseable.close(AbstractCloseable.java:94)
    at org.apache.sshd.common.session.helpers.SessionHelper.lambda$disconnect$9(SessionHelper.java:1213)
    at org.apache.sshd.common.future.AbstractSshFuture.lambda$notifyListener$3(AbstractSshFuture.java:178)
    at org.apache.sshd.common.util.threads.ThreadUtils.runAsInternal(ThreadUtils.java:68)
    at org.apache.sshd.common.future.AbstractSshFuture.notifyListener(AbstractSshFuture.java:177)
    at org.apache.sshd.common.future.DefaultSshFuture.addListener(DefaultSshFuture.java:214)
    at org.apache.sshd.common.session.helpers.SessionHelper.disconnect(SessionHelper.java:1197)
    at org.apache.sshd.common.session.helpers.SessionHelper.checkForTimeouts(SessionHelper.java:301)
    at org.apache.sshd.common.session.helpers.SessionTimeoutListener.run(SessionTimeoutListener.java:84)
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
    at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305)
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    at java.base/java.lang.Thread.run(Thread.java:833)
[ionShutdownHook] s.c.a.AnnotationConfigApplicationContext : Closing org.springframework.context.annotation.AnnotationConfigApplicationContext@63eef88a, started on Wed May 08 14:39:16 EEST 2024
[-timer-thread-1] o.a.s.c.session.ClientUserAuthService    : close(org.apache.sshd.client.session.ClientUserAuthService@4536c813)[Immediately] closed
[-timer-thread-1] o.a.s.c.session.ClientConnectionService  : close(ClientConnectionService[ClientSessionImpl[u@h/0.0.0.0:0000]]) Closing immediately
[-timer-thread-1] o.a.s.c.session.ClientConnectionService  : stopHeartBeat(ClientSessionImpl[u@h/0.0.0.0:0000]) no heartbeat to stop
[-timer-thread-1] o.a.s.c.session.ClientConnectionService  : close(ClientConnectionService[ClientSessionImpl[u@h/0.0.0.0:0000]])[Immediately] closed
[-timer-thread-1] o.a.sshd.common.io.nio2.Nio2Session      : close(Nio2Session[local=/[0:0:0:0:0:0:0:0]:51397, remote=u@h:0000]) Closing immediately
[-timer-thread-1] o.a.sshd.common.io.nio2.Nio2Session      : doCloseImmediately(Nio2Session[local=/[0:0:0:0:0:0:0:0]:51397, remote=u@h:0000]) closing socket=sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected local=/[0:0:0:0:0:0:0:0]:51397 remote=u@h:0000]
[ionShutdownHook] o.s.c.support.DefaultLifecycleProcessor  : Stopping beans in phase -2147483647
[-timer-thread-1] o.a.sshd.common.io.nio2.Nio2Session      : doCloseImmediately(Nio2Session[local=/[0:0:0:0:0:0:0:0]:51397, remote=u@h:0000]) socket=sun.nio.ch.WindowsAsynchronousSocketChannelImpl[closed] closed
[-timer-thread-1] o.a.sshd.common.io.nio2.Nio2Connector    : unmapSession(id=101): Nio2Session[local=/[0:0:0:0:0:0:0:0]:51397, remote=u@h:0000]
[-timer-thread-1] o.a.s.client.session.ClientSessionImpl   : close(ClientSessionImpl[u@h/0.0.0.0:0000])[Immediately] state already Immediate
[-timer-thread-1] o.a.sshd.common.io.nio2.Nio2Session      : close(Nio2Session[local=/[0:0:0:0:0:0:0:0]:51397, remote=u@h:0000])[Immediately] closed
[-timer-thread-1] o.a.s.c.u.closeable.SequentialCloseable  : doClose(org.apache.sshd.common.util.closeable.SequentialCloseable$1@67462be7) signal close complete immediately=true
[-timer-thread-1] o.a.s.client.session.ClientSessionImpl   : close(ClientSessionImpl[u@h/0.0.0.0:0000])[Immediately] closed
[ionShutdownHook] o.s.c.support.DefaultLifecycleProcessor  : Bean 'springBootLoggingLifecycle' completed its stop procedure
[]-nio2-thread-9] o.a.sshd.common.io.nio2.Nio2Session      : handleReadCycleFailure(Nio2Session[local=/[0:0:0:0:0:0:0:0]:51397, remote=u@h:0000]) AsynchronousCloseException after 120471915900 nanos at read cycle=8: null
[ionShutdownHook] o.s.j.e.a.AnnotationMBeanExporter        : Unregistering JMX-exposed beans on shutdown
yaroslavambrozyak commented 1 month ago

I have found a solution for my case

SshClient sshClient = SshClient.setUpDefaultClient();
CoreModuleProperties.PREFERRED_AUTHS.set(sshClient, "password");

After I set a preferred auth method it started to work. To my understanding, it was using keyboard-interactive and expected some input from a user that was not provided.