I'm trying to write a SSHD integration demo with Mina SSHD server (0.14.0) and Camel SSH component (2.16.2). Now I can communicate with the SSHD perfectly by Putty, but failed to integrate the SSHD with Camel, I couldn't get any response from the Camel ProducerTemplate's requestBody(). After a whole day of debugging, still doesn't work. Here is my SSHD code:
public class EchoSshServer {
public void startSshServer() throws IOException {
SshServer sshd = SshServer.setUpDefaultServer();
sshd.setPort(22);
sshd.setKeyPairProvider(new SimpleGeneratorHostKeyProvider("d:\\hostkey.ser"));
sshd.setPasswordAuthenticator(new PasswordAuthenticator() {
@Override
public boolean authenticate(String u, String p, ServerSession s) {
if ("sync".equals(u) && "sync".equals(p))
return true;
return false;
}
});
//sshd.setShellFactory(new EchoShellFactory());
sshd.setCommandFactory(new EchoCommandFactory());
sshd.start();
}
public static void main(String[] args) {
try {
new EchoSshServer().startSshServer();
Thread.sleep(Integer.MAX_VALUE);
} catch (InterruptedException e) {
e.printStackTrace();
} catch (IOException e) {
e.printStackTrace();
}
}
}
The command factory code is as follows:
public class EchoCommandFactory implements CommandFactory {
@Override
public Command createCommand(String command) {
return new EchoCommand(command);
}
public static class EchoCommand implements Command, Runnable {
private String request;
public EchoCommand(String request) {
this.request = request;
}
private InputStream in;
private OutputStream out;
private OutputStream err;
private ExitCallback callback;
private Environment environment;
private Thread thread;
@Override
public void start(Environment env) throws IOException {
environment = env;
thread = new Thread(this, "EchoCommand");
thread.start();
}
@Override
public void run() {
System.out.print(request);
try {
out.write((request).getBytes(StandardCharsets.UTF_8));
out.flush();
} catch (IOException e) {
e.printStackTrace();
}
}
@Override
public void setInputStream(InputStream in) {
this.in = in;
}
@Override
public void setOutputStream(OutputStream out) {
this.out = out;
}
@Override
public void setErrorStream(OutputStream err) {
this.err = err;
}
@Override
public void setExitCallback(ExitCallback callback) {
this.callback = callback;
}
@Override
public void destroy() {
thread.interrupt();
}
}
}
And the client side code:
public static void main(String[] args) throws Exception {
CamelContext context = new DefaultCamelContext();
context.addRoutes(new RouteBuilder() {
@Override
public void configure() throws Exception {
from("direct:start").to("ssh://sync:sync@localhost:22");
}
});
context.start();
ProducerTemplate template = context.createProducerTemplate();
String reply = template.requestBody("direct:start", "login:bot", String.class);
System.out.println(reply);
}
The client will get stuck at the requestBody() method, the server's log is as follows:
[main] INFO org.apache.sshd.common.util.SecurityUtils - BouncyCastle already registered as a JCE provider
[sshd-SshServer[5aa0dbf4]-nio2-thread-1] INFO org.apache.sshd.server.session.ServerSession - Server session created from /127.0.0.1:50781
[sshd-SshServer[5aa0dbf4]-nio2-thread-3] INFO org.apache.sshd.server.session.ServerUserAuthService - Session sync@/127.0.0.1:50781 authenticated
[sshd-SshServer[5aa0dbf4]-nio2-thread-4] INFO org.apache.sshd.server.channel.ChannelSession - Executing command: login:bot
login:bot
The client's log:
18:38:13.171 [main] DEBUG o.a.camel.impl.DefaultCamelContext - Adding routes from builder: Routes: []
18:38:13.212 [main] INFO o.a.camel.impl.DefaultCamelContext - Apache Camel 2.16.2 (CamelContext: camel-1) is starting
18:38:13.213 [main] DEBUG o.a.camel.impl.DefaultCamelContext - Using ClassResolver=org.apache.camel.impl.DefaultClassResolver@64bfbc86, PackageScanClassResolver=org.apache.camel.impl.DefaultPackageScanClassResolver@64bf3bbf, ApplicationContextClassLoader=null
18:38:13.214 [main] INFO o.a.c.m.ManagedManagementStrategy - JMX is enabled
18:38:13.263 [main] DEBUG o.a.c.m.DefaultManagementAgent - Starting JMX agent on server: com.sun.jmx.mbeanserver.JmxMBeanServer@5383967b
18:38:13.326 [main] DEBUG o.a.c.m.DefaultManagementAgent - Registered MBean with ObjectName: org.apache.camel:context=camel-1,type=context,name="camel-1"
18:38:13.327 [main] DEBUG o.a.c.support.TimerListenerManager - Added TimerListener: org.apache.camel.management.mbean.ManagedCamelContext@4bb4de6a
18:38:13.353 [main] DEBUG o.a.c.m.DefaultManagementAgent - Registered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultTypeConverter
18:38:13.359 [main] DEBUG o.a.c.i.c.AnnotationTypeConverterLoader - Found 3 packages with 16 @Converter classes to load
18:38:13.382 [main] DEBUG o.a.c.i.c.AnnotationTypeConverterLoader - Loading file META-INF/services/org/apache/camel/TypeConverter to retrieve list of packages, from url: jar:file:/C:/Users/zhangqianlei/.gradle/caches/modules-2/files-2.1/org.apache.camel/camel-core/2.16.2/c22ed0b30a474c821cc8998cd5a3f8518a60c60/camel-core-2.16.2.jar!/META-INF/services/org/apache/camel/TypeConverter
18:38:13.382 [main] DEBUG o.a.c.i.c.AnnotationTypeConverterLoader - No additional package names found in classpath for annotated type converters.
18:38:13.383 [main] INFO o.a.c.i.c.DefaultTypeConverter - Loaded 182 type converters
18:38:13.387 [main] DEBUG o.a.c.m.DefaultManagementAgent - Registered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultEndpointRegistry
18:38:13.388 [main] DEBUG o.a.c.m.DefaultManagementAgent - Registered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultExecutorServiceManager
18:38:13.389 [main] DEBUG o.a.c.m.DefaultManagementAgent - Registered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=SharedProducerServicePool
18:38:13.389 [main] DEBUG o.a.c.impl.SharedProducerServicePool - Starting service pool: org.apache.camel.impl.SharedProducerServicePool@7920ba90
18:38:13.390 [main] DEBUG o.a.c.m.DefaultManagementAgent - Registered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=SharedPollingConsumerServicePool
18:38:13.390 [main] DEBUG o.a.c.i.SharedPollingConsumerServicePool - Starting service pool: org.apache.camel.impl.SharedPollingConsumerServicePool@6b419da
18:38:13.392 [main] DEBUG o.a.c.m.DefaultManagementAgent - Registered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultInflightRepository
18:38:13.396 [main] DEBUG o.a.c.m.DefaultManagementAgent - Registered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultAsyncProcessorAwaitManager
18:38:13.397 [main] DEBUG o.a.c.m.DefaultManagementAgent - Registered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultShutdownStrategy
18:38:13.398 [main] DEBUG o.a.c.m.DefaultManagementAgent - Registered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultPackageScanClassResolver
18:38:13.401 [main] DEBUG o.a.c.m.DefaultManagementAgent - Registered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultRestRegistry
18:38:13.405 [main] DEBUG o.a.c.m.DefaultManagementAgent - Registered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultRuntimeEndpointRegistry
18:38:13.405 [main] INFO o.a.c.i.DefaultRuntimeEndpointRegistry - Runtime endpoint registry is in extended mode gathering usage statistics of all incoming and outgoing endpoints (cache limit: 1000)
18:38:13.415 [main] DEBUG o.a.camel.impl.DefaultCamelContext - Using ComponentResolver: org.apache.camel.impl.DefaultComponentResolver@5bfa9431 to resolve component with name: direct
18:38:13.415 [main] DEBUG o.a.c.impl.DefaultComponentResolver - Found component: direct in registry: null
18:38:13.416 [main] DEBUG o.a.c.impl.DefaultComponentResolver - Found component: direct via type: org.apache.camel.component.direct.DirectComponent via: META-INF/services/org/apache/camel/component/direct
18:38:13.423 [main] DEBUG o.a.c.m.DefaultManagementAgent - Registered MBean with ObjectName: org.apache.camel:context=camel-1,type=components,name="direct"
18:38:13.424 [main] DEBUG o.apache.camel.impl.DefaultComponent - Creating endpoint uri=[direct://start], path=[start]
18:38:13.427 [main] DEBUG o.a.camel.impl.DefaultCamelContext - direct://start converted to endpoint: Endpoint[direct://start] by component: org.apache.camel.component.direct.DirectComponent@163e4e87
18:38:13.435 [main] DEBUG o.a.c.m.DefaultManagementAgent - Registered MBean with ObjectName: org.apache.camel:context=camel-1,type=endpoints,name="direct://start"
18:38:13.442 [main] DEBUG o.a.camel.impl.DefaultCamelContext - Using ComponentResolver: org.apache.camel.impl.DefaultComponentResolver@5bfa9431 to resolve component with name: ssh
18:38:13.442 [main] DEBUG o.a.c.impl.DefaultComponentResolver - Found component: ssh in registry: null
18:38:13.443 [main] DEBUG o.a.c.impl.DefaultComponentResolver - Found component: ssh via type: org.apache.camel.component.ssh.SshComponent via: META-INF/services/org/apache/camel/component/ssh
18:38:13.447 [main] DEBUG o.a.c.m.DefaultManagementAgent - Registered MBean with ObjectName: org.apache.camel:context=camel-1,type=components,name="ssh"
18:38:13.447 [main] DEBUG o.apache.camel.impl.DefaultComponent - Creating endpoint uri=[ssh://sync:xxxxxx@localhost:22], path=[sync:xxxxxx@localhost:22]
18:38:13.448 [main] DEBUG o.a.camel.impl.DefaultCamelContext - ssh://sync:xxxxxx@localhost:22 converted to endpoint: Endpoint[ssh://sync:xxxxxx@localhost:22] by component: org.apache.camel.component.ssh.SshComponent@6ef888f6
18:38:13.450 [main] DEBUG o.a.c.m.DefaultManagementAgent - Registered MBean with ObjectName: org.apache.camel:context=camel-1,type=endpoints,name="ssh://sync:xxxxxx@localhost:22"
18:38:13.456 [main] DEBUG o.a.c.p.interceptor.DefaultChannel - Initialize channel for target: 'To[ssh://sync:sync@localhost:22]'
18:38:13.460 [main] DEBUG o.a.c.m.DefaultManagementAgent - Registered MBean with ObjectName: org.apache.camel:context=camel-1,type=tracer,name=BacklogTracer
18:38:13.466 [main] DEBUG o.a.c.m.DefaultManagementAgent - Registered MBean with ObjectName: org.apache.camel:context=camel-1,type=tracer,name=BacklogDebugger
18:38:13.478 [main] DEBUG o.a.c.m.DefaultManagementAgent - Registered MBean with ObjectName: org.apache.camel:context=camel-1,type=errorhandlers,name="DefaultErrorHandlerBuilder(ref:CamelDefaultErrorHandlerBuilder)"
18:38:13.484 [main] INFO o.a.camel.impl.DefaultCamelContext - AllowUseOriginalMessage is enabled. If access to the original message is not needed, then its recommended to turn this option off as it may improve performance.
18:38:13.484 [main] INFO o.a.camel.impl.DefaultCamelContext - StreamCaching is not in use. If using streams then its recommended to enable stream caching. See more details at http://camel.apache.org/stream-caching.html
18:38:13.484 [main] DEBUG o.a.camel.impl.DefaultCamelContext - Warming up route id: route1 having autoStartup=true
18:38:13.484 [main] DEBUG org.apache.camel.impl.RouteService - Starting services on route: route1
18:38:13.485 [main] DEBUG org.apache.camel.impl.RouteService - Starting child service on route: route1 -> Channel[sendTo(Endpoint[ssh://sync:xxxxxx@localhost:22])]
18:38:13.489 [main] DEBUG o.a.c.m.DefaultManagementAgent - Registered MBean with ObjectName: org.apache.camel:context=camel-1,type=producers,name=SshProducer(0xdbf57b3)
18:38:13.489 [main] DEBUG o.a.camel.component.ssh.SshProducer - Starting producer: Producer[ssh://sync:xxxxxx@localhost:22]
18:38:13.677 [main] INFO o.a.sshd.common.util.SecurityUtils - BouncyCastle already registered as a JCE provider
18:38:14.029 [main] DEBUG o.a.s.common.io.nio2.Nio2Connector - Creating Nio2Connector
18:38:14.030 [main] DEBUG org.apache.camel.impl.ProducerCache - Adding to producer cache with key: Endpoint[ssh://sync:xxxxxx@localhost:22] for producer: Producer[ssh://sync:xxxxxx@localhost:22]
18:38:14.030 [main] DEBUG o.a.c.processor.DefaultErrorHandler - Redelivery enabled: false on error handler: DefaultErrorHandler[Instrumentation:to[sendTo(Endpoint[ssh://sync:xxxxxx@localhost:22])]]
18:38:14.030 [main] DEBUG org.apache.camel.impl.RouteService - Starting child service on route: route1 -> sendTo(Endpoint[ssh://sync:xxxxxx@localhost:22])
18:38:14.049 [main] DEBUG o.a.c.m.DefaultManagementAgent - Registered MBean with ObjectName: org.apache.camel:context=camel-1,type=processors,name="to1"
18:38:14.049 [main] DEBUG org.apache.camel.impl.RouteService - Starting child service on route: route1 -> Channel[sendTo(Endpoint[ssh://sync:xxxxxx@localhost:22])]
18:38:14.058 [main] DEBUG o.a.c.m.DefaultManagementAgent - Registered MBean with ObjectName: org.apache.camel:context=camel-1,type=routes,name="route1"
18:38:14.058 [main] DEBUG o.a.c.support.TimerListenerManager - Added TimerListener: org.apache.camel.management.mbean.ManagedSuspendableRoute@43195e57
18:38:14.058 [main] DEBUG o.a.camel.impl.DefaultCamelContext - Route: route1 >>> EventDrivenConsumerRoute[Endpoint[direct://start] -> Channel[sendTo(Endpoint[ssh://sync:xxxxxx@localhost:22])]]
18:38:14.058 [main] DEBUG o.a.camel.impl.DefaultCamelContext - Starting consumer (order: 1000) on route: route1
18:38:14.060 [main] DEBUG o.a.c.m.DefaultManagementAgent - Registered MBean with ObjectName: org.apache.camel:context=camel-1,type=consumers,name=DirectConsumer(0x1afd44cb)
18:38:14.060 [main] INFO o.a.camel.impl.DefaultCamelContext - Route: route1 started and consuming from: Endpoint[direct://start]
18:38:14.060 [main] DEBUG o.a.c.m.DefaultManagementLifecycleStrategy - Load performance statistics disabled
18:38:14.060 [main] INFO o.a.camel.impl.DefaultCamelContext - Total 1 routes, of which 1 is started.
18:38:14.061 [main] INFO o.a.camel.impl.DefaultCamelContext - Apache Camel 2.16.2 (CamelContext: camel-1) started in 0.851 seconds
18:38:14.064 [main] DEBUG o.a.c.c.direct.DirectProducer - Starting producer: Producer[direct://start]
18:38:14.064 [main] DEBUG org.apache.camel.impl.ProducerCache - Adding to producer cache with key: Endpoint[direct://start] for producer: Producer[direct://start]
18:38:14.066 [main] DEBUG org.apache.camel.impl.ProducerCache - >>>> Endpoint[direct://start] Exchange[][Message: login:bot]
18:38:14.090 [main] DEBUG o.a.camel.processor.SendProcessor - >>>> Endpoint[ssh://sync:xxxxxx@localhost:22] Exchange[ID-SZWW070P-50779-1459939093005-0-2][Message: login:bot]
18:38:14.091 [main] DEBUG o.a.s.common.io.nio2.Nio2Connector - Connecting to localhost/127.0.0.1:22
18:38:14.097 [sshd-SshClient[3cbcd8f3]-nio2-thread-1] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Creating IoSession on /0:0:0:0:0:0:0:0:50781 from localhost/127.0.0.1:22
18:38:14.105 [sshd-SshClient[3cbcd8f3]-nio2-thread-1] INFO o.a.s.c.session.ClientSessionImpl - Client session created
18:38:14.109 [sshd-SshClient[3cbcd8f3]-nio2-thread-1] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Writing 26 bytes
18:38:14.111 [sshd-SshClient[3cbcd8f3]-nio2-thread-2] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Finished writing
18:38:14.111 [sshd-SshClient[3cbcd8f3]-nio2-thread-1] DEBUG o.a.s.c.session.ClientSessionImpl - Send SSH_MSG_KEXINIT
18:38:14.111 [sshd-SshClient[3cbcd8f3]-nio2-thread-1] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Writing 704 bytes
18:38:14.112 [main] DEBUG o.a.camel.component.ssh.SshHelper - Connected to localhost:22
18:38:14.112 [sshd-SshClient[3cbcd8f3]-nio2-thread-3] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Finished writing
18:38:14.112 [main] DEBUG o.a.camel.component.ssh.SshHelper - Attempting to authenticate username 'sync' using Password...
18:38:14.113 [sshd-SshClient[3cbcd8f3]-nio2-thread-4] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Read 26 bytes
18:38:14.113 [sshd-SshClient[3cbcd8f3]-nio2-thread-4] INFO o.a.s.c.session.ClientSessionImpl - Server version string: SSH-2.0-SSHD-CORE-0.14.0
18:38:14.114 [main] DEBUG o.a.s.c.s.ClientUserAuthServiceOld - Trying authentication with org.apache.sshd.client.auth.deprecated.UserAuthPassword@acf859d
18:38:14.114 [main] DEBUG o.a.s.c.s.ClientUserAuthServiceOld - waiting to send authentication
18:38:14.123 [sshd-SshClient[3cbcd8f3]-nio2-thread-5] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Read 640 bytes
18:38:14.123 [sshd-SshClient[3cbcd8f3]-nio2-thread-5] DEBUG o.a.s.c.session.ClientSessionImpl - Received SSH_MSG_KEXINIT
18:38:14.124 [sshd-SshClient[3cbcd8f3]-nio2-thread-5] DEBUG o.a.s.c.session.ClientSessionImpl - Kex: server->client aes128-ctr hmac-sha2-256 none
18:38:14.124 [sshd-SshClient[3cbcd8f3]-nio2-thread-5] DEBUG o.a.s.c.session.ClientSessionImpl - Kex: client->server aes128-ctr hmac-sha2-256 none
18:38:14.125 [sshd-SshClient[3cbcd8f3]-nio2-thread-5] DEBUG org.apache.sshd.client.kex.DHGEX256 - Send SSH_MSG_KEX_DH_GEX_REQUEST
18:38:14.125 [sshd-SshClient[3cbcd8f3]-nio2-thread-5] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Writing 32 bytes
18:38:14.126 [sshd-SshClient[3cbcd8f3]-nio2-thread-2] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Finished writing
18:38:14.343 [sshd-SshClient[3cbcd8f3]-nio2-thread-3] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Read 536 bytes
18:38:14.343 [sshd-SshClient[3cbcd8f3]-nio2-thread-3] DEBUG org.apache.sshd.client.kex.DHGEX256 - Received SSH_MSG_KEX_DH_GEX_GROUP
18:38:14.525 [sshd-SshClient[3cbcd8f3]-nio2-thread-3] DEBUG org.apache.sshd.client.kex.DHGEX256 - Send SSH_MSG_KEX_DH_GEX_INIT
18:38:14.525 [sshd-SshClient[3cbcd8f3]-nio2-thread-3] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Writing 536 bytes
18:38:14.526 [sshd-SshClient[3cbcd8f3]-nio2-thread-1] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Finished writing
18:38:14.693 [sshd-SshClient[3cbcd8f3]-nio2-thread-4] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Read 1032 bytes
18:38:14.693 [sshd-SshClient[3cbcd8f3]-nio2-thread-4] DEBUG org.apache.sshd.client.kex.DHGEX256 - Received SSH_MSG_KEX_DH_GEX_REPLY
18:38:14.870 [sshd-SshClient[3cbcd8f3]-nio2-thread-4] WARN o.a.s.c.k.AcceptAllServerKeyVerifier - Server at localhost/127.0.0.1:22 presented unverified DSA key: 29:72:77:bf:00:26:1a:f9:35:9c:0b:ed:23:fe:73:38
18:38:14.870 [sshd-SshClient[3cbcd8f3]-nio2-thread-4] DEBUG o.a.s.c.session.ClientSessionImpl - Send SSH_MSG_NEWKEYS
18:38:14.870 [sshd-SshClient[3cbcd8f3]-nio2-thread-4] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Writing 16 bytes
18:38:14.871 [sshd-SshClient[3cbcd8f3]-nio2-thread-5] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Finished writing
18:38:14.871 [sshd-SshClient[3cbcd8f3]-nio2-thread-5] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Read 16 bytes
18:38:14.871 [sshd-SshClient[3cbcd8f3]-nio2-thread-5] DEBUG o.a.s.c.session.ClientSessionImpl - Received SSH_MSG_NEWKEYS
18:38:14.875 [sshd-SshClient[3cbcd8f3]-nio2-thread-5] DEBUG o.a.s.c.session.ClientSessionImpl - Send SSH_MSG_SERVICE_REQUEST for ssh-userauth
18:38:14.875 [sshd-SshClient[3cbcd8f3]-nio2-thread-5] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Writing 80 bytes
18:38:14.876 [sshd-SshClient[3cbcd8f3]-nio2-thread-5] DEBUG o.a.s.c.s.ClientUserAuthServiceOld - accepted
18:38:14.876 [sshd-SshClient[3cbcd8f3]-nio2-thread-3] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Finished writing
18:38:14.876 [main] DEBUG o.a.s.c.s.ClientUserAuthServiceOld - ready to try authentication with new lock
18:38:14.876 [main] DEBUG o.a.s.c.s.ClientUserAuthServiceOld - processing org.apache.sshd.client.auth.deprecated.UserAuthPassword@acf859d
18:38:14.877 [main] DEBUG o.a.s.c.a.d.UserAuthPassword - Send SSH_MSG_USERAUTH_REQUEST for password
18:38:14.877 [main] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Writing 112 bytes
18:38:14.877 [main] DEBUG o.a.s.c.s.ClientUserAuthServiceOld - continuing with org.apache.sshd.client.auth.deprecated.UserAuthPassword@acf859d
18:38:14.877 [sshd-SshClient[3cbcd8f3]-nio2-thread-1] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Finished writing
18:38:14.879 [sshd-SshClient[3cbcd8f3]-nio2-thread-4] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Read 80 bytes
18:38:14.879 [sshd-SshClient[3cbcd8f3]-nio2-thread-4] DEBUG o.a.s.c.session.ClientSessionImpl - Received SSH_MSG_SERVICE_ACCEPT
18:38:14.880 [sshd-SshClient[3cbcd8f3]-nio2-thread-2] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Read 64 bytes
18:38:14.880 [sshd-SshClient[3cbcd8f3]-nio2-thread-2] DEBUG o.a.s.c.s.ClientUserAuthServiceOld - processing org.apache.sshd.client.auth.deprecated.UserAuthPassword@acf859d
18:38:14.880 [sshd-SshClient[3cbcd8f3]-nio2-thread-2] DEBUG o.a.s.c.a.d.UserAuthPassword - Received SSH_MSG_USERAUTH_SUCCESS
18:38:14.880 [sshd-SshClient[3cbcd8f3]-nio2-thread-2] DEBUG o.a.s.c.s.ClientUserAuthServiceOld - succeeded with org.apache.sshd.client.auth.deprecated.UserAuthPassword@acf859d
18:38:14.889 [main] DEBUG o.a.sshd.client.channel.ChannelExec - Send SSH_MSG_CHANNEL_OPEN on channel ChannelExec[id=0, recipient=0]
18:38:14.889 [main] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Writing 80 bytes
18:38:14.889 [sshd-SshClient[3cbcd8f3]-nio2-thread-3] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Finished writing
18:38:14.897 [sshd-SshClient[3cbcd8f3]-nio2-thread-5] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Read 80 bytes
18:38:14.897 [sshd-SshClient[3cbcd8f3]-nio2-thread-5] DEBUG o.a.s.c.s.ClientConnectionService - Received SSH_MSG_CHANNEL_OPEN_CONFIRMATION on channel 0
18:38:14.897 [sshd-SshClient[3cbcd8f3]-nio2-thread-5] DEBUG o.a.sshd.client.channel.ChannelExec - Send SSH_MSG_CHANNEL_REQUEST exec
18:38:14.897 [sshd-SshClient[3cbcd8f3]-nio2-thread-5] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Writing 112 bytes
18:38:14.897 [sshd-SshClient[3cbcd8f3]-nio2-thread-1] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Finished writing
18:38:14.898 [ClientInputStreamPump] DEBUG o.a.sshd.client.channel.ChannelExec - Send SSH_MSG_CHANNEL_DATA on channel 0
18:38:14.898 [ClientInputStreamPump] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Writing 64 bytes
18:38:14.898 [ClientInputStreamPump] DEBUG o.a.sshd.client.channel.ChannelExec - Send SSH_MSG_CHANNEL_EOF on channel ChannelExec[id=0, recipient=0]
18:38:14.898 [sshd-SshClient[3cbcd8f3]-nio2-thread-4] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Finished writing
18:38:14.898 [ClientInputStreamPump] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Writing 64 bytes
18:38:14.899 [sshd-SshClient[3cbcd8f3]-nio2-thread-2] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Finished writing
18:38:14.902 [sshd-SshClient[3cbcd8f3]-nio2-thread-3] DEBUG o.a.sshd.common.io.nio2.Nio2Session - Read 96 bytes
18:38:14.902 [sshd-SshClient[3cbcd8f3]-nio2-thread-3] DEBUG o.a.sshd.client.channel.ChannelExec - Received SSH_MSG_CHANNEL_DATA on channel ChannelExec[id=0, recipient=0]
It seems that the client has received the data, but I can't figure out why the requestBody() doesn't return.
Finally I found the bug, in the SSHD command implementation, we need to call the onExit().
public void run() {
System.out.print(command);
try {
out.write((command + "echo").getBytes(StandardCharsets.UTF_8));
out.flush();
} catch (IOException e) {
e.printStackTrace();
} finally {
if (callback != null) {
callback.onExit(0, "OK");
}
}
}