]> source.dussan.org Git - sonarqube.git/commitdiff
SONAR-8333 make APP logging configuration support 4 log files
authorSébastien Lesaint <sebastien.lesaint@sonarsource.com>
Mon, 14 Nov 2016 13:39:22 +0000 (14:39 +0100)
committerSébastien Lesaint <sebastien.lesaint@sonarsource.com>
Wed, 16 Nov 2016 09:09:21 +0000 (10:09 +0100)
add support for option sonar.wrapped=true to detect when SQ is started by JWP (wrapper) and correctly support all logging use cases
include refactoring at LogBackHelper level to simplify code
refactor applying log level property to make all process support only INFO, DEBUG and TRACE

15 files changed:
server/sonar-process/src/main/java/org/sonar/process/LogbackHelper.java
server/sonar-process/src/test/java/org/sonar/process/LogbackHelperTest.java
server/sonar-search/src/main/java/org/sonar/search/SearchLogging.java
server/sonar-search/src/test/java/org/sonar/search/SearchLoggingTest.java
server/sonar-server/src/main/java/org/sonar/ce/log/CeProcessLogging.java
server/sonar-server/src/main/java/org/sonar/server/app/ServerProcessLogging.java
server/sonar-server/src/main/java/org/sonar/server/app/WebServerProcessLogging.java
server/sonar-server/src/main/java/org/sonar/server/platform/ServerLogging.java
server/sonar-server/src/main/java/org/sonar/server/platform/ws/ChangeLogLevelAction.java
server/sonar-server/src/test/java/org/sonar/ce/log/CeProcessLoggingTest.java
server/sonar-server/src/test/java/org/sonar/server/app/WebServerProcessLoggingTest.java
server/sonar-server/src/test/java/org/sonar/server/platform/ServerLoggingTest.java
sonar-application/src/main/assembly/conf/wrapper.conf
sonar-application/src/main/java/org/sonar/application/AppLogging.java
sonar-application/src/test/java/org/sonar/application/AppLoggingTest.java

index d4496f747c11c394a81dc571208c3e0eb8500719..a669c91a9cee8c2bf330664b646f7f920ed2b0b6 100644 (file)
@@ -30,33 +30,40 @@ import ch.qos.logback.classic.spi.LoggerContextListener;
 import ch.qos.logback.core.ConsoleAppender;
 import ch.qos.logback.core.Context;
 import ch.qos.logback.core.FileAppender;
-import ch.qos.logback.core.filter.Filter;
 import ch.qos.logback.core.joran.spi.JoranException;
 import ch.qos.logback.core.rolling.FixedWindowRollingPolicy;
 import ch.qos.logback.core.rolling.RollingFileAppender;
 import ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy;
 import ch.qos.logback.core.rolling.TimeBasedRollingPolicy;
 import java.io.File;
+import java.util.Arrays;
+import java.util.HashSet;
+import java.util.Set;
 import javax.annotation.CheckForNull;
 import org.apache.commons.lang.StringUtils;
 import org.slf4j.LoggerFactory;
 
+import static java.util.Collections.unmodifiableSet;
 import static java.util.Objects.requireNonNull;
