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 2015/11/26 06:33:11 UTC

[10/10] mina-sshd git commit: Added more informative log messages in cases where exceptions are caught and logged

Added more informative log messages in cases where exceptions are caught and logged


Project: http://git-wip-us.apache.org/repos/asf/mina-sshd/repo
Commit: http://git-wip-us.apache.org/repos/asf/mina-sshd/commit/b07095c9
Tree: http://git-wip-us.apache.org/repos/asf/mina-sshd/tree/b07095c9
Diff: http://git-wip-us.apache.org/repos/asf/mina-sshd/diff/b07095c9

Branch: refs/heads/master
Commit: b07095c9bc7142afb816718251360643ce758f17
Parents: be8428a
Author: Lyor Goldstein <lg...@vmware.com>
Authored: Thu Nov 26 07:32:41 2015 +0200
Committer: Lyor Goldstein <lg...@vmware.com>
Committed: Thu Nov 26 07:32:41 2015 +0200

----------------------------------------------------------------------
 .../exit/AbstractChannelExitRequestHandler.java | 10 ++++--
 .../sshd/common/channel/AbstractChannel.java    | 16 ++++++---
 .../sshd/common/io/nio2/Nio2Acceptor.java       | 14 ++++++--
 .../sshd/common/io/nio2/Nio2ServiceFactory.java |  5 ++-
 .../session/AbstractConnectionService.java      |  9 +++--
 .../sshd/common/session/AbstractSession.java    | 11 ++++--
 .../server/channel/AbstractServerChannel.java   |  3 ++
 .../sshd/server/channel/ChannelSession.java     |  3 ++
 .../sshd/server/forward/TcpipServerChannel.java |  3 ++
 .../org/apache/sshd/server/kex/DHGEXServer.java |  4 ++-
 .../AbstractGeneratorHostKeyProvider.java       | 36 +++++++++++++-------
 .../sshd/server/shell/InvertedShellWrapper.java | 10 +++++-
 .../apache/sshd/server/shell/ProcessShell.java  |  6 +++-
 .../server/subsystem/sftp/SftpSubsystem.java    | 14 +++++++-
 .../org/apache/sshd/client/scp/ScpTest.java     |  2 ++
 .../common/channel/TestChannelListener.java     |  3 ++
 .../server/subsystem/sftp/SshFsMounter.java     |  3 ++
 17 files changed, 120 insertions(+), 32 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/mina-sshd/blob/b07095c9/sshd-core/src/main/java/org/apache/sshd/client/channel/exit/AbstractChannelExitRequestHandler.java
