[
https://issues.apache.org/jira/browse/SSHD-207?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Andrew C updated SSHD-207:
--------------------------
Description:
This is the server's log:
[2013-01-28=15:05:04.742] [NioProcessor-2] DEBUG RelaySession -
networkSessionClosed
[2013-01-28=15:05:04.742] [NioProcessor-2] DEBUG RelaySessionSshChannelSender -
Send SSH_MSG_CHANNEL_CLOSE on channel 339
[2013-01-28=15:05:04.743] [NioProcessor-4] DEBUG SshSession - Received packet
SSH_MSG_CHANNEL_CLOSE
[2013-01-28=15:05:04.743] [NioProcessor-4] DEBUG RelaySessionSshChannelSender -
Received SSH_MSG_CHANNEL_CLOSE on channel 339
[2013-01-28=15:05:04.780] [NioProcessor-4] DEBUG SshSession - Received packet
SSH_MSG_CHANNEL_EOF
[2013-01-28=15:05:04.780] [NioProcessor-4] WARN SshSession - Exception caught
org.apache.sshd.common.SshException: Received SSH_MSG_CHANNEL_EOF on unknown
channel 339
this is the client log:
[2013-01-28=15:05:04.741] [NioProcessor-2] DEBUG
RelaySessionSshChannelRecipient - Received SSH_MSG_CHANNEL_DATA on channel 339
[2013-01-28=15:05:04.741] [NioProcessor-682] DEBUG
RelaySessionSshChannelRecipient - Send SSH_MSG_CHANNEL_DATA on channel 339
[2013-01-28=15:05:04.742] [NioProcessor-682] DEBUG
RelaySessionSshChannelRecipient - Send SSH_MSG_CHANNEL_EOF on channel 339
[2013-01-28=15:05:04.743] [NioProcessor-2] DEBUG ClientSessionImpl - Received
packet SSH_MSG_CHANNEL_CLOSE
[2013-01-28=15:05:04.743] [NioProcessor-2] DEBUG
RelaySessionSshChannelRecipient - Received SSH_MSG_CHANNEL_CLOSE on channel 339
[2013-01-28=15:05:04.743] [NioProcessor-2] DEBUG
RelaySessionSshChannelRecipient - Send SSH_MSG_CHANNEL_CLOSE on channel 339
[2013-01-28=15:05:04.743] [NioProcessor-2] DEBUG
RelaySessionSshChannelRecipient - Closing channel 339 immediately
(RelaySessionSshChannelRecipient is just a hacked ChannelForwardTcpip client)
notice how order of close and eof get switched. I'm assuming it is because
this:
@Override
public void sessionClosed(IoSession session) throws Exception {
if (!closing) {
sendEof();
}
}
isn't locking other changes such as the incoming close. A simple fix would be
to just wrap it in a lock (Ditto for
was:
While testing port forwarding from an OpenSSH_5.8p2 client to a MINA SSHD
server, I noticed that after the first disconnection of a client from the
forwarded port, the entire SSH session would be disconnected. The client
command I ran was:
ssh -N -L 60443:<target>:443 -p 50022 tester@<minasshd>
Looking at the traces, I saw the following from SSHD:
13:54:12.823 [NioProcessor-1] DEBUG o.a.s.server.session.ServerSession -
Received packet SSH_MSG_CHANNEL_OPEN
13:54:12.823 [NioProcessor-1] INFO o.a.s.server.session.ServerSession -
Received SSH_MSG_CHANNEL_OPEN direct-tcpip
13:54:12.826 [NioProcessor-1] INFO o.a.s.s.channel.ChannelDirectTcpip -
Receiving request for direct tcpip: hostToConnect=<target>, portToConnect=443,
originatorIpAddress=127.0.0.1, originatorPort=54145
13:54:15.588 [NioProcessor-1] DEBUG o.a.s.server.session.ServerSession -
Received packet SSH_MSG_CHANNEL_EOF
13:54:15.589 [NioProcessor-1] INFO o.a.s.s.channel.ChannelDirectTcpip -
Received SSH_MSG_CHANNEL_EOF on channel 0
13:54:15.589 [NioProcessor-1] INFO o.a.s.s.channel.ChannelDirectTcpip - Send
SSH_MSG_CHANNEL_CLOSE on channel 0
13:54:15.590 [NioProcessor-1] DEBUG o.a.s.server.session.ServerSession -
Received packet SSH_MSG_CHANNEL_CLOSE
13:54:15.590 [NioProcessor-1] INFO o.a.s.s.channel.ChannelDirectTcpip -
Received SSH_MSG_CHANNEL_CLOSE on channel 0
13:54:15.590 [NioProcessor-1] INFO o.a.s.s.channel.ChannelDirectTcpip -
Closing channel 0 immediately
13:54:15.591 [NioProcessor-1] INFO o.a.s.s.channel.ChannelDirectTcpip -
Closing channel 0 immediately
13:54:15.593 [NioProcessor-26] INFO o.a.s.s.channel.ChannelDirectTcpip - Send
SSH_MSG_CHANNEL_EOF on channel 0
13:54:15.595 [NioProcessor-1] DEBUG o.a.s.server.session.ServerSession -
Received packet SSH_MSG_DISCONNECT
13:54:15.595 [NioProcessor-1] INFO o.a.s.server.session.ServerSession -
Received SSH_MSG_DISCONNECT (reason=2, msg=Received ieof for nonexistent
channel 2.)
13:54:15.595 [NioProcessor-1] INFO o.a.s.server.session.ServerSession -
Closing session
13:54:15.595 [NioProcessor-1] DEBUG o.a.s.server.session.ServerSession -
Closing IoSession
13:54:15.596 [NioProcessor-1] DEBUG o.a.s.server.session.ServerSession -
IoSession closed
So if I read this right, the client sends an EOF, then the server sends a
CLOSE, then the client sends a CLOSE. After all of this, the server sends back
an EOF, but the channel no longer exists at the client, which causes a
disconnection.
I looked into the source code, and figured the following change might correct
the issue:
Index:
sshd-core/src/main/java/org/apache/sshd/server/channel/ChannelDirectTcpip.java
===================================================================
---
sshd-core/src/main/java/org/apache/sshd/server/channel/ChannelDirectTcpip.java
(revision 1207930)
+++
sshd-core/src/main/java/org/apache/sshd/server/channel/ChannelDirectTcpip.java
(working copy)
@@ -109,7 +109,9 @@
@Override
public void sessionClosed(IoSession session) throws Exception {
+ if (!closing) {
sendEof();
+ }
}
};
connector.setHandler(handler);
It appears to work, but I do not know if it is correct, or if it will break
other situations. Can anyone comment on it?
> ChannelForward TCP/IP sends EOF to server after closing channel
> ---------------------------------------------------------------
>
> Key: SSHD-207
> URL: https://issues.apache.org/jira/browse/SSHD-207
> Project: MINA SSHD
> Issue Type: Bug
> Affects Versions: 0.8.0
> Reporter: Andrew C
> Assignee: Guillaume Nodet
>
> This is the server's log:
> [2013-01-28=15:05:04.742] [NioProcessor-2] DEBUG RelaySession -
> networkSessionClosed
> [2013-01-28=15:05:04.742] [NioProcessor-2] DEBUG RelaySessionSshChannelSender
> - Send SSH_MSG_CHANNEL_CLOSE on channel 339
> [2013-01-28=15:05:04.743] [NioProcessor-4] DEBUG SshSession - Received packet
> SSH_MSG_CHANNEL_CLOSE
> [2013-01-28=15:05:04.743] [NioProcessor-4] DEBUG RelaySessionSshChannelSender
> - Received SSH_MSG_CHANNEL_CLOSE on channel 339
> [2013-01-28=15:05:04.780] [NioProcessor-4] DEBUG SshSession - Received packet
> SSH_MSG_CHANNEL_EOF
> [2013-01-28=15:05:04.780] [NioProcessor-4] WARN SshSession - Exception caught
> org.apache.sshd.common.SshException: Received SSH_MSG_CHANNEL_EOF on unknown
> channel 339
> this is the client log:
> [2013-01-28=15:05:04.741] [NioProcessor-2] DEBUG
> RelaySessionSshChannelRecipient - Received SSH_MSG_CHANNEL_DATA on channel 339
> [2013-01-28=15:05:04.741] [NioProcessor-682] DEBUG
> RelaySessionSshChannelRecipient - Send SSH_MSG_CHANNEL_DATA on channel 339
> [2013-01-28=15:05:04.742] [NioProcessor-682] DEBUG
> RelaySessionSshChannelRecipient - Send SSH_MSG_CHANNEL_EOF on channel 339
> [2013-01-28=15:05:04.743] [NioProcessor-2] DEBUG ClientSessionImpl - Received
> packet SSH_MSG_CHANNEL_CLOSE
> [2013-01-28=15:05:04.743] [NioProcessor-2] DEBUG
> RelaySessionSshChannelRecipient - Received SSH_MSG_CHANNEL_CLOSE on channel
> 339
> [2013-01-28=15:05:04.743] [NioProcessor-2] DEBUG
> RelaySessionSshChannelRecipient - Send SSH_MSG_CHANNEL_CLOSE on channel 339
> [2013-01-28=15:05:04.743] [NioProcessor-2] DEBUG
> RelaySessionSshChannelRecipient - Closing channel 339 immediately
> (RelaySessionSshChannelRecipient is just a hacked ChannelForwardTcpip client)
> notice how order of close and eof get switched. I'm assuming it is because
> this:
> @Override
> public void sessionClosed(IoSession session) throws Exception {
> if (!closing) {
> sendEof();
> }
> }
> isn't locking other changes such as the incoming close. A simple fix would
> be to just wrap it in a lock (Ditto for
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira