[
https://issues.apache.org/jira/browse/SSHD-894?focusedWorklogId=197362&page=com.atlassian.jira.plugin.system.issuetabpanels:worklog-tabpanel#worklog-197362
]
ASF GitHub Bot logged work on SSHD-894:
---------------------------------------
Author: ASF GitHub Bot
Created on: 12/Feb/19 04:07
Start Date: 12/Feb/19 04:07
Worklog Time Spent: 10m
Work Description: The-Yoda commented on pull request #90: [SSHD-894] Fix
Race condition when doing async auth.
URL: https://github.com/apache/mina-sshd/pull/90
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)
This patch fixes the issue by changing the order and send the packet
after the service starts.
cc @lgoldstein @thefourtheye @sramki
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
[email protected]
Issue Time Tracking
-------------------
Worklog Id: (was: 197362)
Time Spent: 10m
Remaining Estimate: 0h
> 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
> Priority: Minor
> Time Spent: 10m
> Remaining Estimate: 0h
>
> 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)