+import static org.slf4j.Logger.ROOT_LOGGER_NAME;
 
 /**
  * Helps to configure Logback in a programmatic way, without using XML.
  */
 public class LogbackHelper {
 
-  public static final String ROLLING_POLICY_PROPERTY = "sonar.log.rollingPolicy";
-  public static final String MAX_FILES_PROPERTY = "sonar.log.maxFiles";
+  private static final String ALL_LOGS_TO_CONSOLE_PROPERTY = "sonar.log.console";
+  private static final String SONAR_LOG_LEVEL_PROPERTY = "sonar.log.level";
+  private static final String ROLLING_POLICY_PROPERTY = "sonar.log.rollingPolicy";
+  private static final String MAX_FILES_PROPERTY = "sonar.log.maxFiles";
   private static final String PROCESS_NAME_PLACEHOLDER = "XXXX";
   private static final String THREAD_ID_PLACEHOLDER = "ZZZZ";
   private static final String LOG_FORMAT = "%d{yyyy.MM.dd HH:mm:ss} %-5level " + PROCESS_NAME_PLACEHOLDER + "[" + THREAD_ID_PLACEHOLDER + "][%logger{20}] %msg%n";
+  public static final Set<Level> ALLOWED_ROOT_LOG_LEVELS = unmodifiableSet(setOf(Level.TRACE, Level.DEBUG, Level.INFO));
 
   public LoggerContext getRootContext() {
     org.slf4j.Logger logger;
-    while (!((logger = LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME)) instanceof Logger)) {
+    while (!((logger = LoggerFactory.getLogger(ROOT_LOGGER_NAME)) instanceof Logger)) {
       // It occurs when the initialization step is still not finished because of a race condition
       // on ILoggerFactory.getILoggerFactory
       // http://jira.qos.ch/browse/SLF4J-167
@@ -83,14 +90,12 @@ public class LogbackHelper {
   public static final class RootLoggerConfig {
     private final String processName;
     private final String threadIdFieldPattern;
-    private final String fileName;
-    private final boolean detachConsole;
+    private final String fileNamePrefix;
 
-    public RootLoggerConfig(Builder builder) {
+    private RootLoggerConfig(Builder builder) {
       this.processName = builder.processName;
       this.threadIdFieldPattern = builder.threadIdFieldPattern;
-      this.fileName = builder.fileName;
-      this.detachConsole = builder.detachConsole;
+      this.fileNamePrefix = builder.fileNamePrefix;
     }
 
     public static Builder newRootLoggerConfigBuilder() {
@@ -101,16 +106,12 @@ public class LogbackHelper {
       return processName;
     }
 
-    public String getThreadIdFieldPattern() {
+    String getThreadIdFieldPattern() {
       return threadIdFieldPattern;
     }
 
-    public String getFileName() {
-      return fileName;
-    }
-
-    public boolean isDetachConsole() {
-      return detachConsole;
+    String getFileNamePrefix() {
+      return fileNamePrefix;
     }
 
     public static final class Builder {
@@ -118,8 +119,7 @@ public class LogbackHelper {
       public String processName;
       private String threadIdFieldPattern = "";
       @CheckForNull
-      private String fileName;
-      private boolean detachConsole = true;
+      private String fileNamePrefix;
 
       private Builder() {
         // prevents instantiation outside RootLoggerConfig, use static factory method
@@ -136,15 +136,15 @@ public class LogbackHelper {
         return this;
       }
 
-      public Builder setFileName(String fileName) {
-        checkFileName(fileName);
-        this.fileName = fileName;
+      public Builder setFileNamePrefix(String fileNamePrefix) {
+        checkFileName(fileNamePrefix);
+        this.fileNamePrefix = fileNamePrefix;
         return this;
       }
 
       private static void checkFileName(String fileName) {
-        if (requireNonNull(fileName, "fileName can't be null").isEmpty()) {
-          throw new IllegalArgumentException("fileName can't be empty");
+        if (requireNonNull(fileName, "fileNamePrefix can't be null").isEmpty()) {
+          throw new IllegalArgumentException("fileNamePrefix can't be empty");
         }
       }
 
@@ -154,60 +154,140 @@ public class LogbackHelper {
         }
       }
 
-      public Builder setDetachConsole(boolean detachConsole) {
-        this.detachConsole = detachConsole;
-        return this;
-      }
-
       public RootLoggerConfig build() {
         checkProcessName(this.processName);
-        checkFileName(this.fileName);
+        checkFileName(this.fileNamePrefix);
         return new RootLoggerConfig(this);
       }
     }
   }
 
-  public void configureRootLogger(LoggerContext ctx, Props props, RootLoggerConfig config) {
-    String logFormat = LOG_FORMAT
-        .replace(PROCESS_NAME_PLACEHOLDER, config.getProcessName())
-        .replace(THREAD_ID_PLACEHOLDER, config.getThreadIdFieldPattern());
-    // configure appender
-    LogbackHelper.RollingPolicy rollingPolicy = createRollingPolicy(ctx, props, config.getFileName());
-    FileAppender<ILoggingEvent> fileAppender = rollingPolicy.createAppender("file");
-    fileAppender.setContext(ctx);
-    PatternLayoutEncoder fileEncoder = new PatternLayoutEncoder();
-    fileEncoder.setContext(ctx);
-    fileEncoder.setPattern(logFormat);
-    fileEncoder.start();
-    fileAppender.setEncoder(fileEncoder);
-    fileAppender.start();
-
-    // configure logger
-    Logger rootLogger = ctx.getLogger(ch.qos.logback.classic.Logger.ROOT_LOGGER_NAME);
-    rootLogger.addAppender(fileAppender);
-//    if (config.isDetachConsole()) {
-//      rootLogger.detachAppender("console");
-//    }
-    rootLogger.addAppender(newConsoleAppender(ctx, "console", logFormat));
+  public String buildLogPattern(LogbackHelper.RootLoggerConfig config) {
+    return LOG_FORMAT
+      .replace(PROCESS_NAME_PLACEHOLDER, config.getProcessName())
+      .replace(THREAD_ID_PLACEHOLDER, config.getThreadIdFieldPattern());
   }
 
-  public ConsoleAppender newConsoleAppender(Context loggerContext, String name, String pattern, Filter... filters) {
+  /**
+   * Creates a new {@link ConsoleAppender} to {@code System.out} with the specified name and log pattern.
+   *
+   * @see #buildLogPattern(RootLoggerConfig)
+   */
+  public ConsoleAppender<ILoggingEvent> newConsoleAppender(Context loggerContext, String name, String logPattern) {
     PatternLayoutEncoder consoleEncoder = new PatternLayoutEncoder();
     consoleEncoder.setContext(loggerContext);
-    consoleEncoder.setPattern(pattern);
+    consoleEncoder.setPattern(logPattern);
     consoleEncoder.start();
-    ConsoleAppender consoleAppender = new ConsoleAppender();
+    ConsoleAppender<ILoggingEvent> consoleAppender = new ConsoleAppender<>();
     consoleAppender.setContext(loggerContext);
     consoleAppender.setEncoder(consoleEncoder);
     consoleAppender.setName(name);
     consoleAppender.setTarget("System.out");
-    for (Filter filter : filters) {
-      consoleAppender.addFilter(filter);
-    }
     consoleAppender.start();
     return consoleAppender;
   }
 
+  /**
+   * Make logback configuration for a process to push all its logs to a log file.
+   * <p>
+   *   <ul>
+   *     <li>the file's name will use the prefix defined in {@link RootLoggerConfig#getFileNamePrefix()}.</li>
+   *     <li>the file will follow the rotation policy defined in property {@link #ROLLING_POLICY_PROPERTY} and
+   *     the max number of files defined in property {@link #MAX_FILES_PROPERTY}</li>
+   *     <li>the logs will follow the specified log pattern</li>
+   *   </ul>
+   * </p>
+   *
+   * @see #buildLogPattern(RootLoggerConfig)
+   */
+  public FileAppender<ILoggingEvent> configureGlobalFileLog(Props props, RootLoggerConfig config, String logPattern) {
+    LoggerContext ctx = getRootContext();
+    Logger rootLogger = ctx.getLogger(ROOT_LOGGER_NAME);
+    FileAppender<ILoggingEvent> fileAppender = newFileAppender(ctx, props, config, logPattern);
+    rootLogger.addAppender(fileAppender);
+    return fileAppender;
+  }
+
+  public FileAppender<ILoggingEvent> newFileAppender(LoggerContext ctx, Props props, LogbackHelper.RootLoggerConfig config, String logPattern) {
+    RollingPolicy rollingPolicy = createRollingPolicy(ctx, props, config.getFileNamePrefix());
+    FileAppender<ILoggingEvent> fileAppender = rollingPolicy.createAppender("file_" + config.getFileNamePrefix());
+    fileAppender.setContext(ctx);
+    PatternLayoutEncoder fileEncoder = new PatternLayoutEncoder();
+    fileEncoder.setContext(ctx);
+    fileEncoder.setPattern(logPattern);
+    fileEncoder.start();
+    fileAppender.setEncoder(fileEncoder);
+    fileAppender.start();
+    return fileAppender;
+  }
+
+  /**
+   * Make the logback configuration for a sub process to correctly push all its logs to be read by a stream gobbler
+   * on the sub process's System.out.
+   *
+   * @see #buildLogPattern(RootLoggerConfig)
+   */
+  public void configureForSubprocessGobbler(Props props, String logPattern) {
+    if (isAllLogsToConsoleEnabled(props)) {
+      LoggerContext ctx = getRootContext();
+      ctx.getLogger(ROOT_LOGGER_NAME).addAppender(newConsoleAppender(ctx, "root_console", logPattern));
+    }
+  }
+
+  /**
+   * Finds out whether we are in testing environment (usually ITs) and logs of all processes must be forward to
+   * App's System.out. This is specified by the value of property {@link #ALL_LOGS_TO_CONSOLE_PROPERTY}.
+   */
+  public boolean isAllLogsToConsoleEnabled(Props props) {
+    return props.valueAsBoolean(ALL_LOGS_TO_CONSOLE_PROPERTY, false);
+  }
+
+  @SafeVarargs
+  private static <T> Set<T> setOf(T... args) {
+    Set<T> res = new HashSet<>(args.length);
+    res.addAll(Arrays.asList(args));
+    return res;
+  }
+
+  /**
+   * Configure the log level of the root logger reading the value of property {@link #SONAR_LOG_LEVEL_PROPERTY}.
+   *
+   * @throws IllegalArgumentException if the value of {@link #SONAR_LOG_LEVEL_PROPERTY} is not one of {@link #ALLOWED_ROOT_LOG_LEVELS}
+   */
+  public Level configureRootLogLevel(Props props) {
+    return configureRootLogLevel(props, SONAR_LOG_LEVEL_PROPERTY);
+  }
+
+  /**
+   * Configure the log level of the root logger reading the value of specified property.
+   *
+   * @throws IllegalArgumentException if the value of the specified property is not one of {@link #ALLOWED_ROOT_LOG_LEVELS}
+   */
+  public Level configureRootLogLevel(Props props, String propertyKey) {
+    Level newLevel = Level.toLevel(props.value(propertyKey, Level.INFO.toString()), Level.INFO);
+    return configureRootLogLevel(newLevel);
+  }
+
+  /**
+   * Configure the log level of the root logger to the specified level.
+   *
+   * @throws IllegalArgumentException if the specified level is not one of {@link #ALLOWED_ROOT_LOG_LEVELS}
+   */
+  public Level configureRootLogLevel(Level newLevel) {
+    Logger rootLogger = getRootContext().getLogger(ROOT_LOGGER_NAME);
+    if (!ALLOWED_ROOT_LOG_LEVELS.contains(newLevel)) {
+      throw new IllegalArgumentException(String.format("%s log level is not supported (allowed levels are %s)", newLevel, ALLOWED_ROOT_LOG_LEVELS));
+    }
+    rootLogger.setLevel(newLevel);
+    return newLevel;
+  }
+
+  /**
+   * Configure the log level of the specified logger to specified level.
+   * <p>
+   * Any level is allowed.
+   * </p>
+   */
   public Logger configureLogger(String loggerName, Level level) {
     Logger logger = getRootContext().getLogger(loggerName);
     logger.setLevel(level);
@@ -246,31 +326,31 @@ public class LogbackHelper {
 
   public abstract static class RollingPolicy {
     protected final Context context;
-    protected final String filenamePrefix;
-    protected final File logsDir;
-    protected final int maxFiles;
+    final String filenamePrefix;
+    final File logsDir;
+    final int maxFiles;
 
-    public RollingPolicy(Context context, String filenamePrefix, File logsDir, int maxFiles) {
+    RollingPolicy(Context context, String filenamePrefix, File logsDir, int maxFiles) {
       this.context = context;
       this.filenamePrefix = filenamePrefix;
       this.logsDir = logsDir;
       this.maxFiles = maxFiles;
     }
 
-    public abstract FileAppender createAppender(String appenderName);
+    public abstract FileAppender<ILoggingEvent> createAppender(String appenderName);
   }
 
   /**
    * Log files are not rotated, for example for unix command logrotate is in place.
    */
-  static class NoRollingPolicy extends RollingPolicy {
-    NoRollingPolicy(Context context, String filenamePrefix, File logsDir, int maxFiles) {
+  private static class NoRollingPolicy extends RollingPolicy {
+    private NoRollingPolicy(Context context, String filenamePrefix, File logsDir, int maxFiles) {
       super(context, filenamePrefix, logsDir, maxFiles);
     }
 
     @Override
-    public FileAppender createAppender(String appenderName) {
-      FileAppender appender = new FileAppender<>();
+    public FileAppender<ILoggingEvent> createAppender(String appenderName) {
+      FileAppender<ILoggingEvent> appender = new FileAppender<>();
       appender.setContext(context);
       appender.setFile(new File(logsDir, filenamePrefix + ".log").getAbsolutePath());
       appender.setName(appenderName);
@@ -282,17 +362,17 @@ public class LogbackHelper {
    * Log files are rotated according to time (one file per day, month or year).
    * See http://logback.qos.ch/manual/appenders.html#TimeBasedRollingPolicy
    */
-  static class TimeRollingPolicy extends RollingPolicy {
+  private static class TimeRollingPolicy extends RollingPolicy {
     private final String datePattern;
 
-    public TimeRollingPolicy(Context context, String filenamePrefix, File logsDir, int maxFiles, String datePattern) {
+    private TimeRollingPolicy(Context context, String filenamePrefix, File logsDir, int maxFiles, String datePattern) {
       super(context, filenamePrefix, logsDir, maxFiles);
       this.datePattern = datePattern;
     }
 
     @Override
-    public FileAppender createAppender(String appenderName) {
-      RollingFileAppender appender = new RollingFileAppender();
+    public FileAppender<ILoggingEvent> createAppender(String appenderName) {
+      RollingFileAppender<ILoggingEvent> appender = new RollingFileAppender<>();
       appender.setContext(context);
       appender.setName(appenderName);
       String filePath = new File(logsDir, filenamePrefix + ".log").getAbsolutePath();
@@ -314,23 +394,23 @@ public class LogbackHelper {
    * Log files are rotated according to their size.
    * See http://logback.qos.ch/manual/appenders.html#FixedWindowRollingPolicy
    */
-  static class SizeRollingPolicy extends RollingPolicy {
+  private static class SizeRollingPolicy extends RollingPolicy {
     private final String size;
 
-    SizeRollingPolicy(Context context, String filenamePrefix, File logsDir, int maxFiles, String parameter) {
+    private SizeRollingPolicy(Context context, String filenamePrefix, File logsDir, int maxFiles, String parameter) {
       super(context, filenamePrefix, logsDir, maxFiles);
       this.size = parameter;
     }
 
     @Override
-    public FileAppender createAppender(String appenderName) {
-      RollingFileAppender appender = new RollingFileAppender();
+    public FileAppender<ILoggingEvent> createAppender(String appenderName) {
+      RollingFileAppender<ILoggingEvent> appender = new RollingFileAppender<>();
       appender.setContext(context);
       appender.setName(appenderName);
       String filePath = new File(logsDir, filenamePrefix + ".log").getAbsolutePath();
       appender.setFile(filePath);
 
-      SizeBasedTriggeringPolicy trigger = new SizeBasedTriggeringPolicy(size);
+      SizeBasedTriggeringPolicy<ILoggingEvent> trigger = new SizeBasedTriggeringPolicy<>(size);
       trigger.setContext(context);
       trigger.start();
       appender.setTriggeringPolicy(trigger);
index 389a4c4f395f18c57c7bd9e3028f6992694ab66e..3ffc86c64e9ce9c468d3cfddbcbc1a65db6af34b 100644 (file)
@@ -27,7 +27,6 @@ import ch.qos.logback.classic.spi.LoggerContextListener;
 import ch.qos.logback.core.Appender;
 import ch.qos.logback.core.ConsoleAppender;
 import ch.qos.logback.core.FileAppender;
-import ch.qos.logback.core.filter.Filter;
 import ch.qos.logback.core.rolling.FixedWindowRollingPolicy;
 import ch.qos.logback.core.rolling.RollingFileAppender;
 import ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy;
@@ -42,7 +41,6 @@ import org.junit.rules.TemporaryFolder;
 
 import static org.assertj.core.api.Assertions.assertThat;
 import static org.junit.Assert.fail;
-import static org.mockito.Mockito.mock;
 
 public class LogbackHelperTest {
 
@@ -91,15 +89,6 @@ public class LogbackHelperTest {
     assertThat(appender.getCopyOfAttachedFiltersList()).isEmpty();
   }
 
-  @Test
-  public void newConsoleAppender_with_filter() {
-    Filter filter = mock(Filter.class);
-    LoggerContext ctx = underTest.getRootContext();
-    ConsoleAppender<?> appender = underTest.newConsoleAppender(ctx, "MY_APPENDER", "%msg%n", filter);
-
-    assertThat(appender.getCopyOfAttachedFiltersList()).containsOnly(filter);
-  }
-
   @Test
   public void configureLogger() {
     Logger logger = underTest.configureLogger("my_logger", Level.WARN);
index 4667d67f051574b2bcd2fad75a879fbf3c29e6da..62c710e929aa4086180548c0a282b8e48d3e153c 100644 (file)
@@ -33,8 +33,14 @@ public class SearchLogging {
     LoggerContext ctx = helper.getRootContext();
     ctx.reset();
 
-    helper.configureRootLogger(ctx, props, newRootLoggerConfigBuilder().setProcessName("es").setFileName("es").build());
+    LogbackHelper.RootLoggerConfig config = newRootLoggerConfigBuilder().setProcessName("es").setFileNamePrefix("es").build();
+
+    String logPattern = helper.buildLogPattern(config);
+    helper.configureGlobalFileLog(props, config, logPattern);
+    helper.configureForSubprocessGobbler(props, logPattern);
+    helper.configureRootLogLevel(props);
 
     return ctx;
   }
+
 }
index ab229e74a761bc7ba4c4875ac8e7b05a2bac49f9..cd4533691b985218c3ca953ed20fc8957f8ad196 100644 (file)
@@ -73,7 +73,7 @@ public class SearchLoggingTest {
     LoggerContext ctx = underTest.configure(props);
 
     Logger root = ctx.getLogger(Logger.ROOT_LOGGER_NAME);
-    Appender<ILoggingEvent> appender = root.getAppender("file");
+    Appender<ILoggingEvent> appender = root.getAppender("file_es");
     assertThat(appender).isInstanceOf(FileAppender.class);
     FileAppender fileAppender = (FileAppender) appender;
     assertThat(fileAppender.getFile()).isEqualTo(new File(logDir, "es.log").getAbsolutePath());
index 28dc43956c26ca9eb47abbb598e95391c3a2204e..201878865dfd078e29c55f38a1b3a4e8149be4bb 100644 (file)
@@ -19,6 +19,7 @@
  */
 package org.sonar.ce.log;
 
+import org.sonar.process.Props;
 import org.sonar.server.app.ServerProcessLogging;
 
 /**
@@ -30,4 +31,8 @@ public class CeProcessLogging extends ServerProcessLogging {
     super("ce", "%X{ceTaskUuid}");
   }
 
+  @Override
+  protected void extendConfiguration(Props props) {
+    // no configuration extension to do
+  }
 }
index 72aea06c92a596ef6f69c29aefe25d67f407ec47..ec9f4e565d45b3301e9445d191adc0f326688856 100644 (file)
 package org.sonar.server.app;
 
 import ch.qos.logback.classic.LoggerContext;
-import java.util.logging.LogManager;
-import org.slf4j.bridge.SLF4JBridgeHandler;
-import org.sonar.api.utils.MessageException;
-import org.sonar.api.utils.log.LoggerLevel;
 import org.sonar.process.LogbackHelper;
 import org.sonar.process.Props;
 import org.sonar.server.platform.ServerLogging;
@@ -31,7 +27,6 @@ import org.sonar.server.platform.ServerLogging;
 import static org.sonar.process.LogbackHelper.RootLoggerConfig.newRootLoggerConfigBuilder;
 
 public abstract class ServerProcessLogging {
-  private static final String LOG_LEVEL_PROPERTY = "sonar.log.level";
   private final String processName;
   private final String threadIdFieldPattern;
   private final LogbackHelper helper = new LogbackHelper();
@@ -46,32 +41,28 @@ public abstract class ServerProcessLogging {
     ctx.reset();
 
     helper.enableJulChangePropagation(ctx);
-    helper.configureRootLogger(ctx, props,
-      newRootLoggerConfigBuilder()
-        .setProcessName(processName)
-        .setThreadIdFieldPattern(threadIdFieldPattern)
-        .setFileName(processName)
-        .build());
-    configureLevels(props);
+    configureRootLogger(props);
+
+    extendConfiguration(props);
 
-    // Configure java.util.logging, used by Tomcat, in order to forward to slf4j
-    LogManager.getLogManager().reset();
-    SLF4JBridgeHandler.install();
     return ctx;
   }
 
-  private void configureLevels(Props props) {
-    String levelCode = props.value(LOG_LEVEL_PROPERTY, "INFO");
-    LoggerLevel level;
-    if ("TRACE".equals(levelCode)) {
-      level = LoggerLevel.TRACE;
-    } else if ("DEBUG".equals(levelCode)) {
-      level = LoggerLevel.DEBUG;
-    } else if ("INFO".equals(levelCode)) {
-      level = LoggerLevel.INFO;
-    } else {
-      throw MessageException.of(String.format("Unsupported log level: %s. Please check property %s", levelCode, LOG_LEVEL_PROPERTY));
-    }
-    ServerLogging.configureLevels(helper, level);
+  protected abstract void extendConfiguration(Props props);
+
+  private void configureRootLogger(Props props) {
+    LogbackHelper.RootLoggerConfig config = newRootLoggerConfigBuilder()
+      .setProcessName(processName)
+      .setThreadIdFieldPattern(threadIdFieldPattern)
+      .setFileNamePrefix(processName)
+      .build();
+    String logPattern = helper.buildLogPattern(config);
+
+    helper.configureGlobalFileLog(props, config, logPattern);
+    helper.configureForSubprocessGobbler(props, logPattern);
+
+    helper.configureRootLogLevel(props);
+    ServerLogging.configureHardcodedLevels(helper);
   }
+
 }
index 511aba2c5e57f5858f2e5409024250ed204c3487..f10f249db8d96466a44ef097dd2bfa0b9cfd910e 100644 (file)
  */
 package org.sonar.server.app;
 
+import java.util.logging.LogManager;
+import org.slf4j.bridge.SLF4JBridgeHandler;
+import org.sonar.process.Props;
+
 /**
  * Configure logback for the Web Server process. Logs are written to file "web.log" in SQ's log directory.
  */
@@ -28,4 +32,10 @@ public class WebServerProcessLogging extends ServerProcessLogging {
     super("web", "%X{UID}");
   }
 
+  @Override
+  protected void extendConfiguration(Props props) {
+    // Configure java.util.logging, used by Tomcat, in order to forward to slf4j
+    LogManager.getLogManager().reset();
+    SLF4JBridgeHandler.install();
+  }
 }
index 2c15b75735f4c1aeb0558a81166f61e53bbeaa33..5fe0cbb7d3b89625515e76d213ddfe79b7993d23 100644 (file)
@@ -21,13 +21,11 @@ package org.sonar.server.platform;
 
 import ch.qos.logback.classic.Level;
 import ch.qos.logback.classic.Logger;
-import com.google.common.base.Preconditions;
-import com.google.common.collect.Sets;
+import com.google.common.annotations.VisibleForTesting;
 import java.io.File;
-import java.util.Set;
 import org.slf4j.LoggerFactory;
-import org.sonar.api.config.Settings;
 import org.sonar.api.ce.ComputeEngineSide;
+import org.sonar.api.config.Settings;
 import org.sonar.api.server.ServerSide;
 import org.sonar.api.utils.log.LoggerLevel;
 import org.sonar.api.utils.log.Loggers;
@@ -38,17 +36,23 @@ import org.sonar.process.ProcessProperties;
 @ComputeEngineSide
 public class ServerLogging {
 
-  public static final Set<LoggerLevel> ALLOWED_ROOT_LOG_LEVELS = Sets.immutableEnumSet(LoggerLevel.TRACE, LoggerLevel.DEBUG, LoggerLevel.INFO);
-
-  private final LogbackHelper helper = new LogbackHelper();
+  private final LogbackHelper helper;
   private final Settings settings;
 
   public ServerLogging(Settings settings) {
+    this(new LogbackHelper(), settings);
+  }
+
+  @VisibleForTesting
+  ServerLogging(LogbackHelper helper, Settings settings) {
+    this.helper = helper;
     this.settings = settings;
   }
 
   public void changeLevel(LoggerLevel level) {
-    configureLevels(helper, level);
+    Level logbackLevel = Level.toLevel(level.name());
+    helper.configureRootLogLevel(logbackLevel);
+    configureHardcodedLevels(helper);
     LoggerFactory.getLogger(ServerLogging.class).info("Level of logs changed to {}", level);
   }
 
@@ -56,9 +60,7 @@ public class ServerLogging {
     return Loggers.get(Logger.ROOT_LOGGER_NAME).getLevel();
   }
 
-  public static void configureLevels(LogbackHelper helper, LoggerLevel level) {
-    Preconditions.checkArgument(ALLOWED_ROOT_LOG_LEVELS.contains(level), "%s log level is not supported (allowed levels are %s)", level, ALLOWED_ROOT_LOG_LEVELS);
-    helper.configureLogger(Logger.ROOT_LOGGER_NAME, Level.toLevel(level.name()));
+  public static void configureHardcodedLevels(LogbackHelper helper) {
     helper.configureLogger("rails", Level.WARN);
     helper.configureLogger("org.apache.ibatis", Level.WARN);
     helper.configureLogger("java.sql", Level.WARN);
index 4948a15bfae0e6e1efb3468e159187486d04ddcc..e64eac0db8f4d01c789352f3546f36b828d62e4a 100644 (file)
@@ -28,6 +28,8 @@ import org.sonar.db.Database;
 import org.sonar.server.platform.ServerLogging;
 import org.sonar.server.user.UserSession;
 
+import static org.sonar.process.LogbackHelper.ALLOWED_ROOT_LOG_LEVELS;
+
 public class ChangeLogLevelAction implements SystemWsAction {
 
   private static final String PARAM_LEVEL = "level";
@@ -55,7 +57,7 @@ public class ChangeLogLevelAction implements SystemWsAction {
 
     newAction.createParam(PARAM_LEVEL)
       .setDescription("The new level. Be cautious: DEBUG, and even more TRACE, may have performance impacts.")
-      .setPossibleValues(ServerLogging.ALLOWED_ROOT_LOG_LEVELS)
+      .setPossibleValues(ALLOWED_ROOT_LOG_LEVELS)
       .setRequired(true);
   }
 
index b2e39b3e5d869fdf637af196fe05db0526de3b35..6b2dbfd704d12a084982290d243ddb037bd53273 100644 (file)
@@ -77,7 +77,7 @@ public class CeProcessLoggingTest {
     LoggerContext ctx = underTest.configure(props);
 
     Logger root = ctx.getLogger(Logger.ROOT_LOGGER_NAME);
-    Appender<ILoggingEvent> appender = root.getAppender("file");
+    Appender<ILoggingEvent> appender = root.getAppender("file_ce");
     assertThat(appender).isInstanceOf(FileAppender.class);
     FileAppender fileAppender = (FileAppender) appender;
     assertThat(fileAppender.getFile()).isEqualTo(new File(logDir, "ce.log").getAbsolutePath());
index 170ea8b6c119464b1d7eed1bc2c0d748b44a3d80..0ab5bc9671528709ebab6907700c85a245eb0a8c 100644 (file)
@@ -77,7 +77,7 @@ public class WebServerProcessLoggingTest {
     LoggerContext ctx = underTest.configure(props);
 
     Logger root = ctx.getLogger(Logger.ROOT_LOGGER_NAME);
-    Appender<ILoggingEvent> appender = root.getAppender("file");
+    Appender<ILoggingEvent> appender = root.getAppender("file_web");
     assertThat(appender).isInstanceOf(FileAppender.class);
     FileAppender fileAppender = (FileAppender) appender;
     assertThat(fileAppender.getFile()).isEqualTo(new File(logDir, "web.log").getAbsolutePath());
index d31ce54dfc88bf937d7e069b8699d2766ae46483..c3b6f9b8d68045bf819289f82e7a7220a95d26d0 100644 (file)
@@ -20,7 +20,6 @@
 package org.sonar.server.platform;
 
 import ch.qos.logback.classic.Level;
-import ch.qos.logback.classic.Logger;
 import java.io.File;
 import java.io.IOException;
 import org.apache.commons.io.FileUtils;
@@ -28,8 +27,8 @@ import org.junit.Rule;
 import org.junit.Test;
 import org.junit.rules.ExpectedException;
 import org.junit.rules.TemporaryFolder;
-import org.sonar.api.config.Settings;
 import org.sonar.api.config.MapSettings;
+import org.sonar.api.config.Settings;
 import org.sonar.api.utils.log.LogTester;
 import org.sonar.api.utils.log.LoggerLevel;
 import org.sonar.process.LogbackHelper;
@@ -37,18 +36,19 @@ import org.sonar.process.ProcessProperties;
 
 import static org.assertj.core.api.Assertions.assertThat;
 import static org.mockito.Mockito.mock;
+import static org.mockito.Mockito.spy;
 import static org.mockito.Mockito.verify;
 
 public class ServerLoggingTest {
 
   @Rule
   public TemporaryFolder temp = new TemporaryFolder();
-
   @Rule
   public ExpectedException expectedException = ExpectedException.none();
 
-  Settings settings = new MapSettings();
-  ServerLogging underTest = new ServerLogging(settings);
+  private LogbackHelper logbackHelper = spy(new LogbackHelper());
+  private Settings settings = new MapSettings();
+  private ServerLogging underTest = new ServerLogging(logbackHelper, settings);
 
   @Rule
   public LogTester logTester = new LogTester();
@@ -78,20 +78,66 @@ public class ServerLoggingTest {
   }
 
   @Test
-  public void configureLevels() {
+  public void configureHardcodedLevels() {
     LogbackHelper logbackHelper = mock(LogbackHelper.class);
-    ServerLogging.configureLevels(logbackHelper, LoggerLevel.TRACE);
+    ServerLogging.configureHardcodedLevels(logbackHelper);
 
-    verify(logbackHelper).configureLogger(Logger.ROOT_LOGGER_NAME, Level.TRACE);
-    verify(logbackHelper).configureLogger("java.sql", Level.WARN);
+    verifyHardcodedLevels(logbackHelper);
   }
 
   @Test
-  public void configureLevels_unsupported_level() {
+  public void changeLevel_throws_IAE_if_level_is_WARN() {
     expectedException.expect(IllegalArgumentException.class);
-    expectedException.expectMessage("ERROR log level is not supported (allowed levels are [TRACE, DEBUG, INFO])");
+    expectedException.expectMessage("WARN log level is not supported (allowed levels are [");
 
-    LogbackHelper logbackHelper = mock(LogbackHelper.class);
-    ServerLogging.configureLevels(logbackHelper, LoggerLevel.ERROR);
+    underTest.changeLevel(LoggerLevel.WARN);
+  }
+
+  @Test
+  public void changeLevel_throws_IAE_if_level_is_ERROR() {
+    expectedException.expect(IllegalArgumentException.class);
+    expectedException.expectMessage("ERROR log level is not supported (allowed levels are [");
+
+    underTest.changeLevel(LoggerLevel.ERROR);
+  }
+
+  @Test
+  public void changeLevel_changes_root_logger_level_to_INFO() {
+    underTest.changeLevel(LoggerLevel.INFO);
+
+    verify(logbackHelper).configureRootLogLevel(Level.INFO);
+    verifyHardcodedLevels(logbackHelper);
+  }
+
+  @Test
+  public void changeLevel_changes_root_logger_level_to_DEBUG() {
+    underTest.changeLevel(LoggerLevel.DEBUG);
+
+    verify(logbackHelper).configureRootLogLevel(Level.DEBUG);
+    verifyHardcodedLevels(logbackHelper);
+  }
+
+  @Test
+  public void changeLevel_changes_root_logger_level_to_TRACE() {
+    underTest.changeLevel(LoggerLevel.TRACE);
+
+    verify(logbackHelper).configureRootLogLevel(Level.TRACE);
+    verifyHardcodedLevels(logbackHelper);
+  }
+
+  private void verifyHardcodedLevels(LogbackHelper logbackHelper) {
+    verify(logbackHelper).configureLogger("rails", Level.WARN);
+    verify(logbackHelper).configureLogger("org.apache.ibatis", Level.WARN);
+    verify(logbackHelper).configureLogger("java.sql", Level.WARN);
+    verify(logbackHelper).configureLogger("java.sql.ResultSet", Level.WARN);
+    verify(logbackHelper).configureLogger("org.sonar.MEASURE_FILTER", Level.WARN);
+    verify(logbackHelper).configureLogger("org.elasticsearch", Level.INFO);
+    verify(logbackHelper).configureLogger("org.elasticsearch.node", Level.INFO);
+    verify(logbackHelper).configureLogger("org.elasticsearch.http", Level.INFO);
+    verify(logbackHelper).configureLogger("ch.qos.logback", Level.WARN);
+    verify(logbackHelper).configureLogger("org.apache.catalina", Level.INFO);
+    verify(logbackHelper).configureLogger("org.apache.coyote", Level.INFO);
+    verify(logbackHelper).configureLogger("org.apache.jasper", Level.INFO);
+    verify(logbackHelper).configureLogger("org.apache.tomcat", Level.INFO);
   }
 }
index bf4704c5f1545019c4c1862ed641d5c4b54a5d3b..30b2567c72f6fd97ce73c477ffba6d0f5a4e9ecb 100644 (file)
@@ -12,7 +12,8 @@ wrapper.java.command=java
 #********************************************************************
 # Wrapper Java
 #********************************************************************
-wrapper.java.additional.1=-Djava.awt.headless=true
+wrapper.java.additional.1=-Dsonar.wrapped=true
+wrapper.java.additional.2=-Djava.awt.headless=true
 wrapper.java.mainclass=org.tanukisoftware.wrapper.WrapperSimpleApp
 wrapper.java.classpath.1=../../lib/jsw/*.jar
 wrapper.java.classpath.2=../../lib/*.jar
index 4395f19e7faf8b70a594338988f060c49be0761a..7ec122f95ce636c059c4c667d83bbedb432b4c9f 100644 (file)
  */
 package org.sonar.application;
 
-import ch.qos.logback.classic.Level;
 import ch.qos.logback.classic.Logger;
 import ch.qos.logback.classic.LoggerContext;
-import ch.qos.logback.classic.encoder.PatternLayoutEncoder;
 import ch.qos.logback.classic.spi.ILoggingEvent;
-import ch.qos.logback.core.Appender;
 import ch.qos.logback.core.ConsoleAppender;
 import ch.qos.logback.core.FileAppender;
-import org.slf4j.LoggerFactory;
 import org.sonar.process.LogbackHelper;
 import org.sonar.process.Props;
 
+import static org.slf4j.Logger.ROOT_LOGGER_NAME;
+import static org.sonar.process.LogbackHelper.RootLoggerConfig.newRootLoggerConfigBuilder;
 import static org.sonar.process.monitor.StreamGobbler.LOGGER_GOBBLER;
 
 /**
- * Configure logback for the master process
+ * Configure logback for the APP process.
+ *
+ * <p>
+ * SonarQube's logging use cases:
+ * <ol>
+ *   <li>
+ *     SQ started as a background process (with {@code sonar.sh start}):
+ *     <ul>
+ *       <li>
+ *         logs produced by the JVM before logback is setup in the APP JVM or which can't be caught by logback
+ *         (such as JVM crash) must be written to sonar.log
+ *       </li>
+ *       <li>
+ *         logs produced by the sub process JVMs before logback is setup in the subprocess JVMs or which can't be caught
+ *         by logback (such as JVM crash) must be written to sonar.log
+ *       </li>
+ *       <li>each JVM writes its own logs into its dedicated file</li>
+ *     </ul>
+ *   </li>
+ *   <li>
+ *     SQ started in console with wrapper (ie. with {@code sonar.sh console}):
+ *     <ul>
+ *       <li>
+ *         logs produced by the APP JVM before logback is setup in the APP JVM or which can't be caught by logback
+ *         (such as JVM crash) must be written to sonar.log
+ *       </li>
+ *       <li>
+ *         logs produced by the sub process JVMs before logback is setup in the subprocess JVMs or which can't be caught
+ *         by logback (such as JVM crash) must be written to sonar.log
+ *       </li>
+ *       <li>each JVM writes its own logs into its dedicated file</li>
+ *       <li>APP JVM logs are written to the APP JVM {@code System.out}</li>
+ *     </ul>
+ *   </li>
+ *   <li>
+ *     SQ started from command line (ie. {@code java -jar sonar-application-X.Y.jar}):
+ *     <ul>
+ *       <li>
+ *         logs produced by the APP JVM before logback is setup in the APP JVM or which can't be caught by logback
+ *         (such as JVM crash) are the responsibility of the user to be dealt with
+ *       </li>
+ *       <li>
+ *         logs produced by the sub process JVMs before logback is setup in the subprocess JVMs or which can't be caught
+ *         by logback (such as JVM crash) must be written to APP's {@code System.out}
+ *       </li>
+ *       <li>each JVM writes its own logs into its dedicated file</li>
+ *       <li>APP JVM logs are written to the APP JVM {@code System.out}</li>
+ *     </ul>
+ *   </li>
+ *   <li>
+ *     SQ started from an IT (ie. from command line with {@code option -Dsonar.log.console=true}):
+ *     <ul>
+ *       <li>
+ *         logs produced by the APP JVM before logback is setup in the APP JVM or which can't be caught by logback
+ *         (such as JVM crash) are the responsibility of the developer or maven to be dealt with
+ *       </li>
+ *       <li>
+ *         logs produced by the sub process JVMs before logback is setup in the subprocess JVMs or which can't be caught
+ *         by logback (such as JVM crash) must be written to APP's {@code System.out} and are the responsibility of the
+ *         developer or maven to be dealt with
+ *       </li>
+ *       <li>each JVM writes its own logs into its dedicated file</li>
+ *       <li>logs of all 4 JVMs are also written to the APP JVM {@code System.out}</li>
+ *     </ul>
+ *   </li>
+ * </ol>
+ * </p>
+ *
  */
 class AppLogging {
 
-  static final String CONSOLE_LOGGER = "console";
-  static final String CONSOLE_APPENDER = "CONSOLE";
-  static final String GOBBLER_APPENDER = "GOBBLER";
-  static final String APP_PATTERN = "%d{yyyy.MM.dd HH:mm:ss} %-5level app[][%logger{20}] %msg%n";
+  private static final String CONSOLE_LOGGER = "console";
+  private static final String CONSOLE_PLAIN_APPENDER = "CONSOLE";
+  private static final String APP_CONSOLE_APPENDER = "APP_CONSOLE";
+  private static final String GOBBLER_PLAIN_CONSOLE = "GOBBLER_CONSOLE";
+  private static final LogbackHelper.RootLoggerConfig APP_ROOT_LOGGER_CONFIG = newRootLoggerConfigBuilder()
+    .setProcessName("app")
+    .setFileNamePrefix("sonar")
+    .build();
 
   private final LogbackHelper helper = new LogbackHelper();
 
   LoggerContext configure(Props props) {
     LoggerContext ctx = helper.getRootContext();
     ctx.reset();
+
     helper.enableJulChangePropagation(ctx);
+
     configureConsole(ctx);
-    configureGobbler(props, ctx);
-    configureRoot(props, ctx);
-    if (props.valueAsBoolean("sonar.log.console", false)) {
-      // used by SonarSource testing environment
-      copyGobblerToConsole();
+    if (helper.isAllLogsToConsoleEnabled(props) || !props.valueAsBoolean("sonar.wrapped", false)) {
+      configureWithLogbackWritingToFile(props, ctx);
+    } else {
+      configureWithWrapperWritingToFile(ctx);
     }
+    helper.configureRootLogLevel(props, "sonar.app.log.level");
+
     return ctx;
   }
 
   /**
-   * Enable the copy in console of the logs written in logs/sonar.log
+   * Creates a non additive logger dedicated to printing message as is (ie. assuming they are already formatted).
+   *
+   * It creates a dedicated appender to the System.out which applies no formatting the logs it receives.
    */
-  private static void copyGobblerToConsole() {
-    Logger consoleLogger = (Logger) LoggerFactory.getLogger(CONSOLE_LOGGER);
-    Appender<ILoggingEvent> consoleAppender = consoleLogger.getAppender(CONSOLE_APPENDER);
-
-    Logger gobblerLogger = (Logger) LoggerFactory.getLogger(LOGGER_GOBBLER);
-    gobblerLogger.addAppender(consoleAppender);
-  }
-
   private void configureConsole(LoggerContext loggerContext) {
-    ConsoleAppender<ILoggingEvent> consoleAppender = helper.newConsoleAppender(loggerContext, CONSOLE_APPENDER, "%msg%n");
+    ConsoleAppender<ILoggingEvent> consoleAppender = helper.newConsoleAppender(loggerContext, CONSOLE_PLAIN_APPENDER, "%msg%n");
+
     Logger consoleLogger = loggerContext.getLogger(CONSOLE_LOGGER);
     consoleLogger.setAdditive(false);
     consoleLogger.addAppender(consoleAppender);
   }
 
-  private void configureGobbler(Props props, LoggerContext ctx) {
-    // configure appender
-    LogbackHelper.RollingPolicy rollingPolicy = helper.createRollingPolicy(ctx, props, "sonar");
-    FileAppender<ILoggingEvent> fileAppender = rollingPolicy.createAppender(GOBBLER_APPENDER);
-    fileAppender.setContext(ctx);
-    PatternLayoutEncoder fileEncoder = new PatternLayoutEncoder();
-    fileEncoder.setContext(ctx);
-    fileEncoder.setPattern("%msg%n");
-    fileEncoder.start();
-    fileAppender.setEncoder(fileEncoder);
-    fileAppender.start();
-
-    // configure logger
+  /**
+   * The process has been started by orchestrator (ie. via {@code java -jar} and optionally passing the option {@code -Dsonar.log.console=true}).
+   * Therefor, APP's System.out (and System.err) are <strong>not</strong> copied to sonar.log by the wrapper and
+   * printing to sonar.log must be done at logback level.
+   */
+  private void configureWithLogbackWritingToFile(Props props, LoggerContext ctx) {
+    // configure all logs (ie. root logger) to be written to sonar.log and also to the console with formatting
+    // in practice, this will be only APP's own logs as logs from sub processes LOGGER_GOBBLER and LOGGER_GOBBLER
+    // is configured below to be detached from root
+    // so, this will make all APP's log to be both written to sonar.log and visible in the console
+    configureRootWithLogbackWritingToFile(props, ctx);
+
+    // if option -Dsonar.log.console=true has been set, sub processes will write their logs to their own files but also
+    // copy them to their System.out.
+    // otherwise, the only logs to be expected in LOGGER_GOBBLER are those before logback is setup in subprocesses or
+    // when their JVM crashes
+    // they must be printed to App's System.out as is (as they are already formatted)
+    // logger is configured to be non additive as we don't want these logs to be written to sonar.log and duplicated in
+    // the console (with an incorrect formatting)
+    configureGobbler(ctx);
+  }
+
+  /**
+   * SQ has been started by the wrapper (ie. with sonar.sh) therefor, APP's System.out (and System.err) are written to
+   * sonar.log by the wrapper.
+   */
+  private void configureWithWrapperWritingToFile(LoggerContext ctx) {
+    // configure all logs (ie. root logger) to be written to console with formatting
+    // in practice, this will be only APP's own logs as logs from sub processes are written to LOGGER_GOBBLER and
+    // LOGGER_GOBBLER is configured below to be detached from root
+    // logs are written to the console because we want them to be in sonar.log and the wrapper will write any log
+    // from APP's System.out and System.err to sonar.log
+    Logger rootLogger = ctx.getLogger(ROOT_LOGGER_NAME);
+    rootLogger.addAppender(createAppConsoleAppender(ctx, helper.buildLogPattern(APP_ROOT_LOGGER_CONFIG)));
+
+    // in regular configuration, sub processes are not copying their logs to their System.out, so, the only logs to be
+    // expected in LOGGER_GOBBLER are those before logback is setup in subprocesses or when JVM crashes
+    // so, they must be printed to App's System.out as is (as they are already formatted) and the wrapper will write
+    // them to sonar.log
+    // logger is configured to be non additive as we don't want these logs written to sonar.log and duplicated in the
+    // console with an incorrect formatting
+    configureGobbler(ctx);
+  }
+
+  private void configureRootWithLogbackWritingToFile(Props props, LoggerContext ctx) {
+    Logger rootLogger = ctx.getLogger(ROOT_LOGGER_NAME);
+    String appLogPattern = helper.buildLogPattern(APP_ROOT_LOGGER_CONFIG);
+    FileAppender<ILoggingEvent> fileAppender = helper.newFileAppender(ctx, props, APP_ROOT_LOGGER_CONFIG, appLogPattern);
+    rootLogger.addAppender(fileAppender);
+    rootLogger.addAppender(createAppConsoleAppender(ctx, appLogPattern));
+  }
+
+  /**
+   * Configure the logger to which logs from sub processes are written to
+   * (called {@link org.sonar.process.monitor.StreamGobbler#LOGGER_GOBBLER}) by {@link org.sonar.process.monitor.StreamGobbler},
+   * to be:
+   * <ol>
+   *   <li>non additive (ie. these logs will be output by the appender of {@link org.sonar.process.monitor.StreamGobbler#LOGGER_GOBBLER} and only this one)</li>
+   *   <li>write logs as is (ie. without any extra formatting)</li>
+   *   <li>write exclusively to App's System.out</li>
+   * </ol>
+   */
+  private void configureGobbler(LoggerContext ctx) {
     Logger gobblerLogger = ctx.getLogger(LOGGER_GOBBLER);
     gobblerLogger.setAdditive(false);
-    gobblerLogger.addAppender(fileAppender);
+    gobblerLogger.addAppender(helper.newConsoleAppender(ctx, GOBBLER_PLAIN_CONSOLE, "%msg%n"));
   }
 
-  private void configureRoot(Props props, LoggerContext loggerContext) {
-    ConsoleAppender<ILoggingEvent> consoleAppender = helper.newConsoleAppender(loggerContext, "ROOT_CONSOLE", APP_PATTERN);
-    Logger rootLogger = loggerContext.getLogger(Logger.ROOT_LOGGER_NAME);
-    rootLogger.setLevel(Level.toLevel(props.value("sonar.app.log.level", Level.INFO.toString()), Level.INFO));
-    rootLogger.addAppender(consoleAppender);
+  private ConsoleAppender<ILoggingEvent> createAppConsoleAppender(LoggerContext ctx, String appLogPattern) {
+    return helper.newConsoleAppender(ctx, APP_CONSOLE_APPENDER, appLogPattern);
   }
+
 }
index 4465bcb0664c8381903d5418349cbcf4d8c9670a..0fccc6e11c787c18abc73809acc020f52042ecd1 100644 (file)
@@ -22,11 +22,16 @@ package org.sonar.application;
 import ch.qos.logback.classic.Level;
 import ch.qos.logback.classic.Logger;
 import ch.qos.logback.classic.LoggerContext;
+import ch.qos.logback.classic.encoder.PatternLayoutEncoder;
 import ch.qos.logback.classic.spi.ILoggingEvent;
 import ch.qos.logback.core.Appender;
+import ch.qos.logback.core.ConsoleAppender;
 import ch.qos.logback.core.FileAppender;
+import ch.qos.logback.core.encoder.Encoder;
+import ch.qos.logback.core.joran.spi.ConsoleTarget;
 import ch.qos.logback.core.rolling.RollingFileAppender;
 import java.io.File;
+import java.util.Iterator;
 import java.util.Properties;
 import org.junit.AfterClass;
 import org.junit.Before;
@@ -38,6 +43,7 @@ import org.sonar.process.ProcessProperties;
 import org.sonar.process.Props;
 
 import static org.assertj.core.api.Assertions.assertThat;
+import static org.slf4j.Logger.ROOT_LOGGER_NAME;
 import static org.sonar.process.monitor.StreamGobbler.LOGGER_GOBBLER;
 
 public class AppLoggingTest {
@@ -62,43 +68,111 @@ public class AppLoggingTest {
   }
 
   @Test
-  public void configure_defaults() {
+  public void no_writing_to_sonar_log_file_when_running_from_sonar_script() {
+    emulateRunFromSonarScript();
+
     LoggerContext ctx = underTest.configure(props);
 
-    Logger gobbler = ctx.getLogger(LOGGER_GOBBLER);
-    Appender<ILoggingEvent> appender = gobbler.getAppender(AppLogging.GOBBLER_APPENDER);
-    assertThat(appender).isInstanceOf(RollingFileAppender.class);
+    ctx.getLoggerList().forEach(AppLoggingTest::verifyNoFileAppender);
+  }
+
+  @Test
+  public void root_logger_only_writes_to_console_with_formatting_when_running_from_sonar_script() {
+    emulateRunFromSonarScript();
 
-    // gobbler is not copied to console
-    assertThat(gobbler.getAppender(AppLogging.GOBBLER_APPENDER)).isNotNull();
-    assertThat(gobbler.getAppender(AppLogging.CONSOLE_APPENDER)).isNull();
+    LoggerContext ctx = underTest.configure(props);
+
+    Logger rootLogger = ctx.getLogger(ROOT_LOGGER_NAME);
+    ConsoleAppender<ILoggingEvent> consoleAppender = (ConsoleAppender<ILoggingEvent>) rootLogger.getAppender("APP_CONSOLE");
+    verifyAppFormattedLogEncoder(consoleAppender.getEncoder());
+    assertThat(rootLogger.iteratorForAppenders()).hasSize(1);
   }
 
   @Test
-  public void configure_no_rotation() {
-    props.set("sonar.log.rollingPolicy", "none");
+  public void gobbler_logger_writes_to_console_without_formatting_when_running_from_sonar_script() {
+    emulateRunFromSonarScript();
+
+    LoggerContext ctx = underTest.configure(props);
+
+    Logger gobblerLogger = ctx.getLogger(LOGGER_GOBBLER);
+    verifyGobblerConsoleAppender(gobblerLogger);
+    assertThat(gobblerLogger.iteratorForAppenders()).hasSize(1);
+  }
+
+  @Test
+  public void root_logger_writes_to_console_with_formatting_and_to_sonar_log_file_when_running_from_command_line() {
+    emulateRunFromCommandLine(false);
 
     LoggerContext ctx = underTest.configure(props);
 
-    Logger gobbler = ctx.getLogger(LOGGER_GOBBLER);
-    Appender<ILoggingEvent> appender = gobbler.getAppender(AppLogging.GOBBLER_APPENDER);
-    assertThat(appender).isNotInstanceOf(RollingFileAppender.class).isInstanceOf(FileAppender.class);
+    Logger rootLogger = ctx.getLogger(ROOT_LOGGER_NAME);
+    verifyAppConsoleAppender(rootLogger.getAppender("APP_CONSOLE"));
+    verifySonarLogFileAppender(rootLogger.getAppender("file_sonar"));
+    assertThat(rootLogger.iteratorForAppenders()).hasSize(2);
+
+    // verify no other logger writes to sonar.log
+    ctx.getLoggerList()
+      .stream()
+      .filter(logger -> !ROOT_LOGGER_NAME.equals(logger.getName()))
+      .forEach(AppLoggingTest::verifyNoFileAppender);
   }
 
   @Test
-  public void copyGobblerToConsole() {
-    props.set("sonar.log.console", "true");
+  public void gobbler_logger_writes_to_console_without_formatting_when_running_from_command_line() {
+    emulateRunFromCommandLine(false);
 
     LoggerContext ctx = underTest.configure(props);
-    Logger gobbler = ctx.getLogger(LOGGER_GOBBLER);
-    assertThat(gobbler.getAppender(AppLogging.GOBBLER_APPENDER)).isNotNull();
-    assertThat(gobbler.getAppender(AppLogging.CONSOLE_APPENDER)).isNotNull();
+
+    Logger gobblerLogger = ctx.getLogger(LOGGER_GOBBLER);
+    verifyGobblerConsoleAppender(gobblerLogger);
+    assertThat(gobblerLogger.iteratorForAppenders()).hasSize(1);
+  }
+
+  @Test
+  public void root_logger_writes_to_console_with_formatting_and_to_sonar_log_file_when_running_from_ITs() {
+    emulateRunFromCommandLine(true);
+
+    LoggerContext ctx = underTest.configure(props);
+
+    Logger rootLogger = ctx.getLogger(ROOT_LOGGER_NAME);
+    verifyAppConsoleAppender(rootLogger.getAppender("APP_CONSOLE"));
+    verifySonarLogFileAppender(rootLogger.getAppender("file_sonar"));
+    assertThat(rootLogger.iteratorForAppenders()).hasSize(2);
+
+    ctx.getLoggerList()
+      .stream()
+      .filter(logger -> !ROOT_LOGGER_NAME.equals(logger.getName()))
+      .forEach(AppLoggingTest::verifyNoFileAppender);
+  }
+
+  @Test
+  public void gobbler_logger_writes_to_console_without_formatting_when_running_from_ITs() {
+    emulateRunFromCommandLine(true);
+
+    LoggerContext ctx = underTest.configure(props);
+
+    Logger gobblerLogger = ctx.getLogger(LOGGER_GOBBLER);
+    verifyGobblerConsoleAppender(gobblerLogger);
+    assertThat(gobblerLogger.iteratorForAppenders()).hasSize(1);
+  }
+
+  @Test
+  public void configure_no_rotation_on_sonar_file() {
+    props.set("sonar.log.rollingPolicy", "none");
+
+    LoggerContext ctx = underTest.configure(props);
+
+    Logger rootLogger = ctx.getLogger(ROOT_LOGGER_NAME);
+    Appender<ILoggingEvent> appender = rootLogger.getAppender("file_sonar");
+    assertThat(appender)
+      .isNotInstanceOf(RollingFileAppender.class)
+      .isInstanceOf(FileAppender.class);
   }
 
   @Test
   public void default_level_for_root_logger_is_INFO() {
     LoggerContext ctx = underTest.configure(props);
-    Logger rootLogger = ctx.getLogger(Logger.ROOT_LOGGER_NAME);
+    Logger rootLogger = ctx.getLogger(ROOT_LOGGER_NAME);
     assertThat(rootLogger.getLevel()).isEqualTo(Level.INFO);
   }
 
@@ -107,7 +181,7 @@ public class AppLoggingTest {
     props.set("sonar.app.log.level", "TRACE");
 
     LoggerContext ctx = underTest.configure(props);
-    Logger rootLogger = ctx.getLogger(Logger.ROOT_LOGGER_NAME);
+    Logger rootLogger = ctx.getLogger(ROOT_LOGGER_NAME);
     assertThat(rootLogger.getLevel()).isEqualTo(Level.TRACE);
   }
 
@@ -116,7 +190,7 @@ public class AppLoggingTest {
     props.set("sonar.app.log.level", "trace");
 
     LoggerContext ctx = underTest.configure(props);
-    Logger rootLogger = ctx.getLogger(Logger.ROOT_LOGGER_NAME);
+    Logger rootLogger = ctx.getLogger(ROOT_LOGGER_NAME);
     assertThat(rootLogger.getLevel()).isEqualTo(Level.TRACE);
   }
 
@@ -125,7 +199,56 @@ public class AppLoggingTest {
     props.set("sonar.app.log.level", "DodoDouh!");
 
     LoggerContext ctx = underTest.configure(props);
-    Logger rootLogger = ctx.getLogger(Logger.ROOT_LOGGER_NAME);
+    Logger rootLogger = ctx.getLogger(ROOT_LOGGER_NAME);
     assertThat(rootLogger.getLevel()).isEqualTo(Level.INFO);
   }
+
+  private void emulateRunFromSonarScript() {
+    props.set("sonar.wrapped", "true");
+  }
+
+  private void emulateRunFromCommandLine(boolean withAllLogsPrintedToConsole) {
+    if (withAllLogsPrintedToConsole) {
+      props.set("sonar.log.console", "true");
+    }
+  }
+
+  private static void verifyNoFileAppender(Logger logger) {
+    Iterator<Appender<ILoggingEvent>> iterator = logger.iteratorForAppenders();
+    while (iterator.hasNext()) {
+      assertThat(iterator.next()).isNotInstanceOf(FileAppender.class);
+    }
+  }
+
+  private void verifySonarLogFileAppender(Appender<ILoggingEvent> appender) {
+    assertThat(appender).isInstanceOf(FileAppender.class);
+    FileAppender fileAppender = (FileAppender) appender;
+    assertThat(fileAppender.getFile()).isEqualTo(new File(logDir, "sonar.log").getAbsolutePath());
+    verifyAppFormattedLogEncoder(fileAppender.getEncoder());
+  }
+
+  private void verifyAppConsoleAppender(Appender<ILoggingEvent> appender) {
+    assertThat(appender).isInstanceOf(ConsoleAppender.class);
+    ConsoleAppender<ILoggingEvent> consoleAppender = (ConsoleAppender<ILoggingEvent>) appender;
+    assertThat(consoleAppender.getTarget()).isEqualTo(ConsoleTarget.SystemOut.getName());
+    verifyAppFormattedLogEncoder(consoleAppender.getEncoder());
+  }
+
+  private void verifyAppFormattedLogEncoder(Encoder<ILoggingEvent> encoder) {
+    verifyFormattedLogEncoder(encoder, "%d{yyyy.MM.dd HH:mm:ss} %-5level app[][%logger{20}] %msg%n");
+  }
+
+  private void verifyGobblerConsoleAppender(Logger logger) {
+    Appender<ILoggingEvent> appender = logger.getAppender("GOBBLER_CONSOLE");
+    assertThat(appender).isInstanceOf(ConsoleAppender.class);
+    ConsoleAppender<ILoggingEvent> consoleAppender = (ConsoleAppender<ILoggingEvent>) appender;
+    assertThat(consoleAppender.getTarget()).isEqualTo(ConsoleTarget.SystemOut.getName());
+    verifyFormattedLogEncoder(consoleAppender.getEncoder(), "%msg%n");
+  }
+
+  private void verifyFormattedLogEncoder(Encoder<ILoggingEvent> encoder, String logPattern) {
+    assertThat(encoder).isInstanceOf(PatternLayoutEncoder.class);
+    PatternLayoutEncoder patternEncoder = (PatternLayoutEncoder) encoder;
+    assertThat(patternEncoder.getPattern()).isEqualTo(logPattern);
+  }
 }