You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mina.apache.org by "Thomas Wolf (Jira)" <ji...@apache.org> on 2022/11/23 22:29:00 UTC
[jira] [Commented] (SSHD-1307) Nio2Session.shutdownOutput() should wait for writes in progress
[ https://issues.apache.org/jira/browse/SSHD-1307?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17637979#comment-17637979 ]
Thomas Wolf commented on SSHD-1307:
-----------------------------------
Sorry for having missed that. Yes, it is. 2.9.2 was released a few days ago. It does include this fix.
> Nio2Session.shutdownOutput() should wait for writes in progress
> ---------------------------------------------------------------
>
> Key: SSHD-1307
> URL: https://issues.apache.org/jira/browse/SSHD-1307
> Project: MINA SSHD
> Issue Type: Bug
> Affects Versions: 2.9.1
> Reporter: Thomas Wolf
> Assignee: Thomas Wolf
> Priority: Major
> Fix For: 2.9.2
>
> Time Spent: 1h
> Remaining Estimate: 0h
>
> Split out from [SSHD-1055|https://issues.apache.org/jira/browse/SSHD-1055?focusedCommentId=17621354&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-17621354]:
> I am currently experiencing an exception that appears to be related to the use of the serverSession.shudownOutputStream(); in the TcpIpClientChannel.handleEOF method.
> My context is the following
> * Apache Mina sshd client version 2.9.1 on the local side.
> * OpenSSH 5.9 on the remote server side.
> * Local port forwarding port 9000 to remote localhost:8080
> * The error occurs on the Apache Mina sshd client side.
> I intermittently take exceptions on URL connections that are completed and they have received the last of the data and is processing the SSH_MSG_CHANNEL_EOF
> Any ideas or thoughts would be appreciated.
> {code:java}
> 09:16:42.873 [sshd-SshClient[477424ca]-nio2-thread-8] DEBUG org.apache.sshd.common.forward.TcpipClientChannel - handleData(TcpipClientChannel[id=71, recipient=2]-ClientSessionImpl[root@elib17.us.oracle.com/10.80.104.97:22]) SSH_MSG_CHANNEL_DATA len=999
> 09:16:42.873 [sshd-SshClient[477424ca]-nio2-thread-8] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - writeBuffer(Nio2Session[local=/127.0.0.1:9000, remote=/127.0.0.1:62027]) writing 999 bytes
> 09:16:42.873 [sshd-SshClient[477424ca]-nio2-thread-8] DEBUG org.apache.sshd.common.forward.TcpipClientChannel - handleData(TcpipClientChannel[id=71, recipient=2]-ClientSessionImpl[root@elib17.us.oracle.com/10.80.104.97:22]) SSH_MSG_CHANNEL_DATA len=2
> 09:16:42.873 [sshd-SshClient[477424ca]-nio2-thread-8] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - writeBuffer(Nio2Session[local=/127.0.0.1:9000, remote=/127.0.0.1:62027]) writing 2 bytes
> 09:16:42.873 [sshd-SshClient[477424ca]-nio2-thread-8] DEBUG org.apache.sshd.common.forward.TcpipClientChannel - handleData(TcpipClientChannel[id=71, recipient=2]-ClientSessionImpl[root@elib17.us.oracle.com/10.80.104.97:22]) SSH_MSG_CHANNEL_DATA len=115
> 09:16:42.873 [sshd-SshClient[477424ca]-nio2-thread-8] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - writeBuffer(Nio2Session[local=/127.0.0.1:9000, remote=/127.0.0.1:62027]) writing 115 bytes
> 09:16:42.873 [sshd-SshClient[477424ca]-nio2-thread-8] DEBUG org.apache.sshd.common.forward.TcpipClientChannel - handleEof(TcpipClientChannel[id=71, recipient=2]-ClientSessionImpl[root@elib17.us.oracle.com/10.80.104.97:22]) SSH_MSG_CHANNEL_EOF
> 09:16:42.873 [sshd-SshClient[477424ca]-nio2-thread-8] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - shudownOutputStream(Nio2Session[local=/127.0.0.1:9000, remote=/127.0.0.1:62027])
> 09:16:42.875 [sshd-SshClient[477424ca]-nio2-thread-6] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - handleWriteCycleFailure(Nio2Session[local=/127.0.0.1:9000, remote=/127.0.0.1:62027]) failed (ClosedChannelException) to write 115 bytes at write cycle=17 afer 987500 nanos: null
> 09:16:42.875 [sshd-SshClient[477424ca]-nio2-thread-6] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - exceptionCaught(Nio2Session[local=/127.0.0.1:9000, remote=/127.0.0.1:62027]) caught ClosedChannelException[null] - calling handler
> 09:16:42.879 [sshd-SshClient[477424ca]-nio2-thread-4] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - handleReadCycleCompletion(Nio2Session[local=/127.0.0.1:9000, remote=/127.0.0.1:62027]) Socket has been disconnected (result=-1), closing IoSession now
> 09:16:42.879 [sshd-SshClient[477424ca]-nio2-thread-4] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - close(Nio2Session[local=/127.0.0.1:9000, remote=/127.0.0.1:62027]) Closing immediately
> 09:16:42.879 [sshd-SshClient[477424ca]-nio2-thread-4] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - doCloseImmediately(Nio2Session[local=/127.0.0.1:9000, remote=/127.0.0.1:62027]) closing socket=sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected oshut local=/127.0.0.1:9000 remote=/127.0.0.1:62027]
> 09:16:42.879 [sshd-SshClient[477424ca]-nio2-thread-4] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - doCloseImmediately(Nio2Session[local=/127.0.0.1:9000, remote=/127.0.0.1:62027]) socket=sun.nio.ch.WindowsAsynchronousSocketChannelImpl[closed] closed
> 09:16:42.880 [sshd-SshClient[477424ca]-nio2-thread-4] DEBUG org.apache.sshd.common.io.nio2.Nio2Acceptor - unmapSession(id=168): Nio2Session[local=/127.0.0.1:9000, remote=/127.0.0.1:62027]
> 09:16:42.880 [sshd-SshClient[477424ca]-nio2-thread-4] DEBUG org.apache.sshd.common.forward.DefaultForwarder - sessionClosed(Nio2Session[local=/127.0.0.1:9000, remote=/127.0.0.1:62027]) closing channel=TcpipClientChannel[id=71, recipient=2]-ClientSessionImpl[root@elib17.us.oracle.com/10.80.104.97:22] after 67 messages - cause=ClosedChannelException
> 09:16:42.880 [sshd-SshClient[477424ca]-nio2-thread-4] DEBUG org.apache.sshd.common.forward.TcpipClientChannel - close(TcpipClientChannel[id=71, recipient=2]-ClientSessionImpl[root@elib17.us.oracle.com/10.80.104.97:22]) Closing immediately
> 09:16:42.880 [sshd-SshClient[477424ca]-nio2-thread-4] DEBUG org.apache.sshd.common.forward.TcpipClientChannel - close(TcpipClientChannel[id=71, recipient=2]-ClientSessionImpl[root@elib17.us.oracle.com/10.80.104.97:22]) no EOF sent
> 09:16:42.880 [sshd-SshClient[477424ca]-nio2-thread-4] DEBUG org.apache.sshd.common.channel.Window - Closing Window[client/local](TcpipClientChannel[id=71, recipient=2]-ClientSessionImpl[root@elib17.us.oracle.com/10.80.104.97:22])
> 09:16:42.880 [sshd-SshClient[477424ca]-nio2-thread-4] DEBUG org.apache.sshd.common.channel.Window - Closing Window[client/remote](TcpipClientChannel[id=71, recipient=2]-ClientSessionImpl[root@elib17.us.oracle.com/10.80.104.97:22])
> 09:16:42.880 [sshd-SshClient[477424ca]-nio2-thread-4] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - close(Nio2Session[local=/127.0.0.1:9000, remote=/127.0.0.1:62027])[Immediately] state already Closed
> 09:16:42.880 [sshd-SshClient[477424ca]-nio2-thread-4] DEBUG org.apache.sshd.common.forward.TcpipClientChannel$1 - close([TcpipClientChannel[id=71, recipient=2]-ClientSessionImpl[root@elib17.us.oracle.com/10.80.104.97:22]] cmd=SSH_MSG_CHANNEL_DATA) Closing immediately
> 09:16:42.880 [sshd-SshClient[477424ca]-nio2-thread-4] DEBUG org.apache.sshd.common.forward.TcpipClientChannel$1 - close([TcpipClientChannel[id=71, recipient=2]-ClientSessionImpl[root@elib17.us.oracle.com/10.80.104.97:22]] cmd=SSH_MSG_CHANNEL_DATA)[Immediately] closed
> 09:16:42.880 [sshd-SshClient[477424ca]-nio2-thread-4] DEBUG org.apache.sshd.common.channel.ChannelAsyncInputStream - close(ChannelAsyncInputStream[TcpipClientChannel[id=71, recipient=2]-ClientSessionImpl[root@elib17.us.oracle.com/10.80.104.97:22]]) Closing immediately
> 09:16:42.880 [sshd-SshClient[477424ca]-nio2-thread-4] DEBUG org.apache.sshd.common.channel.ChannelAsyncInputStream - close(ChannelAsyncInputStream[TcpipClientChannel[id=71, recipient=2]-ClientSessionImpl[root@elib17.us.oracle.com/10.80.104.97:22]])[Immediately] closed
> 09:16:42.880 [sshd-SshClient[477424ca]-nio2-thread-4] DEBUG org.apache.sshd.common.channel.AbstractChannel$GracefulChannelCloseable - close(TcpipClientChannel[id=71, recipient=2]-ClientSessionImpl[root@elib17.us.oracle.com/10.80.104.97:22])[immediately=true] processing
> 09:16:42.880 [sshd-SshClient[477424ca]-nio2-thread-4] DEBUG org.apache.sshd.client.session.ClientConnectionService - unregisterChannel(TcpipClientChannel[id=71, recipient=2]-ClientSessionImpl[root@elib17.us.oracle.com/10.80.104.97:22]) result=TcpipClientChannel[id=71, recipient=2]-ClientSessionImpl[root@elib17.us.oracle.com/10.80.104.97:22]
> 09:16:42.880 [sshd-SshClient[477424ca]-nio2-thread-4] DEBUG org.apache.sshd.common.util.closeable.SequentialCloseable - doClose(org.apache.sshd.common.util.closeable.SequentialCloseable$1@21cadb52<or...@21cadb52>) signal close complete immediately=true
> 09:16:42.880 [sshd-SshClient[477424ca]-nio2-thread-4] DEBUG org.apache.sshd.common.util.closeable.SequentialCloseable - doClose(org.apache.sshd.common.util.closeable.SequentialCloseable$1@28848783<or...@28848783>) signal close complete immediately=true
> 09:16:42.880 [sshd-SshClient[477424ca]-nio2-thread-4] DEBUG org.apache.sshd.common.util.closeable.SequentialCloseable - doClose(org.apache.sshd.common.util.closeable.SequentialCloseable$1@73eedba7<or...@73eedba7>) signal close complete immediately=true
> 09:16:42.880 [sshd-SshClient[477424ca]-nio2-thread-4] DEBUG org.apache.sshd.common.forward.TcpipClientChannel - close(TcpipClientChannel[id=71, recipient=2]-ClientSessionImpl[root@elib17.us.oracle.com/10.80.104.97:22])[Immediately] closed
> 09:16:42.880 [sshd-SshClient[477424ca]-nio2-thread-4] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - close(Nio2Session[local=/127.0.0.1:9000, remote=/127.0.0.1:62027])[Immediately] closed
> 09:16:42.883 [sshd-SshClient[477424ca]-nio2-thread-6] WARN org.apache.sshd.common.forward.DefaultForwarder - exceptionCaught(Nio2Session[local=/127.0.0.1:9000, remote=/127.0.0.1:62027]) ClosedChannelException: null
> java.nio.channels.ClosedChannelException: null
> at sun.nio.ch.AsynchronousSocketChannelImpl.write(Unknown Source)
> at sun.nio.ch.AsynchronousSocketChannelImpl.write(Unknown Source)
> at org.apache.sshd.common.io.nio2.Nio2Session.doWriteCycle(Nio2Session.java:492)
> at org.apache.sshd.common.io.nio2.Nio2Session.startWriting(Nio2Session.java:475)
> at org.apache.sshd.common.io.nio2.Nio2Session.finishWrite(Nio2Session.java:564)
> at org.apache.sshd.common.io.nio2.Nio2Session.handleCompletedWriteCycle(Nio2Session.java:534)
> at org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:501)
> at org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:498)
> 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(Unknown Source)
> at sun.nio.ch.Invoker$2.run(Unknown Source)
> at sun.nio.ch.AsynchronousChannelGroupImpl$1.run(Unknown Source)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
> at java.lang.Thread.run(Unknown Source)
> 09:16:42.883 [sshd-SshClient[477424ca]-nio2-thread-6] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - close(Nio2Session[local=/127.0.0.1:9000, remote=/127.0.0.1:62027])[Immediately] state already Closed
> 09:16:42.883 [sshd-SshClient[477424ca]-nio2-thread-6] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - close(Nio2Session[local=/127.0.0.1:9000, remote=/127.0.0.1:62027])[Immediately] state already Closed
> 09:16:58.809 [sshd-SshClient[477424ca]-nio2-thread-7] DEBUG org.apache.sshd.common.forward.TcpipClientChannel - handleData(TcpipClientChannel[id=11, recipient=1]-ClientSessionImpl[root@elib17.us.oracle.com/10.80.104.97:22]) SSH_MSG_CHANNEL_DATA len=309
> 09:16:58.809 [sshd-SshClient[477424ca]-nio2-thread-7] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - writeBuffer(Nio2Session[local=/127.0.0.1:9000, remote=/127.0.0.1:61820]) writing 309 bytes
> {code}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@mina.apache.org
For additional commands, e-mail: dev-help@mina.apache.org