----------------------------------------------------------------------
diff --git a/sshd-core/src/main/java/org/apache/sshd/client/channel/exit/AbstractChannelExitRequestHandler.java b/sshd-core/src/main/java/org/apache/sshd/client/channel/exit/AbstractChannelExitRequestHandler.java
index 3040c4a..3a25f2b 100644
--- a/sshd-core/src/main/java/org/apache/sshd/client/channel/exit/AbstractChannelExitRequestHandler.java
+++ b/sshd-core/src/main/java/org/apache/sshd/client/channel/exit/AbstractChannelExitRequestHandler.java
@@ -102,10 +102,16 @@ public abstract class AbstractChannelExitRequestHandler<V> extends AbstractChann
         try {
             notifier.notifyEvent(event);
             if (log.isDebugEnabled()) {
-                log.debug("notifyStateChanged({})", event);
+                log.debug("notifyStateChanged({})[{}] event={}", channel, request, event);
             }
         } catch (Exception e) {
-            log.warn("Failed (" + e.getClass().getSimpleName() + ") to notify event=" + event + ": " + e.getMessage());
+            log.warn("notifyStateChanged({})[{}] Failed ({}) to notify event={}: {}",
+                     channel, request, e.getClass().getSimpleName(), event, e.getMessage());
+            if (log.isDebugEnabled()) {
+                log.debug("notifyStateChanged(" + channel + ")[" + request + "]"
+                        + " event=" + event + " notification failure details",
+                         e);
+            }
             if (e instanceof RuntimeException) {
                 throw (RuntimeException) e;
             } else {

http://git-wip-us.apache.org/repos/asf/mina-sshd/blob/b07095c9/sshd-core/src/main/java/org/apache/sshd/common/channel/AbstractChannel.java
----------------------------------------------------------------------
diff --git a/sshd-core/src/main/java/org/apache/sshd/common/channel/AbstractChannel.java b/sshd-core/src/main/java/org/apache/sshd/common/channel/AbstractChannel.java
index 549b42d..2165ee5 100644
--- a/sshd-core/src/main/java/org/apache/sshd/common/channel/AbstractChannel.java
+++ b/sshd-core/src/main/java/org/apache/sshd/common/channel/AbstractChannel.java
@@ -175,16 +175,22 @@ public abstract class AbstractChannel
             try {
                 result = handler.process(this, req, wantReply, buffer);
             } catch (Exception e) {
-                log.warn("handleRequest({}) {} while {}#process({}): {}",
-                         this, e.getClass().getSimpleName(), handler.getClass().getSimpleName(), req, e.getMessage());
+                log.warn("handleRequest({}) {} while {}#process({})[want-reply={}]: {}",
+                         this, e.getClass().getSimpleName(), handler.getClass().getSimpleName(),
+                         req, wantReply, e.getMessage());
+                if (log.isDebugEnabled()) {
+                    log.debug("handleRequest(" + this + ") request=" + req
+                            + "[want-reply=" + wantReply + "] processing failure details",
+                              e);
+                }
                 result = RequestHandler.Result.ReplyFailure;
             }
 
             // if Unsupported then check the next handler in line
             if (RequestHandler.Result.Unsupported.equals(result)) {
                 if (log.isTraceEnabled()) {
-                    log.trace("handleRequest({})[{}#process({})]: {}",
-                              this, handler.getClass().getSimpleName(), req, result);
+                    log.trace("handleRequest({})[{}#process({})[want-reply={}]]: {}",
+                              this, handler.getClass().getSimpleName(), req, wantReply, result);
                 }
             } else {
                 sendResponse(buffer, req, result, wantReply);
@@ -193,7 +199,7 @@ public abstract class AbstractChannel
         }
 
         // none of the handlers processed the request
-        log.warn("handleRequest({}) Unknown channel request: {}", this, req);
+        log.warn("handleRequest({}) Unknown channel request: {}[want-reply={}]", this, req, wantReply);
         sendResponse(buffer, req, RequestHandler.Result.Unsupported, wantReply);
     }
 

http://git-wip-us.apache.org/repos/asf/mina-sshd/blob/b07095c9/sshd-core/src/main/java/org/apache/sshd/common/io/nio2/Nio2Acceptor.java
----------------------------------------------------------------------
diff --git a/sshd-core/src/main/java/org/apache/sshd/common/io/nio2/Nio2Acceptor.java b/sshd-core/src/main/java/org/apache/sshd/common/io/nio2/Nio2Acceptor.java
index 836f41d..ebc590d 100644
--- a/sshd-core/src/main/java/org/apache/sshd/common/io/nio2/Nio2Acceptor.java
+++ b/sshd-core/src/main/java/org/apache/sshd/common/io/nio2/Nio2Acceptor.java
@@ -86,13 +86,21 @@ public class Nio2Acceptor extends Nio2Service implements IoAcceptor {
             AsynchronousServerSocketChannel channel = channels.remove(address);
             if (channel != null) {
                 try {
-                    log.trace("unbind({})", address);
+                    if (log.isTraceEnabled()) {
+                        log.trace("unbind({})", address);
+                    }
                     channel.close();
                 } catch (IOException e) {
-                    log.warn("Error unbinding channel for " + address, e);
+                    log.warn("unbind({}) {} while unbinding channel: {}",
+                             address, e.getClass().getSimpleName(), e.getMessage());
+                    if (log.isDebugEnabled()) {
+                        log.debug("unbind(" + address + ") failure details", e);
+                    }
                 }
             } else {
-                log.trace("No active channel to unbind {}", address);
+                if (log.isTraceEnabled()) {
+                    log.trace("No active channel to unbind {}", address);
+                }
             }
         }
     }

