[SSHD-227] ChannelSession sends SSH_MSG_CHANNEL_DATA after SSH_MSG_CHANNEL_CLOSE has been sent

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 0.8.0, 0.9.0
• Fix Version/s: 0.9.0
• Assignee: Guillaume Nodet
• Reporter: Marian Seitner
• Created: 10/Apr/13 11:59
• Updated: 19/Jul/13 05:51
• Resolved: 19/Jul/13 05:51

Description

A server-side initiated CHANNEL_CLOSE results in an exception because the client doesn't stop sending CHANNEL_DATA after itself confirming via CHANNEL_CLOSE.

In AbstractChannel.close() the CHANNEL_CLOSE message is acknowledged by responding with CHANNEL_CLOSE, but the ClientInputStreamPump thread in ChannelSession doesn't have a chance to react because the CloseFuture is closed only afterwards. ClientInputStreamPump also doesn't check if a channel is in a closing state.

Client:
[NioProcessor-8] DEBUG o.a.sshd.client.channel.ChannelExec - Received SSH_MSG_CHANNEL_CLOSE on channel 1
[NioProcessor-8] DEBUG o.a.sshd.client.channel.ChannelExec - Send SSH_MSG_CHANNEL_CLOSE on channel 1
[ClientInputStreamPump] DEBUG o.a.sshd.client.channel.ChannelExec - Send SSH_MSG_CHANNEL_DATA on channel 1

Server:
DEBUG o.a.s.server.session.ServerSession - Received packet SSH_MSG_CHANNEL_CLOSE
DEBUG o.a.s.server.channel.ChannelSession - Received SSH_MSG_CHANNEL_CLOSE on channel 1
DEBUG o.a.s.server.session.ServerSession - Received packet SSH_MSG_CHANNEL_DATA
WARN o.a.s.server.session.ServerSession - Exception caught
org.apache.sshd.common.SshException: Received SSH_MSG_CHANNEL_DATA on unknown channel 1
at org.apache.sshd.common.session.AbstractSession.getChannel(AbstractSession.java:1101) ~[sshd-core-0.9.0-SNAPSHOT.jar:0.9.0-SNAPSHOT]
at org.apache.sshd.common.session.AbstractSession.channelData(AbstractSession.java:1004) ~[sshd-core-0.9.0-SNAPSHOT.jar:0.9.0-SNAPSHOT]
at org.apache.sshd.server.session.ServerSession.running(ServerSession.java:224) ~[sshd-core-0.9.0-SNAPSHOT.jar:0.9.0-SNAPSHOT]
at org.apache.sshd.server.session.ServerSession.handleMessage(ServerSession.java:197) ~[sshd-core-0.9.0-SNAPSHOT.jar:0.9.0-SNAPSHOT]
at org.apache.sshd.common.session.AbstractSession.decode(AbstractSession.java:583) ~[sshd-core-0.9.0-SNAPSHOT.jar:0.9.0-SNAPSHOT]
at org.apache.sshd.common.session.AbstractSession.messageReceived(AbstractSession.java:254) ~[sshd-core-0.9.0-SNAPSHOT.jar:0.9.0-SNAPSHOT]
at org.apache.sshd.common.AbstractSessionIoHandler.messageReceived(AbstractSessionIoHandler.java:58) ~[sshd-core-0.9.0-SNAPSHOT.jar:0.9.0-SNAPSHOT]
at org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceived(DefaultIoFilterChain.java:716) ~[mina-core-2.0.5.jar:na]
at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434) [mina-core-2.0.5.jar:na]
at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46) [mina-core-2.0.5.jar:na]
at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:796) [mina-core-2.0.5.jar:na]
at org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:119) [mina-core-2.0.5.jar:na]
at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434) [mina-core-2.0.5.jar:na]
at org.apache.mina.core.filterchain.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:426) [mina-core-2.0.5.jar:na]
at org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:697) [mina-core-2.0.5.jar:na]
at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:651) [mina-core-2.0.5.jar:na]
at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:640) [mina-core-2.0.5.jar:na]
at org.apache.mina.core.polling.AbstractPollingIoProcessor.access$600(AbstractPollingIoProcessor.java:67) [mina-core-2.0.5.jar:na]
at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:1111) [mina-core-2.0.5.jar:na]
at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64) [mina-core-2.0.5.jar:na]
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895) [na:1.6.0_41]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918) [na:1.6.0_41]
at java.lang.Thread.run(Thread.java:662) [na:1.6.0_41]

Issue Links

• is part of: SSHD-238 Improve channel closing behaviors