You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mina.apache.org by "Subramaniajeeva (JIRA)" <ji...@apache.org> on 2019/02/12 04:06:00 UTC
[jira] [Created] (SSHD-894) Race condition when doing async auth
Subramaniajeeva created SSHD-894:
------------------------------------
Summary: Race condition when doing async auth
Key: SSHD-894
URL: https://issues.apache.org/jira/browse/SSHD-894
Project: MINA SSHD
Issue Type: Bug
Affects Versions: 2.2.0
Reporter: Subramaniajeeva
Currently, when doing async auth, the response is being sent to client
before starting the service with auth status set. When the client
responds back with next request, the request will reach auth service and
fail with `No current authentication mechanism for cmd=SSH_MSG_CHANNEL_OPEN`.
This happens mostly when the system starts (as, service initialization
might take time)
Here is the exception trace:
{noformat}
07:52:20.706 [sshd-SshServer[9225652]-nio2-thread-4] TRACE org.apache.sshd.server.session.ServerSessionImpl - doHandleMessage(ServerSessionImpl[null@/0:0:0:0:0:0:0:1:62743]) process SSH_MSG_USERAUTH_REQUEST
07:52:20.706 [sshd-SshServer[9225652]-nio2-thread-4] DEBUG org.apache.sshd.server.session.ServerUserAuthService - process(ServerSessionImpl[null@/0:0:0:0:0:0:0:1:62743]) Received SSH_MSG_USERAUTH_REQUEST user=xxx, service=ssh-connection, method=password
07:52:20.706 [sshd-SshServer[9225652]-nio2-thread-4] DEBUG org.apache.sshd.server.session.ServerUserAuthService - process(ServerSessionImpl[null@/0:0:0:0:0:0:0:1:62743]) Authenticating user 'xxx' with service 'ssh-connection' and method 'password' (attempt 1 / 20)
password
07:52:21.712 [Thread-2] DEBUG org.apache.sshd.server.session.ServerUserAuthService - handleAuthenticationSuccess(xxx@ServerSessionImpl[null@/0:0:0:0:0:0:0:1:62743]) SSH_MSG_USERAUTH_REQUEST
07:52:21.712 [Thread-2] TRACE org.apache.sshd.server.session.ServerSessionImpl - encode(ServerSessionImpl[ull@/0:0:0:0:0:0:0:1:62743]) packet #5 [chunk #1](1/1) 34
07:52:21.712 [Thread-2] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - writePacket(Nio2Session[local=/0:0:0:0:0:0:0:1:2000, remote=/0:0:0:0:0:0:0:1:62743]) Writing 64 bytes
07:52:21.712 [Thread-2] TRACE org.apache.sshd.common.util.threads.SshdThreadFactory - newThread(java.lang.ThreadGroup[name=main,maxpri=10])[sshd-SshServer[9225652]-nio2-thread-5] runnable=java.util.concurrent.ThreadPoolExecutor$Worker@447ad89c[State = -1, empty queue]
07:52:21.713 [sshd-SshServer[9225652]-nio2-thread-5] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - handleCompletedWriteCycle(Nio2Session[local=/0:0:0:0:0:0:0:1:2000, remote=/0:0:0:0:0:0:0:1:62743]) finished writing len=64
07:52:21.713 [Thread-0] TRACE org.apache.sshd.common.util.threads.SshdThreadFactory - newThread(java.lang.ThreadGroup[name=main,maxpri=10])[sshd-SshServer[9225652]-nio2-thread-6] runnable=java.util.concurrent.ThreadPoolExecutor$Worker@337d9585[State = -1, empty queue]
07:52:21.714 [sshd-SshServer[9225652]-nio2-thread-6] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - handleReadCycleCompletion(Nio2Session[local=/0:0:0:0:0:0:0:1:2000, remote=/0:0:0:0:0:0:0:1:62743]) read 80 bytes
07:52:21.714 [sshd-SshServer[9225652]-nio2-thread-6] TRACE org.apache.sshd.server.session.ServerSessionImpl - decode(ServerSessionImpl[xxx@/0:0:0:0:0:0:0:1:62743]) packet #7 [chunk #1](24/24) 5a 00 00 00 07 73 65 73 73 69 6f 6e 00 00 00 01 00 20 00 00 00 00 80 00 Z....session............
07:52:21.714 [sshd-SshServer[9225652]-nio2-thread-6] TRACE org.apache.sshd.server.session.ServerSessionImpl - doHandleMessage(ServerSessionImpl[xxx@/0:0:0:0:0:0:0:1:62743]) process SSH_MSG_CHANNEL_OPEN
07:52:21.716 [Thread-2] INFO org.apache.sshd.server.session.ServerUserAuthService - Session xxx@/0:0:0:0:0:0:0:1:62743 authenticated
07:52:21.717 [sshd-SshServer[9225652]-nio2-thread-6] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - exceptionCaught(Nio2Session[local=/0:0:0:0:0:0:0:1:2000, remote=/0:0:0:0:0:0:0:1:62743]) caught IllegalStateException[No current authentication mechanism for cmd=SSH_MSG_CHANNEL_OPEN] - calling handler
07:52:21.717 [sshd-SshServer[9225652]-nio2-thread-6] WARN org.apache.sshd.server.session.ServerSessionImpl - exceptionCaught(ServerSessionImpl[xxx@/0:0:0:0:0:0:0:1:62743])[state=Opened] IllegalStateException: No current authentication mechanism for cmd=SSH_MSG_CHANNEL_OPEN
07:52:21.718 [sshd-SshServer[9225652]-nio2-thread-6] DEBUG org.apache.sshd.server.session.ServerSessionImpl - exceptionCaught(ServerSessionImpl[xxx@/0:0:0:0:0:0:0:1:62743])[state=Opened] details
java.lang.IllegalStateException: No current authentication mechanism for cmd=SSH_MSG_CHANNEL_OPEN
at org.apache.sshd.server.session.ServerUserAuthService.process(ServerUserAuthService.java:224)
at org.apache.sshd.common.session.helpers.AbstractSession.doHandleMessage(AbstractSession.java:626)
at org.apache.sshd.common.session.helpers.AbstractSession.handleMessage(AbstractSession.java:559)
at org.apache.sshd.common.session.helpers.AbstractSession.decode(AbstractSession.java:1542)
at org.apache.sshd.common.session.helpers.AbstractSession.messageReceived(AbstractSession.java:520)
at org.apache.sshd.common.session.helpers.AbstractSessionIoHandler.messageReceived(AbstractSessionIoHandler.java:63)
at org.apache.sshd.common.io.nio2.Nio2Session.handleReadCycleCompletion(Nio2Session.java:339)
at org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:318)
at org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:315)
at org.apache.sshd.common.io.nio2.Nio2CompletionHandler.lambda$completed$0(Nio2CompletionHandler.java:38)
at java.security.AccessController.doPrivileged(Native Method)
at org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:37)
at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126)
at sun.nio.ch.Invoker$2.run(Invoker.java:218)
at sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:112)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
07:52:21.719 [sshd-SshServer[9225652]-nio2-thread-6] DEBUG org.apache.sshd.common.session.helpers.SessionTimeoutListener - sessionException(ServerSessionImpl[xxx@/0:0:0:0:0:0:0:1:62743]) IllegalStateException: No current authentication mechanism for cmd=SSH_MSG_CHANNEL_OPEN
{noformat}
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)