http://git-wip-us.apache.org/repos/asf/mina-sshd/blob/b07095c9/sshd-core/src/main/java/org/apache/sshd/common/io/nio2/Nio2ServiceFactory.java
----------------------------------------------------------------------
diff --git a/sshd-core/src/main/java/org/apache/sshd/common/io/nio2/Nio2ServiceFactory.java b/sshd-core/src/main/java/org/apache/sshd/common/io/nio2/Nio2ServiceFactory.java
index 2a91b79..5fb773f 100644
--- a/sshd-core/src/main/java/org/apache/sshd/common/io/nio2/Nio2ServiceFactory.java
+++ b/sshd-core/src/main/java/org/apache/sshd/common/io/nio2/Nio2ServiceFactory.java
@@ -44,7 +44,10 @@ public class Nio2ServiceFactory extends AbstractIoServiceFactory {
         try {
             group = AsynchronousChannelGroup.withThreadPool(ThreadUtils.protectExecutorServiceShutdown(getExecutorService(), isShutdownOnExit()));
         } catch (IOException e) {
-            log.warn("Failed (" + e.getClass().getSimpleName() + " to start async. channel group: " + e.getMessage(), e);
+            log.warn("Failed (" + e.getClass().getSimpleName() + " to start async. channel group: " + e.getMessage());
+            if (log.isDebugEnabled()) {
+                log.debug("Start async. channel group failure details", e);
+            }
             throw new RuntimeSshException(e);
         }
     }

http://git-wip-us.apache.org/repos/asf/mina-sshd/blob/b07095c9/sshd-core/src/main/java/org/apache/sshd/common/session/AbstractConnectionService.java
----------------------------------------------------------------------
diff --git a/sshd-core/src/main/java/org/apache/sshd/common/session/AbstractConnectionService.java b/sshd-core/src/main/java/org/apache/sshd/common/session/AbstractConnectionService.java
index 8e4943a..1cd68e4 100644
--- a/sshd-core/src/main/java/org/apache/sshd/common/session/AbstractConnectionService.java
+++ b/sshd-core/src/main/java/org/apache/sshd/common/session/AbstractConnectionService.java
@@ -433,14 +433,19 @@ public abstract class AbstractConnectionService extends AbstractInnerCloseable i
                 try {
                     result = handler.process(this, req, wantReply, buffer);
                 } catch (Exception e) {
-                    log.warn("Error processing global request " + req, e);
+                    log.warn("globalRequest({})[want-reply={}] failed ({}) to process: {}",
+                             req, wantReply, e.getClass().getSimpleName(), e.getMessage());
+                    if (log.isDebugEnabled()) {
+                        log.debug("globalRequest(" + req + ")[want-reply=" + wantReply + "] failure details", e);
+                    }
                     result = RequestHandler.Result.ReplyFailure;
                 }
 
                 // if Unsupported then check the next handler in line
                 if (RequestHandler.Result.Unsupported.equals(result)) {
                     if (log.isTraceEnabled()) {
-                        log.trace("{}#process({}): {}", handler.getClass().getSimpleName(), req, result);
+                        log.trace("{}#process({})[want-reply={}] : {}",
+                                  handler.getClass().getSimpleName(), req, wantReply, result);
                     }
                 } else {
                     sendResponse(buffer, req, result, wantReply);

http://git-wip-us.apache.org/repos/asf/mina-sshd/blob/b07095c9/sshd-core/src/main/java/org/apache/sshd/common/session/AbstractSession.java
----------------------------------------------------------------------
diff --git a/sshd-core/src/main/java/org/apache/sshd/common/session/AbstractSession.java b/sshd-core/src/main/java/org/apache/sshd/common/session/AbstractSession.java
index 7d90d11..d25b524 100644
--- a/sshd-core/src/main/java/org/apache/sshd/common/session/AbstractSession.java
+++ b/sshd-core/src/main/java/org/apache/sshd/common/session/AbstractSession.java
@@ -578,7 +578,11 @@ public abstract class AbstractSession extends AbstractKexFactoryManager implemen
                 return;
             }
         }
