sshtools / maverick-synergy

Next Generation Java SSH API
https://jadaptive.com
GNU Lesser General Public License v3.0
90 stars 27 forks source link

java.lang.IllegalStateException: Authentication in progress! #94

Open ext-marko-parikka opened 4 months ago

ext-marko-parikka commented 4 months ago

We are running java application to move files from one place to another periodically by using Spring @Scheduled annotation. In test environment, we are executing the process every minute. The process checks if there are files to be moved.

In this test case, there are no files at all to be moved. The sshclient is created like this:

SshClientBuilder.create()
          .addIdentities(sshKeyPair)
          .withHostname(host)
          .withPort(port)
          .withUsername(username)
          .build();

And sftp client like this: SftpClientBuilder.create().withClient(sshClient).build()

Once and a while this happens: `29 May 2024 09:00:01,141 [ pool-746-thread-1] ERROR - Connection task failed with an error java.lang.IllegalStateException: Authentication in progress! at com.sshtools.client.AuthenticationProtocolClient.doNextAuthentication(AuthenticationProtocolClient.java:270) at com.sshtools.client.AuthenticationProtocolClient.processMessage(AuthenticationProtocolClient.java:205) at com.sshtools.synergy.ssh.TransportProtocol$5.doTask(TransportProtocol.java:2103) at com.sshtools.common.ssh.ConnectionAwareTask.run(ConnectionAwareTask.java:49) at com.sshtools.common.ssh.ExecutorOperationSupport$OperationTask.executeAllTasks(ExecutorOperationSupport.java:134) at com.sshtools.common.ssh.ExecutorOperationSupport$OperationTask.run(ExecutorOperationSupport.java:89) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:829)

29 May 2024 09:13:01,114 [ pool-751-thread-1] ERROR - Connection task failed with an error java.lang.IllegalStateException: Authentication in progress! at com.sshtools.client.AuthenticationProtocolClient.doNextAuthentication(AuthenticationProtocolClient.java:270) at com.sshtools.client.AuthenticationProtocolClient.processMessage(AuthenticationProtocolClient.java:205) at com.sshtools.synergy.ssh.TransportProtocol$5.doTask(TransportProtocol.java:2103) at com.sshtools.common.ssh.ConnectionAwareTask.run(ConnectionAwareTask.java:49) at com.sshtools.common.ssh.ExecutorOperationSupport$OperationTask.executeAllTasks(ExecutorOperationSupport.java:134) at com.sshtools.common.ssh.ExecutorOperationSupport$OperationTask.run(ExecutorOperationSupport.java:89) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:829)

29 May 2024 09:21:01,108 [ pool-755-thread-1] ERROR - Connection task failed with an error java.lang.IllegalStateException: Authentication in progress! at com.sshtools.client.AuthenticationProtocolClient.doNextAuthentication(AuthenticationProtocolClient.java:270) at com.sshtools.client.AuthenticationProtocolClient.processMessage(AuthenticationProtocolClient.java:205) at com.sshtools.synergy.ssh.TransportProtocol$5.doTask(TransportProtocol.java:2103) at com.sshtools.common.ssh.ConnectionAwareTask.run(ConnectionAwareTask.java:49) at com.sshtools.common.ssh.ExecutorOperationSupport$OperationTask.executeAllTasks(ExecutorOperationSupport.java:134) at com.sshtools.common.ssh.ExecutorOperationSupport$OperationTask.run(ExecutorOperationSupport.java:89) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:829)`

And when I check the code, it should never happen: if (currentAuthenticator != null) { // should never happen throw new IllegalStateException("Authentication in progress!"); }

ext-marko-parikka commented 4 months ago

These errors started to occur when we started to use version: 3.1.1. With 3.0.11 version, we did not face these kind of exceptions.

mr-mister123 commented 4 months ago

Yes, it has to do with a fix i proposed for issue 82.

now the problem happens much less often (authentication failed) but when it happens, it will result in that exception, since there is still an race-condition anywhere. i will dig deeper into it in the next days.

ext-marko-parikka commented 18 hours ago

We are facing the same issues with 3.1.2:

... 01 Oct 2024 12:16:30,309 [ pool-8-thread-1] DEBUG - SSH_MSG_USERAUTH_FAILURE received auths=publickey,password,keyboard-interactive 01 Oct 2024 12:16:30,309 [ pool-8-thread-1] DEBUG - none authentication failed 01 Oct 2024 12:16:30,309 [ scheduling-1] DEBUG - Authenticating with publickey 01 Oct 2024 12:16:30,309 [ scheduling-1] DEBUG - Authentication protocol is NOT ready 01 Oct 2024 12:16:30,310 [ scheduling-1] DEBUG - Authentication protocol is ready 01 Oct 2024 12:16:30,310 [ scheduling-1] DEBUG - Adding publickey authentication 01 Oct 2024 12:16:30,310 [ scheduling-1] DEBUG - Starting publickey authentication 01 Oct 2024 12:16:30,310 [ scheduling-1] DEBUG - Authenticating with ecdsa-sha2 ... 01 Oct 2024 12:16:30,310 [ scheduling-1] DEBUG - Verifying key ecdsa-sha2-nistp256 01 Oct 2024 12:16:30,310 [ scheduling-1] DEBUG - Encoded key ... 01 Oct 2024 12:16:30,310 [ pool-8-thread-1] ERROR - Connection task failed with an error java.lang.IllegalStateException: Authentication in progress! at com.sshtools.client.AuthenticationProtocolClient.doNextAuthentication(AuthenticationProtocolClient.java:275) at com.sshtools.client.AuthenticationProtocolClient.processMessage(AuthenticationProtocolClient.java:210) at com.sshtools.synergy.ssh.TransportProtocol$5.doTask(TransportProtocol.java:2103) at com.sshtools.common.ssh.ConnectionAwareTask.run(ConnectionAwareTask.java:49) at com.sshtools.common.ssh.ExecutorOperationSupport$OperationTask.executeAllTasks(ExecutorOperationSupport.java:134) at com.sshtools.common.ssh.ExecutorOperationSupport$OperationTask.run(ExecutorOperationSupport.java:89) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:829)