You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@mina.apache.org by lg...@apache.org on 2020/12/11 08:51:27 UTC

[mina-sshd] 02/15: [SSHD-1085] Added CliLogger + more verbosity on SshClientMain execution

This is an automated email from the ASF dual-hosted git repository.

lgoldstein pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/mina-sshd.git

commit daf4a18eca51cc951b5715b449e07c85ae035c48
Author: Lyor Goldstein <lg...@apache.org>
AuthorDate: Wed Dec 9 23:07:33 2020 +0200

    [SSHD-1085] Added CliLogger + more verbosity on SshClientMain execution
---
 CHANGES.md                                         |   3 +
 .../main/java/org/apache/sshd/cli/CliLogger.java   | 149 +++++++++++++++++++++
 .../sshd/cli/client/CliClientModuleProperties.java |   6 +
 .../org/apache/sshd/cli/client/SshClientMain.java  |  48 ++++++-
 4 files changed, 202 insertions(+), 4 deletions(-)

diff --git a/CHANGES.md b/CHANGES.md
index fc90adf..6a8b852 100644
--- a/CHANGES.md
+++ b/CHANGES.md
@@ -16,6 +16,9 @@
 
 ## Minor code helpers
 
+* [SSHD-1085](https://issues.apache.org/jira/browse/SSHD-1085) Added `CliLogger` + more verbosity on `SshClientMain`
+
+
 ## Behavioral changes and enhancements
 
 * [SSHD-1085](https://issues.apache.org/jira/browse/SSHD-1085) Added more notifications related to channel state change for detecting channel closing or closed earlier.
diff --git a/sshd-cli/src/main/java/org/apache/sshd/cli/CliLogger.java b/sshd-cli/src/main/java/org/apache/sshd/cli/CliLogger.java
new file mode 100644
index 0000000..e6094fd
--- /dev/null
+++ b/sshd-cli/src/main/java/org/apache/sshd/cli/CliLogger.java
@@ -0,0 +1,149 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The ASF licenses this file
+ * to you under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance
+ * with the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing,
+ * software distributed under the License is distributed on an
+ * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ * KIND, either express or implied. See the License for the
+ * specific language governing permissions and limitations
+ * under the License.
+ */
+
+package org.apache.sshd.cli;
+
+import java.io.PrintStream;
+import java.text.DateFormat;
+import java.text.SimpleDateFormat;
+import java.util.Date;
+import java.util.logging.Level;
+
+/**
+ * @author <a href="mailto:dev@mina.apache.org">Apache MINA SSHD Project</a>
+ */
+public class CliLogger {
+    public static final DateFormat LOG_TIME_FORMATTER = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss,SSS");
+
+    protected final Level threshold;
+    protected final PrintStream logStream;
+
+    public CliLogger(Level threshold, PrintStream logStream) {
+        this.threshold = threshold;
+        this.logStream = logStream;
+    }
+
+    public boolean isErrorEnabled() {
+        return isEnabledLevel(Level.SEVERE);
+    }
+
+    public void error(String msg) {
+        error(msg, null);
+    }
+
+    public void error(String msg, Throwable err) {
+        log(Level.SEVERE, msg, err);
+    }
+
+    public boolean isWarnEnabled() {
+        return isEnabledLevel(Level.WARNING);
+    }
+
+    public void warn(String msg) {
+        warn(msg, null);
+    }
+
+    public void warn(String msg, Throwable err) {
+        log(Level.WARNING, msg, err);
+    }
+
+    public boolean isInfoEnabled() {
+        return isEnabledLevel(Level.INFO);
+    }
+
+    public void info(String msg) {
+        info(msg, null);
+    }
+
+    public void info(String msg, Throwable err) {
+        log(Level.INFO, msg, err);
+    }
+
+    public boolean isDebugEnabled() {
+        return isEnabledLevel(Level.FINE);
+    }
+
+    public void debug(String msg) {
+        debug(msg, null);
+    }
+
+    public void debug(String msg, Throwable err) {
+        log(Level.FINE, msg, err);
+    }
+
+    public boolean isTraceEnabled() {
+        return isEnabledLevel(Level.FINER);
+    }
+
+    public void trace(String msg) {
+        trace(msg, null);
+    }
+
+    public void trace(String msg, Throwable err) {
+        log(Level.FINER, msg, err);
+    }
+
+    public boolean isEnabledLevel(Level level) {
+        return isLevelEnabled(level, threshold);
+    }
+
+    public void log(Level level, String msg, Throwable err) {
+        if (!isEnabledLevel(level)) {
+            return;
+        }
+
+        Date now = new Date();
+        String time;
+        synchronized (LOG_TIME_FORMATTER) {
+            time = LOG_TIME_FORMATTER.format(now);
+        }
+        logStream.append(time)
+                .append(' ').append(level.getName())
+                .append(' ').append(Thread.currentThread().getName())
+                .append(' ').append(msg)
+                .println();
+        if (err != null) {
+            err.printStackTrace(logStream);
+        }
+    }
+
+    public static boolean isErrorEnabled(Level level) {
+        return isLevelEnabled(level, Level.SEVERE);
+    }
+
+    public static boolean isWarnEnabled(Level level) {
+        return isLevelEnabled(level, Level.WARNING);
+    }
+
+    public static boolean isInfoEnabled(Level level) {
+        return isLevelEnabled(level, Level.INFO);
+    }
+
+    public static boolean isDebugEnabled(Level level) {
+        return isLevelEnabled(level, Level.FINE);
+    }
+
+    public static boolean isTraceEnabled(Level level) {
+        return isLevelEnabled(level, Level.FINER);
+    }
+
+    public static boolean isLevelEnabled(Level level, Level threshold) {
+        return (level != null) && (threshold != null) && (level.intValue() <= threshold.intValue());
+    }
+}
diff --git a/sshd-cli/src/main/java/org/apache/sshd/cli/client/CliClientModuleProperties.java b/sshd-cli/src/main/java/org/apache/sshd/cli/client/CliClientModuleProperties.java
index 2af0c44..25bce07 100644
--- a/sshd-cli/src/main/java/org/apache/sshd/cli/client/CliClientModuleProperties.java
+++ b/sshd-cli/src/main/java/org/apache/sshd/cli/client/CliClientModuleProperties.java
@@ -41,6 +41,12 @@ public final class CliClientModuleProperties {
     public static final Property<Duration> AUTH_TIMEOUT
             = Property.duration("cli-auth-timeout", Duration.ofMinutes(2));
 
+    /**
+     * Key used to retrieve the value of the timeout for opening an EXEC or SHELL channel - in msec.
+     */
+    public static final Property<Duration> CHANNEL_OPEN_TIMEOUT
+            = Property.duration("cli-channel-open-timeout", Duration.ofSeconds(30));
+
     private CliClientModuleProperties() {
         throw new UnsupportedOperationException("No instance");
     }
diff --git a/sshd-cli/src/main/java/org/apache/sshd/cli/client/SshClientMain.java b/sshd-cli/src/main/java/org/apache/sshd/cli/client/SshClientMain.java
index c71f4fa..89740ce 100644
--- a/sshd-cli/src/main/java/org/apache/sshd/cli/client/SshClientMain.java
+++ b/sshd-cli/src/main/java/org/apache/sshd/cli/client/SshClientMain.java
@@ -23,18 +23,22 @@ import java.io.InputStreamReader;
 import java.io.OutputStream;
 import java.io.PrintStream;
 import java.nio.charset.Charset;
+import java.time.Duration;
 import java.util.ArrayList;
+import java.util.Collection;
 import java.util.EnumSet;
 import java.util.List;
 import java.util.Map;
 import java.util.logging.Level;
 
+import org.apache.sshd.cli.CliLogger;
 import org.apache.sshd.cli.CliSupport;
 import org.apache.sshd.client.SshClient;
 import org.apache.sshd.client.channel.ChannelShell;
 import org.apache.sshd.client.channel.ClientChannel;
 import org.apache.sshd.client.channel.ClientChannelEvent;
 import org.apache.sshd.client.session.ClientSession;
+import org.apache.sshd.common.channel.Channel;
 import org.apache.sshd.common.channel.PtyChannelConfiguration;
 import org.apache.sshd.common.util.GenericUtils;
 import org.apache.sshd.common.util.io.NoCloseInputStream;
@@ -53,6 +57,7 @@ public class SshClientMain extends SshClientCliSupport {
 
     //////////////////////////////////////////////////////////////////////////
 
+    @SuppressWarnings("checkstyle:methodlength")
     public static void main(String[] args) throws Exception {
         PrintStream stdout = System.out;
         PrintStream stderr = System.err;
@@ -142,6 +147,8 @@ public class SshClientMain extends SshClientCliSupport {
                 return;
             }
 
+            CliLogger logger = new CliLogger(level, System.err);
+            boolean verbose = logger.isInfoEnabled();
             try (SshClient client = (SshClient) session.getFactoryManager()) {
                 /*
                  * String authSock = System.getenv(SshAgent.SSH_AUTHSOCKET_ENV_NAME); if (authSock == null && provider
@@ -152,6 +159,11 @@ public class SshClientMain extends SshClientCliSupport {
 
                 try {
                     if (socksPort >= 0) {
+                        if (verbose) {
+                            logger.info(
+                                    "Start dynamic port forwarding to " + SshdSocketAddress.LOCALHOST_NAME + ":" + socksPort);
+                        }
+
                         session.startDynamicPortForwarding(
                                 new SshdSocketAddress(SshdSocketAddress.LOCALHOST_NAME, socksPort));
                         Thread.sleep(Long.MAX_VALUE);
@@ -159,21 +171,46 @@ public class SshClientMain extends SshClientCliSupport {
                         Map<String, ?> env = resolveClientEnvironment(client);
                         PtyChannelConfiguration ptyConfig = resolveClientPtyOptions(client);
                         ClientChannel channel;
+                        String cmdValue;
                         if (GenericUtils.isEmpty(command)) {
                             channel = session.createShellChannel(ptyConfig, env);
                             ((ChannelShell) channel).setAgentForwarding(agentForward);
                             channel.setIn(new NoCloseInputStream(System.in));
+                            cmdValue = Channel.CHANNEL_SHELL;
                         } else {
-                            channel = session.createExecChannel(
-                                    String.join(" ", command).trim(), ptyConfig, env);
+                            cmdValue = String.join(" ", command).trim();
+                            channel = session.createExecChannel(cmdValue, ptyConfig, env);
+                        }
+
+                        if (logger.isDebugEnabled()) {
+                            logger.debug("PTY=" + ptyConfig + " for command=" + cmdValue);
+                            logger.debug("ENV=" + env + " for command=" + cmdValue);
                         }
 
                         try (OutputStream channelOut = new NoCloseOutputStream(System.out);
                              OutputStream channelErr = new NoCloseOutputStream(System.err)) {
                             channel.setOut(channelOut);
                             channel.setErr(channelErr);
-                            channel.open().await(); // TODO use verify and a configurable timeout
-                            channel.waitFor(EnumSet.of(ClientChannelEvent.CLOSED), 0L);
+
+                            Duration maxWait = CliClientModuleProperties.CHANNEL_OPEN_TIMEOUT.getRequired(channel);
+                            if (verbose) {
+                                logger.info("Wait " + maxWait + " for open channel for command=" + cmdValue);
+                            }
+                            channel.open().verify(maxWait);
+                            if (verbose) {
+                                logger.info("Channel opened for command=" + cmdValue);
+                            }
+
+                            Collection<ClientChannelEvent> result = channel.waitFor(EnumSet.of(ClientChannelEvent.CLOSED), 0L);
+                            if (verbose) {
+                                logger.info("command=" + cmdValue + " - waitFor result=" + result);
+                                if (result.contains(ClientChannelEvent.EXIT_SIGNAL)) {
+                                    logger.info("    " + ClientChannelEvent.EXIT_SIGNAL + "=" + channel.getExitSignal());
+                                }
+                                if (result.contains(ClientChannelEvent.EXIT_STATUS)) {
+                                    logger.info("    " + ClientChannelEvent.EXIT_STATUS + "=" + channel.getExitStatus());
+                                }
+                            }
                         } finally {
                             channel.close();
                         }
@@ -185,6 +222,9 @@ public class SshClientMain extends SshClientCliSupport {
             } finally {
                 session.close();
             }
+        } catch (Exception e) {
+            e.printStackTrace(System.err);
+            throw e;
         } finally {
             if (logStream != null && logStream != stdout && logStream != stderr) {
                 logStream.close();