-        log.warn("Exception caught", t);
+        log.warn("exceptionCaught({}) {}: {}", this, t.getClass().getSimpleName(), t.getMessage());
+        if (log.isDebugEnabled()) {
+            log.debug("execeptionCaught(" + this + ") details", t);
+        }
+
         if (t instanceof SshException) {
             int code = ((SshException) t).getDisconnectCode();
             if (code > 0) {
@@ -623,7 +627,10 @@ public abstract class AbstractSession extends AbstractKexFactoryManager implemen
             listener.sessionClosed(this);
         } catch (RuntimeException t) {
             Throwable e = GenericUtils.peelException(t);
-            log.warn(e.getClass().getSimpleName() + " while signal session " + toString() + " closed: " + e.getMessage(), e);
+            log.warn(e.getClass().getSimpleName() + " while signal session " + toString() + " closed: " + e.getMessage());
+            if (log.isDebugEnabled()) {
+                log.debug("preClose exception details", e);
+            }
         } finally {
             // clear the listeners since we are closing the session (quicker GC)
             this.sessionListeners.clear();

http://git-wip-us.apache.org/repos/asf/mina-sshd/blob/b07095c9/sshd-core/src/main/java/org/apache/sshd/server/channel/AbstractServerChannel.java
----------------------------------------------------------------------
diff --git a/sshd-core/src/main/java/org/apache/sshd/server/channel/AbstractServerChannel.java b/sshd-core/src/main/java/org/apache/sshd/server/channel/AbstractServerChannel.java
index 45d074b..1cd47a7 100644
--- a/sshd-core/src/main/java/org/apache/sshd/server/channel/AbstractServerChannel.java
+++ b/sshd-core/src/main/java/org/apache/sshd/server/channel/AbstractServerChannel.java
@@ -82,6 +82,9 @@ public abstract class AbstractServerChannel extends AbstractChannel implements S
             } catch (Throwable ignored) {
                 log.warn("doInit({}) failed ({}) to inform listener of open failure={}: {}",
                          this, ignored.getClass().getSimpleName(), e.getClass().getSimpleName(), ignored.getMessage());
+                if (log.isDebugEnabled()) {
+                    log.debug("doInit(" + this + ") listener inform failure details", ignored);
+                }
             }
             f.setException(e);
         }

http://git-wip-us.apache.org/repos/asf/mina-sshd/blob/b07095c9/sshd-core/src/main/java/org/apache/sshd/server/channel/ChannelSession.java
----------------------------------------------------------------------
diff --git a/sshd-core/src/main/java/org/apache/sshd/server/channel/ChannelSession.java b/sshd-core/src/main/java/org/apache/sshd/server/channel/ChannelSession.java
index 985ac7c..e3b422e 100644
--- a/sshd-core/src/main/java/org/apache/sshd/server/channel/ChannelSession.java
+++ b/sshd-core/src/main/java/org/apache/sshd/server/channel/ChannelSession.java
@@ -166,6 +166,9 @@ public class ChannelSession extends AbstractServerChannel {
             } catch (Exception e) {
                 log.warn("doCloseImmediately({}) failed ({}) to destroy command: {}",
                          this, e.getClass().getSimpleName(), e.getMessage());
+                if (log.isDebugEnabled()) {
+                    log.debug("doCloseImmediately(" + this + ") command destruction failure details", e);
+                }
             } finally {
                 command = null;
             }

