mina-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Goldstein Lyor (JIRA)" <j...@apache.org>
Subject [jira] [Assigned] (SSHD-894) Race condition when doing async auth
Date Tue, 12 Feb 2019 10:22:00 GMT

     [ https://issues.apache.org/jira/browse/SSHD-894?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

Goldstein Lyor reassigned SSHD-894:
-----------------------------------

    Assignee: Goldstein Lyor

> 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
>            Assignee: Goldstein Lyor
>            Priority: Minor
>          Time Spent: 50m
>  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)

Mime
View raw message