Hello,
I am evaluating embedding Apache sshd with support for reverse port forwarding.
That is to say, I wish to execute a command on some client-host like this:
ssh -N -T -R 49501:localhost:22 user@apache-sshd-host
and then, on the apache-sshd-host server, use a command like
ssh -p 49501 client-user@localhost
to essentially ssh back to the original host. This all works fine when using
the OpenSSH server (also on apache-sshd-host), but now when I try to use Apache
sshd (with an appropriate ForwardingFilter configured) the first connection
from client-host to apache-sshd-host works find, but the second connection from
apache-sshd-host on the forward port starts but then gets reset and closed. The
syslog on client-host shows:
ssh[6394]: WARNING: Server requests forwarding for unknown listen_port 49501
ssh[6394]: channel_by_id: -1: bad id
ssh[6394]: Disconnecting: Received oclose for nonexistent channel -1.
That seems odd to me because I’m not trying to forward port 49501 on the
client. The Apache sshd log shows (here user is
"2b4580b3-5ef8-46d9-aebd-c5e6dee74a9e” and client-host is 192.168.1.55):
DEBUG o.a.sshd.common.io.nio2.Nio2Acceptor : setOption(SO_REUSEADDR)[true]
from property=socket-reuseaddr
TRACE o.a.sshd.common.io.nio2.Nio2Acceptor :
createNio2Session(org.apache.sshd.common.io.nio2.Nio2Acceptor@797e7c6b)
address=/127.0.0.1:49501
DEBUG o.a.sshd.common.io.nio2.Nio2Session : Creating IoSession on
/127.0.0.1:49501 from /127.0.0.1:52801
DEBUG o.a.s.c.forward.DefaultTcpipForwarder :
sessionCreated(Nio2Session[local=/127.0.0.1:49501, remote=/127.0.0.1:52801])
remote=null
DEBUG o.a.s.common.forward.TcpipClientChannel : init()
service=ServerConnectionService[ServerSessionImpl[2b4580b3-5ef8-46d9-aebd-c5e6dee74a9e@/192.168.1.55:44430]]
session=ServerSessionImpl[2b4580b3-5ef8-46d9-aebd-c5e6dee74a9e@/192.168.1.55:44430]
id=0
DEBUG org.apache.sshd.common.channel.Window :
init(Window[client/local](TcpipClientChannel[id=0,
recipient=-1]-ServerSessionImpl[2b4580b3-5ef8-46d9-aebd-c5e6dee74a9e@/192.168.1.55:44430]))
size=2097152, max=2097152, packet=32768
DEBUG o.a.s.s.session.ServerConnectionService :
registerChannel(ServerConnectionService[ServerSessionImpl[2b4580b3-5ef8-46d9-aebd-c5e6dee74a9e@/192.168.1.55:44430]])[id=0]
TcpipClientChannel[id=0,
recipient=-1]-ServerSessionImpl[2b4580b3-5ef8-46d9-aebd-c5e6dee74a9e@/192.168.1.55:44430]
DEBUG o.a.s.common.forward.TcpipClientChannel : open(TcpipClientChannel[id=0,
recipient=-1]-ServerSessionImpl[2b4580b3-5ef8-46d9-aebd-c5e6dee74a9e@/192.168.1.55:44430])
send SSH_MSG_CHANNEL_OPEN
TRACE o.a.s.server.session.ServerSessionImpl :
encode(ServerSessionImpl[2b4580b3-5ef8-46d9-aebd-c5e6dee74a9e@/192.168.1.55:44430])
packet #8 [chunk #1](64/66) 5a 00 00 00 0f 66 6f 72 77 61 72 64 65 64 2d 74 63
70 69 70 00 00 00 00 00 20 00 00 00 00 80 00 00 00 00 09 31 32 37 2e 30 2e 30
2e 31 00 00 c1 5d 00 00 00 09 31 32 37 2e 30 2e 30 2e 31 00 00
Z....forwarded-tcpip................127.0.0.1...]....127.0.0.1..
TRACE o.a.s.server.session.ServerSessionImpl :
encode(ServerSessionImpl[2b4580b3-5ef8-46d9-aebd-c5e6dee74a9e@/192.168.1.55:44430])
packet #8 [chunk #2](66/66) ce 41
.A
DEBUG o.a.sshd.common.io.nio2.Nio2Session : Writing 128 bytes
DEBUG o.a.sshd.common.io.nio2.Nio2Session :
handleCompletedWriteCycle(Nio2Session[local=/192.168.1.52:8022,
remote=/192.168.1.55:44430]) finished writing len=128
DEBUG o.a.sshd.common.io.nio2.Nio2Session :
handleReadCycleCompletion(Nio2Session[local=/127.0.0.1:49501,
remote=/127.0.0.1:52801]) read 21 bytes
TRACE o.a.s.common.forward.TcpipClientChannel : Waiting 9223372036854775807
millis for lock on channel TcpipClientChannel[id=0,
recipient=-1]-ServerSessionImpl[2b4580b3-5ef8-46d9-aebd-c5e6dee74a9e@/192.168.1.55:44430],
mask=[CLOSED, OPENED], cond=[]
DEBUG o.a.sshd.common.io.nio2.Nio2Session :
handleReadCycleCompletion(Nio2Session[local=/192.168.1.52:8022,
remote=/192.168.1.55:44430]) read 80 bytes
TRACE o.a.s.server.session.ServerSessionImpl :
decode(ServerSessionImpl[2b4580b3-5ef8-46d9-aebd-c5e6dee74a9e@/192.168.1.55:44430])
packet #9 [chunk #1](28/28) 5c 00 00 00 00 00 00 00 01 00 00 00 0b 6f 70 65 6e
20 66 61 69 6c 65 64 00 00 00 00
\............open.failed....
TRACE o.a.s.server.session.ServerSessionImpl :
doHandleMessage(ServerSessionImpl[2b4580b3-5ef8-46d9-aebd-c5e6dee74a9e@/192.168.1.55:44430])
process SSH_MSG_CHANNEL_OPEN_FAILURE
DEBUG o.a.s.s.session.ServerConnectionService :
channelOpenFailure(TcpipClientChannel[id=0,
recipient=-1]-ServerSessionImpl[2b4580b3-5ef8-46d9-aebd-c5e6dee74a9e@/192.168.1.55:44430])
Received SSH_MSG_CHANNEL_OPEN_FAILURE
DEBUG o.a.s.common.forward.TcpipClientChannel :
handleOpenFailure(TcpipClientChannel[id=0,
recipient=-1]-ServerSessionImpl[2b4580b3-5ef8-46d9-aebd-c5e6dee74a9e@/192.168.1.55:44430])
reason=SSH_OPEN_ADMINISTRATIVELY_PROHIBITED, lang=, msg=open failed
TRACE o.a.s.common.forward.TcpipClientChannel : Lock notified on channel
TcpipClientChannel[id=0,
recipient=-1]-ServerSessionImpl[2b4580b3-5ef8-46d9-aebd-c5e6dee74a9e@/192.168.1.55:44430]
after 1262394 nanos
TRACE o.a.s.common.forward.TcpipClientChannel : Waiting 9223372036854775806
millis for lock on channel TcpipClientChannel[id=0,
recipient=-1]-ServerSessionImpl[2b4580b3-5ef8-46d9-aebd-c5e6dee74a9e@/192.168.1.55:44430],
mask=[CLOSED, OPENED], cond=[]
WARN o.a.s.c.forward.DefaultTcpipForwarder : Failed (SshException) to open
channel for session=Nio2Session[local=/127.0.0.1:49501,
remote=/127.0.0.1:52801]: open failed
DEBUG o.a.s.c.forward.DefaultTcpipForwarder :
sessionCreated(Nio2Session[local=/127.0.0.1:49501, remote=/127.0.0.1:52801])
channel=TcpipClientChannel[id=0,
recipient=-1]-ServerSessionImpl[2b4580b3-5ef8-46d9-aebd-c5e6dee74a9e@/192.168.1.55:44430]
open failure details
org.apache.sshd.common.SshException: open failed
at
org.apache.sshd.client.channel.AbstractClientChannel.handleOpenFailure(AbstractClientChannel.java:364)
at
org.apache.sshd.common.session.helpers.AbstractConnectionService.channelOpenFailure(AbstractConnectionService.java:406)
at
org.apache.sshd.common.session.helpers.AbstractConnectionService.process(AbstractConnectionService.java:326)
at
org.apache.sshd.common.session.helpers.AbstractSession.doHandleMessage(AbstractSession.java:564)
at
org.apache.sshd.common.session.helpers.AbstractSession.handleMessage(AbstractSession.java:497)
at
org.apache.sshd.common.session.helpers.AbstractSession.decode(AbstractSession.java:1406)
at
org.apache.sshd.common.session.helpers.AbstractSession.messageReceived(AbstractSession.java:458)
at
org.apache.sshd.common.session.helpers.AbstractSessionIoHandler.messageReceived(AbstractSessionIoHandler.java:67)
at
org.apache.sshd.common.io.nio2.Nio2Session.handleReadCycleCompletion(Nio2Session.java:277)
at
org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:257)
at
org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:254)
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(Invoker.java:126)
at sun.nio.ch.Invoker$2.run(Invoker.java:218)
at
sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:112)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
DEBUG o.a.s.s.session.ServerConnectionService :
unregisterChannel(TcpipClientChannel[id=0,
recipient=-1]-ServerSessionImpl[2b4580b3-5ef8-46d9-aebd-c5e6dee74a9e@/192.168.1.55:44430])
result=null
DEBUG o.a.s.common.forward.TcpipClientChannel : close(TcpipClientChannel[id=0,
recipient=-1]-ServerSessionImpl[2b4580b3-5ef8-46d9-aebd-c5e6dee74a9e@/192.168.1.55:44430])
prevent sending EOF
DEBUG o.a.s.common.forward.TcpipClientChannel : close(TcpipClientChannel[id=0,
recipient=-1]-ServerSessionImpl[2b4580b3-5ef8-46d9-aebd-c5e6dee74a9e@/192.168.1.55:44430])
Closing gracefully
DEBUG org.apache.sshd.common.channel.Window : Closing
Window[client/local](TcpipClientChannel[id=0,
recipient=-1]-ServerSessionImpl[2b4580b3-5ef8-46d9-aebd-c5e6dee74a9e@/192.168.1.55:44430])
DEBUG org.apache.sshd.common.channel.Window : Closing
Window[client/remote](TcpipClientChannel[id=0,
recipient=-1]-ServerSessionImpl[2b4580b3-5ef8-46d9-aebd-c5e6dee74a9e@/192.168.1.55:44430])
TRACE o.a.s.c.u.closeable.SequentialCloseable : doClose(false) closing
Nio2Session[local=/127.0.0.1:49501, remote=/127.0.0.1:52801]
DEBUG o.a.sshd.common.io.nio2.Nio2Session :
close(Nio2Session[local=/127.0.0.1:49501, remote=/127.0.0.1:52801]) Closing
gracefully
TRACE o.a.s.c.util.closeable.FuturesCloseable : doClose(false) complete
pending: 0
DEBUG o.a.s.c.forward.DefaultTcpipForwarder :
sessionClosed(Nio2Session[local=/127.0.0.1:49501, remote=/127.0.0.1:52801])
closing channel=TcpipClientChannel[id=0,
recipient=-1]-ServerSessionImpl[2b4580b3-5ef8-46d9-aebd-c5e6dee74a9e@/192.168.1.55:44430]
DEBUG o.a.s.common.forward.TcpipClientChannel : close(TcpipClientChannel[id=0,
recipient=-1]-ServerSessionImpl[2b4580b3-5ef8-46d9-aebd-c5e6dee74a9e@/192.168.1.55:44430])[Graceful]
state already Graceful
I’m new to Apache sshd, so am having trouble figuring out where I’ve gone
wrong. I’d be grateful if anyone could offer any clues!
Kind regards,
Matt