http://git-wip-us.apache.org/repos/asf/mina-sshd/blob/b07095c9/sshd-core/src/main/java/org/apache/sshd/server/forward/TcpipServerChannel.java
----------------------------------------------------------------------
diff --git a/sshd-core/src/main/java/org/apache/sshd/server/forward/TcpipServerChannel.java b/sshd-core/src/main/java/org/apache/sshd/server/forward/TcpipServerChannel.java
index a47a3e0..6519555 100644
--- a/sshd-core/src/main/java/org/apache/sshd/server/forward/TcpipServerChannel.java
+++ b/sshd-core/src/main/java/org/apache/sshd/server/forward/TcpipServerChannel.java
@@ -205,6 +205,9 @@ public class TcpipServerChannel extends AbstractServerChannel {
             } catch (Throwable ignored) {
                 log.warn("handleChannelConnectResult({})[exception] failed ({}) to inform listener of open failure={}: {}",
                          this, ignored.getClass().getSimpleName(), e.getClass().getSimpleName(), ignored.getMessage());
+                if (log.isDebugEnabled()) {
+                    log.debug("handleChannelConnectResult(" + this + ")[exception] listener exception details", ignored);
+                }
             }
             f.setException(e);
         }

http://git-wip-us.apache.org/repos/asf/mina-sshd/blob/b07095c9/sshd-core/src/main/java/org/apache/sshd/server/kex/DHGEXServer.java
----------------------------------------------------------------------
diff --git a/sshd-core/src/main/java/org/apache/sshd/server/kex/DHGEXServer.java b/sshd-core/src/main/java/org/apache/sshd/server/kex/DHGEXServer.java
index 4509ae5..667db11 100644
--- a/sshd-core/src/main/java/org/apache/sshd/server/kex/DHGEXServer.java
+++ b/sshd-core/src/main/java/org/apache/sshd/server/kex/DHGEXServer.java
@@ -300,7 +300,9 @@ public class DHGEXServer extends AbstractDHServerKeyExchange {
             }
         }
 
-        log.debug("Loaded moduli groups from {}", moduliStr);
+        if (log.isDebugEnabled()) {
+            log.debug("Loaded moduli groups from {}", moduliStr);
+        }
         return groups;
     }
 

http://git-wip-us.apache.org/repos/asf/mina-sshd/blob/b07095c9/sshd-core/src/main/java/org/apache/sshd/server/keyprovider/AbstractGeneratorHostKeyProvider.java
----------------------------------------------------------------------
diff --git a/sshd-core/src/main/java/org/apache/sshd/server/keyprovider/AbstractGeneratorHostKeyProvider.java b/sshd-core/src/main/java/org/apache/sshd/server/keyprovider/AbstractGeneratorHostKeyProvider.java
index dc0ca54..de00461 100644
--- a/sshd-core/src/main/java/org/apache/sshd/server/keyprovider/AbstractGeneratorHostKeyProvider.java
+++ b/sshd-core/src/main/java/org/apache/sshd/server/keyprovider/AbstractGeneratorHostKeyProvider.java
@@ -32,6 +32,7 @@ import java.security.KeyPairGenerator;
 import java.security.spec.AlgorithmParameterSpec;
 import java.util.Collections;
 
+import org.apache.sshd.common.config.keys.KeyUtils;
 import org.apache.sshd.common.keyprovider.AbstractKeyPairProvider;
 import org.apache.sshd.common.util.SecurityUtils;
 import org.apache.sshd.common.util.io.IoUtils;
@@ -114,10 +115,11 @@ public abstract class AbstractGeneratorHostKeyProvider extends AbstractKeyPairPr
                     try {
                         keyPair = readKeyPair(keyPath, IoUtils.EMPTY_OPEN_OPTIONS);
                     } catch (Exception e) {
-                        log.warn("Failed (" + e.getClass().getSimpleName() + ")"
-                                        + " to load from " + keyPath
-                                        + ": " + e.getMessage(),
-                                e);
+                        log.warn("Failed ({}) to load from {}: {}",
+                                 e.getClass().getSimpleName(), keyPath, e.getMessage());
+                        if (log.isDebugEnabled()) {
+                            log.debug("loadKeys(" + keyPath + ") failure details", e);
+                        }
                     }
                 }
             }
