mina-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Subramaniajeeva (JIRA)" <j...@apache.org>
Subject [jira] [Created] (SSHD-894) Race condition when doing async auth
Date Tue, 12 Feb 2019 04:06:00 GMT
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)

Mime
View raw message