[
https://issues.apache.org/jira/browse/SSHD-1055?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Alexander Amador updated SSHD-1055:
-----------------------------------
Attachment: image001.png
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.
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<mailto: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<mailto: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<mailto: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
--
[Oracle]
Alexander Amador
> Remote port forwarding mode does not handle EOF properly
> --------------------------------------------------------
>
> Key: SSHD-1055
> URL: https://issues.apache.org/jira/browse/SSHD-1055
> Project: MINA SSHD
> Issue Type: Bug
> Affects Versions: 2.5.1
> Reporter: Feng Jiajie
> Assignee: Thomas Wolf
> Priority: Major
> Fix For: 2.9.0
>
> Attachments: image001.png
>
> Time Spent: 1h 10m
> Remaining Estimate: 0h
>
> I want to call the remote server's gRPC service locally through an SSH
> tunnel.
> MyApp -> MINA SSHD -> \{Internet} -> gRPC Server
> It works just fine with OpenSSH, but there is a small problem(no problems
> with core functions, only in unusual circumstances) with Mina SSHD.
> I think the problem is Mina SSHD's handling of EOF.
> Here is the example:
> Step 1. Start a gRPC server:
> Because we only need a gRPC server to reproduce the problem, so I write a
> simple version without any service:
> {code:java}
> <dependency>
> <groupId>io.grpc</groupId>
> <artifactId>grpc-netty-shaded</artifactId>
> <version>1.27.2</version>
> </dependency>
> <dependency>
> <groupId>io.grpc</groupId>
> <artifactId>grpc-protobuf</artifactId>
> <version>1.27.2</version>
> </dependency>
> <dependency>
> <groupId>io.grpc</groupId>
> <artifactId>grpc-stub</artifactId>
> <version>1.27.2</version>
> </dependency>
> {code}
> main:
> {code:java}
> import io.grpc.Server;
> import io.grpc.ServerBuilder;
> public class EmptyGrpcServer {
> public static void main(String[] args) throws Exception {
> Server server = ServerBuilder.forPort(23645).build().start();
> server.awaitTermination();
> }
> }
> {code}
> Full example can be fond here:
> [https://github.com/grpc/grpc-java/blob/master/examples/src/main/java/io/grpc/examples/helloworld/HelloWorldServer.java]
>
> Step 2. Start a MINA SSHD server:
> {code:java}
> import org.apache.sshd.server.SshServer;
> import org.apache.sshd.server.forward.AcceptAllForwardingFilter;
> import org.apache.sshd.server.keyprovider.SimpleGeneratorHostKeyProvider;
> import java.nio.file.Paths;
> public class Example1 {
> public static void main(String[] args) throws Exception {
> SshServer sshd = SshServer.setUpDefaultServer();
> sshd.setPort(12133);
> sshd.setKeyPairProvider(new
> SimpleGeneratorHostKeyProvider(Paths.get("/tmp/a.ser")));
> sshd.setPasswordAuthenticator((username, password, session) -> true);
> sshd.setForwardingFilter(AcceptAllForwardingFilter.INSTANCE);
> sshd.start();
> Thread.sleep(10000000);
> }
> }
> {code}
> Step 3. Create a channel using ssh client
> {code:java}
> ssh -o 'ExitOnForwardFailure yes' -vvv -p 12133 -f -x -N -T -R
> 0.0.0.0:0:127.0.0.1:23645 [email protected]
> {code}
> Step 4. Reproduce
> If I connect directly to the gRPC server using curl, cause gRPC using http/2,
> I would get error output like this:
> {code:java}
> $ curl 127.0.0.1:23645
> ���+Unexpected HTTP/1.x request: GET /
> $
> {code}
> Then if I do step 3 with an OpenSSH server, I would get same error output:
> {code:java}
> $ ssh -o 'ExitOnForwardFailure yes' -f -x -N -T -R 0.0.0.0:0:127.0.0.1:23645
> [email protected]
> Allocated port 13525 for remote forward to 127.0.0.1:23645
> $
> $ curl dev.kbyte.cn:13525
> ���+Unexpected HTTP/1.x request: GET /
> $
> {code}
> But when I do step 3 with MINA SSHD, curl would stuck without any output:
> {code:java}
> $ curl 127.0.0.1:55604
> {code}
> I found MINA SSHD had already got and wrote the package with the string
> "Unexpected.HTTP/1.x.request:.GET", and received SSH_MSG_CHANNEL_EOF.
> So I think handleEof should do more? like send SSH_MSG_CHANNEL_EOF to curl?
>
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
