[
https://issues.apache.org/jira/browse/SSHD-1307?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Thomas Wolf resolved SSHD-1307.
-------------------------------
Fix Version/s: 2.9.2
Resolution: Fixed
PR merged.
> 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: 40m
> 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[[email protected]/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[[email protected]/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[[email protected]/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[[email protected]/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[[email protected]/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[[email protected]/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[[email protected]/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[[email protected]/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[[email protected]/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[[email protected]/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[[email protected]/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[[email protected]/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[[email protected]/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[[email protected]/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[[email protected]/10.80.104.97:22])
> result=TcpipClientChannel[id=71,
> recipient=2]-ClientSessionImpl[[email protected]/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<org.apache.sshd.common.util.closeable.SequentialCloseable$1@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<org.apache.sshd.common.util.closeable.SequentialCloseable$1@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<org.apache.sshd.common.util.closeable.SequentialCloseable$1@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[[email protected]/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[[email protected]/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: [email protected]
For additional commands, e-mail: [email protected]