@@ -128,19 +130,22 @@ public abstract class AbstractGeneratorHostKeyProvider extends AbstractKeyPairPr
             try {
                 keyPair = generateKeyPair(alg);
             } catch (Exception e) {
-                log.warn("Failed (" + e.getClass().getSimpleName() + ")"
-                                + " to generate " + alg + " keys: " + e.getMessage(),
-                        e);
+                log.warn("loadKeys({})[{}] Failed ({}) to generate {} key-pair: {}",
+                         keyPath, alg, e.getClass().getSimpleName(), alg, e.getMessage());
+                if (log.isDebugEnabled()) {
+                    log.debug("loadKeys(" + keyPath + ")[" + alg + "] key-pair generation failure details", e);
+                }
             }
 
             if ((keyPair != null) && (keyPath != null)) {
                 try {
                     writeKeyPair(keyPair, keyPath);
                 } catch (Exception e) {
-                    log.warn("Failed (" + e.getClass().getSimpleName() + ")"
-                                    + " to write to " + keyPath
-                                    + ": " + e.getMessage(),
-                            e);
+                    log.warn("loadKeys({})[{}] Failed ({}) to write {} key: {}",
+                             alg, keyPath, e.getClass().getSimpleName(), alg, e.getMessage());
+                    if (log.isDebugEnabled()) {
+                        log.debug("loadKeys(" + keyPath + ")[" + alg + "] writefailure details", e);
+                    }
                 }
             }
         }
@@ -165,10 +170,15 @@ public abstract class AbstractGeneratorHostKeyProvider extends AbstractKeyPairPr
             try (OutputStream os = Files.newOutputStream(keyPath, options)) {
                 doWriteKeyPair(keyPath.toString(), kp, os);
             } catch (Exception e) {
-                log.warn("Unable to write key {}: {}", path, e);
+                log.warn("writeKeyPair({}) failed ({}) to write key {}: {}",
+                         keyPath, e.getClass().getSimpleName(), e.getMessage());
+                if (log.isDebugEnabled()) {
+                    log.debug("writeKeyPair(" + keyPath + ") write failure details", e);
+                }
             }
         } else {
-            log.error("Overwriting key ({}) is disabled: using throwaway {}", keyPath, kp);
+            log.error("Overwriting key ({}) is disabled: using throwaway {}: {}",
+                      keyPath, KeyUtils.getKeyType(kp), KeyUtils.getFingerPrint((kp == null) ? null : kp.getPublic()));
         }
     }
 

http://git-wip-us.apache.org/repos/asf/mina-sshd/blob/b07095c9/sshd-core/src/main/java/org/apache/sshd/server/shell/InvertedShellWrapper.java
----------------------------------------------------------------------
diff --git a/sshd-core/src/main/java/org/apache/sshd/server/shell/InvertedShellWrapper.java b/sshd-core/src/main/java/org/apache/sshd/server/shell/InvertedShellWrapper.java
index 43155ff..d9bb8ad 100644
--- a/sshd-core/src/main/java/org/apache/sshd/server/shell/InvertedShellWrapper.java
+++ b/sshd-core/src/main/java/org/apache/sshd/server/shell/InvertedShellWrapper.java
@@ -165,6 +165,9 @@ public class InvertedShellWrapper extends AbstractLoggingBean implements Command
         } catch (Exception e) {
             log.warn("destroy({}) failed ({}) to destroy shell: {}",
                      this, e.getClass().getSimpleName(), e.getMessage());
+            if (log.isDebugEnabled()) {
+                log.debug("destroy(" + this + ") shell destruction failure details", e);
+            }
             err = GenericUtils.accumulateException(err, e);
         }
 
@@ -174,6 +177,9 @@ public class InvertedShellWrapper extends AbstractLoggingBean implements Command
             } catch (Exception e) {
                 log.warn("destroy({}) failed ({}) to shut down executor: {}",
                          this, e.getClass().getSimpleName(), e.getMessage());
+                if (log.isDebugEnabled()) {
+                    log.debug("destroy(" + this + ") executor shutdown failure details", e);
+                }
                 err = GenericUtils.accumulateException(err, e);
             }
         }
