[
https://issues.apache.org/jira/browse/SSHD-1307?focusedWorklogId=819792&page=com.atlassian.jira.plugin.system.issuetabpanels:worklog-tabpanel#worklog-819792
]
ASF GitHub Bot logged work on SSHD-1307:
----------------------------------------
Author: ASF GitHub Bot
Created on: 24/Oct/22 17:36
Start Date: 24/Oct/22 17:36
Worklog Time Spent: 10m
Work Description: tomaswolf commented on code in PR #257:
URL: https://github.com/apache/mina-sshd/pull/257#discussion_r1003582623
##########
sshd-core/src/main/java/org/apache/sshd/common/io/nio2/Nio2Session.java:
##########
@@ -298,24 +300,44 @@ public Nio2Service getService() {
@Override
public void shutdownOutputStream() throws IOException {
- AsynchronousSocketChannel socket = getSocket();
- if (socket.isOpen()) {
- if (log.isDebugEnabled()) {
- log.debug("shudownOutputStream({})", this);
- }
- try {
- socket.shutdownOutput();
- } catch (ClosedChannelException e) {
- // This may get called on a Channel EOF in TCP/IP port
forwarding. But reading and writing run
- // asynchronously, so it is possible that the socket channel
is actually closed here and the producer
- // that wrote into this channel has already disconnected.
- //
- // As this is asynchronous, there is a race condition here.
The isOpen() test above does not guarantee
- // that the socket channel is indeed open when we call
shutdownOutput().
- //
- // In any case it's safe here to ignore this exception as
we're trying to shut down an external end
- // of a TCP/IP port forwarding.
+ if (outputShutDown.compareAndSet(false, true)) {
+ // Schedule a "shut down the output stream" fake write packet with
a null buffer. Let already pending writes
+ // finish first.
+ Nio2DefaultIoWriteFuture future = new
Nio2DefaultIoWriteFuture("shutdown-" + getRemoteAddress(), null, null);
+ writes.add(future);
+ startWriting();
+ }
+ }
+
+ protected void doShutdownOutputStream(Nio2DefaultIoWriteFuture future,
AsynchronousSocketChannel socket)
+ throws IOException {
+ try {
+ if (socket.isOpen()) {
+ if (log.isDebugEnabled()) {
+ log.debug("doShutdownOutputStream({})", this);
+ }
+ try {
+ socket.shutdownOutput();
+ } catch (ClosedChannelException e) {
+ // This may get called on a Channel EOF in TCP/IP port
forwarding. But reading and writing run
Review Comment:
Done.
Issue Time Tracking
-------------------
Worklog Id: (was: 819792)
Time Spent: 0.5h (was: 20m)
> 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
> Time Spent: 0.5h
> 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]
