SLCORE-292 Handle exceptions passed to logger as last format param

core/src/main/java/org/sonar/api/utils/log/SonarLintLogger.java

@@ -20,14 +20,15 @@
 package org.sonar.api.utils.log;
 
 import org.sonarsource.sonarlint.core.client.api.common.LogOutput.Level;
+import org.sonarsource.sonarlint.core.log.EventArgUtil;
 import org.sonarsource.sonarlint.core.log.LogOutputDelegator;
 import org.sonarsource.sonarlint.core.log.MessageFormat;
 
 /**
  * This class can't be moved to another package because {@link BaseLogger} is not public.
  */
 public class SonarLintLogger extends BaseLogger {
-  private LogOutputDelegator logOutput;
+  private final LogOutputDelegator logOutput;
 
   public SonarLintLogger(LogOutputDelegator logOutput) {
     this.logOutput = logOutput;
@@ -61,20 +62,18 @@ void doDebug(String msg) {
 
   @Override
   void doDebug(String msg, Object arg) {
-    logOutput.log(MessageFormat.format(msg, new Object[] {arg}), Level.DEBUG);
+    doLogExtractingThrowable(Level.DEBUG, msg, new Object[] {arg});
 
   }
 
   @Override
   void doDebug(String msg, Object arg1, Object arg2) {
-    logOutput.log(MessageFormat.format(msg, new Object[] {arg1, arg2}), Level.DEBUG);
-
+    doLogExtractingThrowable(Level.DEBUG, msg, new Object[] {arg1, arg2});
   }
 
   @Override
   void doDebug(String msg, Object... args) {
-    logOutput.log(MessageFormat.format(msg, args), Level.DEBUG);
-
+    doLogExtractingThrowable(Level.DEBUG, msg, args);
   }
 
   @Override
@@ -85,18 +84,17 @@ void doInfo(String msg) {
 
   @Override
   void doInfo(String msg, Object arg) {
-    logOutput.log(MessageFormat.format(msg, new Object[] {arg}), Level.INFO);
-
+    doLogExtractingThrowable(Level.INFO, msg, new Object[] {arg});
   }
 
   @Override
   void doInfo(String msg, Object arg1, Object arg2) {
-    logOutput.log(MessageFormat.format(msg, new Object[] {arg1, arg2}), Level.INFO);
+    doLogExtractingThrowable(Level.INFO, msg, new Object[] {arg1, arg2});
   }
 
   @Override
   void doInfo(String msg, Object... args) {
-    logOutput.log(MessageFormat.format(msg, args), Level.INFO);
+    doLogExtractingThrowable(Level.INFO, msg, args);
   }
 
   @Override
@@ -111,17 +109,17 @@ void doWarn(String msg, Throwable thrown) {
 
   @Override
   void doWarn(String msg, Object arg) {
-    logOutput.log(MessageFormat.format(msg, new Object[] {arg}), Level.WARN);
+    doLogExtractingThrowable(Level.WARN, msg, new Object[] {arg});
   }
 
   @Override
   void doWarn(String msg, Object arg1, Object arg2) {
-    logOutput.log(MessageFormat.format(msg, new Object[] {arg1, arg2}), Level.WARN);
+    doLogExtractingThrowable(Level.WARN, msg, new Object[] {arg1, arg2});
   }
 
   @Override
   void doWarn(String msg, Object... args) {
-    logOutput.log(MessageFormat.format(msg, args), Level.WARN);
+    doLogExtractingThrowable(Level.WARN, msg, args);
   }
 
   @Override
@@ -131,24 +129,34 @@ void doError(String msg) {
 
   @Override
   void doError(String msg, Object arg) {
-    logOutput.log(MessageFormat.format(msg, new Object[] {arg}), Level.ERROR);
+    doLogExtractingThrowable(Level.ERROR, msg, new Object[] {arg});
   }
 
   @Override
   void doError(String msg, Object arg1, Object arg2) {
-    logOutput.log(MessageFormat.format(msg, new Object[] {arg1, arg2}), Level.ERROR);
+    doLogExtractingThrowable(Level.ERROR, msg, new Object[] {arg1, arg2});
   }
 
   @Override
   void doError(String msg, Object... args) {
-    logOutput.log(MessageFormat.format(msg, args), Level.ERROR);
+    doLogExtractingThrowable(Level.ERROR, msg, args);
   }
 
   @Override
   void doError(String msg, Throwable thrown) {
     logOutput.log(msg, Level.ERROR, thrown);
   }
 
+  private void doLogExtractingThrowable(Level level, String msg, Object[] argArray) {
+    Throwable extractedThrowable = EventArgUtil.extractThrowable(argArray);
+    if (EventArgUtil.successfulExtraction(extractedThrowable)) {
+      Object[] trimmedArgArray = EventArgUtil.trimmedCopy(argArray);
+      logOutput.log(MessageFormat.format(msg, trimmedArgArray), level, extractedThrowable);
+    } else {
+      logOutput.log(MessageFormat.format(msg, argArray), level);
+    }
+  }
+
   @Override
   public boolean isTraceEnabled() {
     return false;

core/src/main/java/org/sonarsource/sonarlint/core/log/EventArgUtil.java

@@ -0,0 +1,58 @@
+/*
+ * SonarLint Core - Implementation
+ * Copyright (C) 2016-2021 SonarSource SA
+ * mailto:info AT sonarsource DOT com
+ *
+ * This program is free software; you can redistribute it and/or
+ * modify it under the terms of the GNU Lesser General Public
+ * License as published by the Free Software Foundation; either
+ * version 3 of the License, or (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
+ * Lesser General Public License for more details.
+ *
+ * You should have received a copy of the GNU Lesser General Public License
+ * along with this program; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301, USA.
+ */
+package org.sonarsource.sonarlint.core.log;
+
+import javax.annotation.Nullable;
+
+/**
+ * Inspired from logback
+ *
+ */
+public class EventArgUtil {
+
+  public static final Throwable extractThrowable(@Nullable Object[] argArray) {
+    if (argArray == null || argArray.length == 0) {
+      return null;
+    }
+
+    final Object lastEntry = argArray[argArray.length - 1];
+    if (lastEntry instanceof Throwable) {
+      return (Throwable) lastEntry;
+    }
+    return null;
+  }
+
+  /**
+   * This method should be called only if {@link #successfulExtraction(Throwable)} returns true.
+   *
+   * @param argArray
+   * @return
+   */
+  public static Object[] trimmedCopy(Object[] argArray) {
+    final int trimemdLen = argArray.length - 1;
+    Object[] trimmed = new Object[trimemdLen];
+    System.arraycopy(argArray, 0, trimmed, 0, trimemdLen);
+    return trimmed;
+  }
+
+  public static boolean successfulExtraction(Throwable throwable) {
+    return throwable != null;
+  }
+}

core/src/test/java/org/sonar/api/utils/log/SonarLintLoggerTest.java

@@ -20,45 +20,69 @@
 package org.sonar.api.utils.log;
 
 import org.junit.Test;
+import org.mockito.InOrder;
+import org.mockito.Mockito;
 import org.sonarsource.sonarlint.core.client.api.common.LogOutput.Level;
 import org.sonarsource.sonarlint.core.log.LogOutputDelegator;
 
 import static org.assertj.core.api.Assertions.assertThat;
 import static org.mockito.Mockito.mock;
-import static org.mockito.Mockito.verify;
-import static org.mockito.Mockito.verifyZeroInteractions;
+import static org.mockito.Mockito.times;
+import static org.mockito.Mockito.verifyNoInteractions;
 
 public class SonarLintLoggerTest {
-  private LogOutputDelegator delegator = mock(LogOutputDelegator.class);
-  private SonarLintLogger logger = new SonarLintLogger(delegator);
+  private final LogOutputDelegator delegator = mock(LogOutputDelegator.class);
+  private final SonarLintLogger logger = new SonarLintLogger(delegator);
 
   @Test
   public void should_not_log_trace() {
     logger.doTrace("msg");
     logger.doTrace("msg", "a");
     logger.doTrace("msg", "a", "a");
-    logger.doTrace("msg", new Object[] {"a"});
+    // Keep a separate variable to avoid Eclipse refactoring into a non varargs method
+    Object[] args = new Object[] {"a"};
+    logger.doTrace("msg", args);
 
-    verifyZeroInteractions(delegator);
+    verifyNoInteractions(delegator);
   }
 
   @Test
   public void should_log_error() {
     logger.doError("msg");
+    logger.doError("msg", (Object) null);
+    // Keep a separate variable to avoid Eclipse refactoring into a non varargs method
+    Object[] emptyArgs = new Object[0];
+    logger.doError("msg", emptyArgs);
     logger.doError("msg {}", "a");
     logger.doError("msg {} {}", "a", "a");
-    logger.doError("msg {}", new Object[] {"b"});
+    // Keep a separate variable to avoid Eclipse refactoring into a non varargs method
+    Object[] args = new Object[] {"b"};
+    logger.doError("msg {}", args);
 
-    verify(delegator).log("msg", Level.ERROR);
-    verify(delegator).log("msg a", Level.ERROR);
-    verify(delegator).log("msg a a", Level.ERROR);
-    verify(delegator).log("msg b", Level.ERROR);
+    InOrder inOrder = Mockito.inOrder(delegator);
+    inOrder.verify(delegator, times(3)).log("msg", Level.ERROR);
+    inOrder.verify(delegator).log("msg a", Level.ERROR);
+    inOrder.verify(delegator).log("msg a a", Level.ERROR);
+    inOrder.verify(delegator).log("msg b", Level.ERROR);
   }
 
   @Test
   public void level_is_always_debug() {
     assertThat(logger.setLevel(LoggerLevel.INFO)).isFalse();
     assertThat(logger.getLevel()).isEqualTo(LoggerLevel.DEBUG);
+  }
+
+  // SLCORE-292
+  @Test
+  public void extract_throwable_from_format_params() {
+    Throwable throwable = new Throwable("thrown");
+    logger.doError("msg", (Object) throwable);
+    logger.doError("msg {}", "a", throwable);
+    logger.doError("msg {} {}", "a", "a", throwable);
 
+    InOrder inOrder = Mockito.inOrder(delegator);
+    inOrder.verify(delegator).log("msg", Level.ERROR, throwable);
+    inOrder.verify(delegator).log("msg a", Level.ERROR, throwable);
+    inOrder.verify(delegator).log("msg a a", Level.ERROR, throwable);
   }
 }