@@ -219,7 +225,9 @@ public class InvertedShellWrapper extends AbstractLoggingBean implements Command
             } catch (Exception err) {
                 log.warn("pumpStreams({}) failed ({}) to destroy shell: {}",
                          this, e.getClass().getSimpleName(), e.getMessage());
-                err = GenericUtils.accumulateException(err, e);
+                if (log.isDebugEnabled()) {
+                    log.debug("pumpStreams(" + this + ") shell destruction failure details", err);
+                }
             }
 
             int exitValue = shell.exitValue();

http://git-wip-us.apache.org/repos/asf/mina-sshd/blob/b07095c9/sshd-core/src/main/java/org/apache/sshd/server/shell/ProcessShell.java
----------------------------------------------------------------------
diff --git a/sshd-core/src/main/java/org/apache/sshd/server/shell/ProcessShell.java b/sshd-core/src/main/java/org/apache/sshd/server/shell/ProcessShell.java
index dbe47a7..78492b7 100644
--- a/sshd-core/src/main/java/org/apache/sshd/server/shell/ProcessShell.java
+++ b/sshd-core/src/main/java/org/apache/sshd/server/shell/ProcessShell.java
@@ -95,7 +95,11 @@ public class ProcessShell extends AbstractLoggingBean implements InvertedShell,
                 Map<String, String> procEnv = builder.environment();
                 procEnv.putAll(varsMap);
             } catch (Exception e) {
-                log.warn("Could not set environment for command=" + cmdValue, e);
+                log.warn("start() - Failed ({}) to set environment for command={}: {}",
+                         e.getClass().getSimpleName(), cmdValue, e.getMessage());
+                if (log.isDebugEnabled()) {
+                    log.debug("start(" + cmdValue + ") failure details", e);
+                }
             }
         }
 

http://git-wip-us.apache.org/repos/asf/mina-sshd/blob/b07095c9/sshd-core/src/main/java/org/apache/sshd/server/subsystem/sftp/SftpSubsystem.java
----------------------------------------------------------------------
diff --git a/sshd-core/src/main/java/org/apache/sshd/server/subsystem/sftp/SftpSubsystem.java b/sshd-core/src/main/java/org/apache/sshd/server/subsystem/sftp/SftpSubsystem.java
index 850c5fe..17e00f0 100644
--- a/sshd-core/src/main/java/org/apache/sshd/server/subsystem/sftp/SftpSubsystem.java
+++ b/sshd-core/src/main/java/org/apache/sshd/server/subsystem/sftp/SftpSubsystem.java
@@ -2785,6 +2785,10 @@ public class SftpSubsystem
     }
 
     protected Map<String, Object> handleReadFileAttributesException(Path file, String view, LinkOption[] options, IOException e) throws IOException {
+        if (log.isTraceEnabled()) {
+            log.trace("handleReadFileAttributesException(" + file + ")[" + view + "] details", e);
+        }
+
         switch (unsupportedAttributePolicy) {
             case Ignore:
                 break;
@@ -2990,6 +2994,10 @@ public class SftpSubsystem
     }
 
     protected void handleUserPrincipalLookupServiceException(Class<? extends Principal> principalType, String name, IOException e) throws IOException {
+        if (log.isTraceEnabled()) {
+            log.trace("handleUserPrincipalLookupServiceException(" + principalType.getSimpleName() + "[" + name + "]) details", e);
+        }
+
         /* According to Javadoc:
          *
          *      "Where an implementation does not support any notion of group
@@ -3080,7 +3088,11 @@ public class SftpSubsystem
                 SftpEventListener listener = getSftpEventListenerProxy();
                 listener.destroying(getServerSession());
             } catch (Exception e) {
-                log.warn("Failed (" + e.getClass().getSimpleName() + ") to announce destruction event: " + e.getMessage(), e);
+                log.warn("destroy({}) Failed ({}) to announce destruction event: {}",
+                         getServerSession(), e.getClass().getSimpleName(), e.getMessage());
+                if (log.isDebugEnabled()) {
+                    log.debug("destroy(" + getServerSession() + ") destruction announcement failure details", e);
+                }
             }
 
             // if thread has not completed, cancel it

http://git-wip-us.apache.org/repos/asf/mina-sshd/blob/b07095c9/sshd-core/src/test/java/org/apache/sshd/client/scp/ScpTest.java
----------------------------------------------------------------------
diff --git a/sshd-core/src/test/java/org/apache/sshd/client/scp/ScpTest.java b/sshd-core/src/test/java/org/apache/sshd/client/scp/ScpTest.java
index 1fd8194..fc34111 100644
--- a/sshd-core/src/test/java/org/apache/sshd/client/scp/ScpTest.java
+++ b/sshd-core/src/test/java/org/apache/sshd/client/scp/ScpTest.java
@@ -691,12 +691,14 @@ public class ScpTest extends BaseTestSupport {
                 Path remoteFile = remoteDir.resolve("file.txt");
                 String remotePath = Utils.resolveRelativeRemotePath(parentPath, remoteFile);
                 byte[] data = (getClass().getName() + "#" + getCurrentTestName()).getBytes(StandardCharsets.UTF_8);
+                outputDebugMessage("Upload data to %s", remotePath);
                 scp.upload(data, remotePath, EnumSet.allOf(PosixFilePermission.class), null);
                 assertFileLength(remoteFile, data.length, TimeUnit.SECONDS.toMillis(5L));
 
                 byte[] uploaded = Files.readAllBytes(remoteFile);
                 assertArrayEquals("Mismatched uploaded data", data, uploaded);
 
+                outputDebugMessage("Download data from %s", remotePath);
                 byte[] downloaded = scp.downloadBytes(remotePath);
                 assertArrayEquals("Mismatched downloaded data", uploaded, downloaded);
             } finally {

http://git-wip-us.apache.org/repos/asf/mina-sshd/blob/b07095c9/sshd-core/src/test/java/org/apache/sshd/common/channel/TestChannelListener.java
----------------------------------------------------------------------
diff --git a/sshd-core/src/test/java/org/apache/sshd/common/channel/TestChannelListener.java b/sshd-core/src/test/java/org/apache/sshd/common/channel/TestChannelListener.java
index 780374d..153eee9 100644
--- a/sshd-core/src/test/java/org/apache/sshd/common/channel/TestChannelListener.java
+++ b/sshd-core/src/test/java/org/apache/sshd/common/channel/TestChannelListener.java
@@ -88,6 +88,9 @@ public class TestChannelListener extends AbstractLoggingBean implements ChannelL
         Assert.assertTrue("Same channel instance re-failed: " + channel, failedChannels.add(channel));
         modificationsCounter.release();
         log.warn("channelOpenFailure({}) {} : {}", channel, reason.getClass().getSimpleName(), reason.getMessage());
+        if (log.isDebugEnabled()) {
+            log.debug("channelOpenFailure(" + channel + ") details", reason);
+        }
     }
 
     @Override

http://git-wip-us.apache.org/repos/asf/mina-sshd/blob/b07095c9/sshd-core/src/test/java/org/apache/sshd/server/subsystem/sftp/SshFsMounter.java
----------------------------------------------------------------------
diff --git a/sshd-core/src/test/java/org/apache/sshd/server/subsystem/sftp/SshFsMounter.java b/sshd-core/src/test/java/org/apache/sshd/server/subsystem/sftp/SshFsMounter.java
index 2218a7a..7195e7f 100644
--- a/sshd-core/src/test/java/org/apache/sshd/server/subsystem/sftp/SshFsMounter.java
+++ b/sshd-core/src/test/java/org/apache/sshd/server/subsystem/sftp/SshFsMounter.java
@@ -189,6 +189,9 @@ public class SshFsMounter {
                     log.info("destroy(" + username + ")[" + command + "] stdin closed");
                 } catch (IOException e) {
                     log.warn("destroy(" + username + ")[" + command + "] failed (" + e.getClass().getSimpleName() + ") to close stdin: " + e.getMessage());
+                    if (log.isDebugEnabled()) {
+                        log.debug("destroy(" + username + ")[" + command + "] failure details", e);
+                    }
                 } finally {
                     stdin = null;
                 }