SONAR-2719 add timestamp to maven logs

10 files changed, 152 insertions, 104 deletions

diff --git a/sonar-batch/src/main/resources/org/sonar/batch/logback-base.xml b/sonar-batch/src/main/resources/org/sonar/batch/logback-base.xml
new file mode 100644
index 00000000000..618c62a74d5
--- /dev/null
+++ b/sonar-batch/src/main/resources/org/sonar/batch/logback-base.xml
@@ -0,0 +1,33 @@
+<included>
+  <logger name="org.hibernate">
+    <level value="WARN"/>
+  </logger>
+
+  <!-- set DEBUG to activate SQL logs. NOT RECOMMENDED  -->
+  <logger name="org.hibernate.SQL">
+    <level value="ERROR"/>
+  </logger>
+
+  <!-- set INFO to activate SQL statistics. NOT RECOMMENDED  -->
+  <logger name="org.sonar.DBSTATISTICS">
+    <level value="ERROR"/>
+  </logger>
+
+  <logger name="net.sf.ehcache">
+    <level value="WARN"/>
+  </logger>
+
+  <logger name="org.hibernate.cache.ReadWriteCache">
+    <!-- removing "An item was expired by the cache while it was locked (increase your cache timeout)" msg -->
+    <level value="ERROR"/>
+  </logger>
+  <logger name="org.hibernate.cache.EhCacheProvider">
+    <!-- removing "org.hibernate.cache.EhCacheProvider - Could not find configuratio)" message -->
+    <level value="ERROR"/>
+  </logger>
+
+  <root>
+    <level value="${ROOT_LOGGER_LEVEL}"/>
+    <appender-ref ref="STDOUT"/>
+  </root>
+</included>
\ No newline at end of file
diff --git a/sonar-batch/src/main/resources/org/sonar/batch/logback.xml b/sonar-batch/src/main/resources/org/sonar/batch/logback.xml
index 91b34037ace..2e65d27a617 100644
--- a/sonar-batch/src/main/resources/org/sonar/batch/logback.xml
+++ b/sonar-batch/src/main/resources/org/sonar/batch/logback.xml
@@ -1,11 +1,16 @@
 <?xml version="1.0" encoding="UTF-8" ?>
-
 <configuration debug="false">
 
+  <!--
+  This file is directly loaded by Sonar Ant Task 1.1 and Sonar Runner 1.1.
+  Inclusion of logback-base.xml is not supported by these 2 versions, so loggers must
+  be duplicated.
+  -->
+
   <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
-    <layout class="ch.qos.logback.classic.PatternLayout">
-      <pattern>[%level] %X{module} %msg%n</pattern>
-    </layout>
+    <encoder>
+      <pattern>%d{HH:mm:ss.SSS} %-5level %msg%n</pattern>
+    </encoder>
   </appender>
 
   <logger name="org.hibernate">
@@ -35,10 +40,9 @@
     <level value="ERROR"/>
   </logger>
 
-  <!-- see org.sonar.mojo.InternalMojo#initLogging -->
   <root>
     <level value="${ROOT_LOGGER_LEVEL}"/>
     <appender-ref ref="STDOUT"/>
   </root>
-
+  
 </configuration>
\ No newline at end of file
diff --git a/sonar-core/pom.xml b/sonar-core/pom.xml
index 270de36a396..302e57dfe68 100644
--- a/sonar-core/pom.xml
+++ b/sonar-core/pom.xml
@@ -70,6 +70,28 @@
       <artifactId>commons-dbcp</artifactId>
     </dependency>
 
+    <!-- logging -->
+    <dependency>
+      <groupId>org.slf4j</groupId>
+      <artifactId>slf4j-api</artifactId>
+    </dependency>
+    <dependency>
+      <groupId>ch.qos.logback</groupId>
+      <artifactId>logback-classic</artifactId>
+    </dependency>
+    <dependency>
+      <groupId>ch.qos.logback</groupId>
+      <artifactId>logback-core</artifactId>
+    </dependency>
+    <dependency>
+      <groupId>org.slf4j</groupId>
+      <artifactId>jcl-over-slf4j</artifactId>
+    </dependency>
+    <dependency>
+      <groupId>org.slf4j</groupId>
+      <artifactId>log4j-over-slf4j</artifactId>
+    </dependency>
+
     <dependency>
       <groupId>junit</groupId>
       <artifactId>junit</artifactId>
@@ -86,11 +108,6 @@
       <scope>test</scope>
     </dependency>
     <dependency>
-      <groupId>ch.qos.logback</groupId>
-      <artifactId>logback-classic</artifactId>
-      <scope>test</scope>
-    </dependency>
-    <dependency>
       <groupId>org.dbunit</groupId>
       <artifactId>dbunit</artifactId>
       <scope>test</scope>
diff --git a/sonar-server/src/main/java/org/sonar/server/platform/Logback.java b/sonar-core/src/main/java/org/sonar/core/config/Logback.java
index eec641e2f65..ceb1cc0dba4 100644
--- a/sonar-server/src/main/java/org/sonar/server/platform/Logback.java
+++ b/sonar-core/src/main/java/org/sonar/core/config/Logback.java
@@ -17,36 +17,59 @@
  * License along with Sonar; if not, write to the Free Software
  * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02
  */
-package org.sonar.server.platform;
+package org.sonar.core.config;
 
 import ch.qos.logback.classic.LoggerContext;
 import ch.qos.logback.classic.joran.JoranConfigurator;
 import ch.qos.logback.core.joran.spi.JoranException;
 import ch.qos.logback.core.util.StatusPrinter;
+import org.apache.commons.io.FileUtils;
+import org.apache.commons.io.IOUtils;
 import org.slf4j.LoggerFactory;
 
 import java.io.File;
+import java.io.FileInputStream;
+import java.io.IOException;
+import java.io.InputStream;
 
 /**
- * Configure Logback with $SONAR_HOME/conf/logback.xml
+ * Configure Logback
  *
  * @since 2.12
  */
-final class Logback {
+public final class Logback {
 
-  static void configure() {
-    configure(new File(SonarHome.getHome(), "conf/logback.xml"));
+  public static void configure(String classloaderPath) {
+    InputStream input = Logback.class.getResourceAsStream(classloaderPath);
+    if (input == null) {
+      throw new IllegalArgumentException("Logback configuration not found in classloader: " + classloaderPath);
+    }
+    configure(input);
+  }
+
+  public static void configure(File logbackFile) {
+    try {
+      FileInputStream input = FileUtils.openInputStream(logbackFile);
+      configure(input);
+    } catch (IOException e) {
+      throw new IllegalArgumentException("Fail to load the Logback configuration: " + logbackFile, e);
+    }
   }
 
-  static void configure(File logbackFile) {
+  /**
+   * Note that this method closes the input stream
+   */
+  private static void configure(InputStream input) {
     LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();
     try {
       JoranConfigurator configurator = new JoranConfigurator();
       configurator.setContext(lc);
       lc.reset();
-      configurator.doConfigure(logbackFile);
+      configurator.doConfigure(input);
     } catch (JoranException e) {
       // StatusPrinter will handle this
+    } finally {
+      IOUtils.closeQuietly(input);
     }
     StatusPrinter.printInCaseOfErrorsOrWarnings(lc);
   }
diff --git a/sonar-maven-plugin/src/main/java/org/sonar/maven/SonarMojo.java b/sonar-maven-plugin/src/main/java/org/sonar/maven/SonarMojo.java
index 6b78f9b463d..89b5190ba97 100644
--- a/sonar-maven-plugin/src/main/java/org/sonar/maven/SonarMojo.java
+++ b/sonar-maven-plugin/src/main/java/org/sonar/maven/SonarMojo.java
@@ -19,11 +19,6 @@
  */
 package org.sonar.maven;
 
-import ch.qos.logback.classic.LoggerContext;
-import ch.qos.logback.classic.joran.JoranConfigurator;
-import ch.qos.logback.core.joran.spi.JoranException;
-import org.apache.commons.configuration.*;
-import org.apache.commons.io.IOUtils;
 import org.apache.maven.artifact.factory.ArtifactFactory;
 import org.apache.maven.artifact.metadata.ArtifactMetadataSource;
 import org.apache.maven.artifact.repository.ArtifactRepository;
@@ -38,13 +33,12 @@ import org.apache.maven.plugin.PluginManager;
 import org.apache.maven.project.MavenProject;
 import org.apache.maven.project.MavenProjectBuilder;
 import org.apache.maven.shared.dependency.tree.DependencyTreeBuilder;
-import org.slf4j.LoggerFactory;
 import org.sonar.api.batch.bootstrap.ProjectDefinition;
 import org.sonar.api.batch.bootstrap.ProjectReactor;
 import org.sonar.batch.Batch;
 import org.sonar.batch.MavenProjectConverter;
 import org.sonar.batch.bootstrapper.EnvironmentInformation;
-import java.io.InputStream;
+import org.sonar.core.config.Logback;
 
 /**
  * @goal sonar
@@ -81,7 +75,7 @@ public final class SonarMojo extends AbstractMojo {
 
   /**
    * The artifact factory to use.
-   * 
+   *
    * @component
    * @required
    * @readonly
@@ -90,7 +84,7 @@ public final class SonarMojo extends AbstractMojo {
 
   /**
    * The artifact repository to use.
-   * 
+   *
    * @parameter expression="${localRepository}"
    * @required
    * @readonly
@@ -99,7 +93,7 @@ public final class SonarMojo extends AbstractMojo {
 
   /**
    * The artifact metadata source to use.
-   * 
+   *
    * @component
    * @required
    * @readonly
@@ -108,7 +102,7 @@ public final class SonarMojo extends AbstractMojo {
 
   /**
    * The artifact collector to use.
-   * 
+   *
    * @component
    * @required
    * @readonly
@@ -117,7 +111,7 @@ public final class SonarMojo extends AbstractMojo {
 
   /**
    * The dependency tree builder to use.
-   * 
+   *
    * @component
    * @required
    * @readonly
@@ -139,7 +133,7 @@ public final class SonarMojo extends AbstractMojo {
   private RuntimeInformation runtimeInformation;
 
   public void execute() throws MojoExecutionException, MojoFailureException {
-    initLogging();
+    configureLogback();
     executeBatch();
   }
 
@@ -159,29 +153,8 @@ public final class SonarMojo extends AbstractMojo {
     return new EnvironmentInformation("Maven", mavenVersion);
   }
 
-  private void initLogging() throws MojoExecutionException {
-    LoggerContext context = (LoggerContext) LoggerFactory.getILoggerFactory();
-    JoranConfigurator jc = new JoranConfigurator();
-    jc.setContext(context);
-    context.reset();
-    InputStream input = getClass().getResourceAsStream("/org/sonar/batch/logback.xml");
+  private void configureLogback() {
     System.setProperty("ROOT_LOGGER_LEVEL", getLog().isDebugEnabled() ? "DEBUG" : "INFO");
-    try {
-      jc.doConfigure(input);
-
-    } catch (JoranException e) {
-      throw new MojoExecutionException("can not initialize logging", e);
-
-    } finally {
-      IOUtils.closeQuietly(input);
-    }
-  }
-
-  private Configuration getInitialConfiguration() {
-    CompositeConfiguration configuration = new CompositeConfiguration();
-    configuration.addConfiguration(new SystemConfiguration());
-    configuration.addConfiguration(new EnvironmentConfiguration());
-    configuration.addConfiguration(new MapConfiguration(project.getModel().getProperties()));
-    return configuration;
+    Logback.configure("/org/sonar/maven/logback.xml");
   }
 }
diff --git a/sonar-maven-plugin/src/main/resources/org/sonar/maven/logback.xml b/sonar-maven-plugin/src/main/resources/org/sonar/maven/logback.xml
new file mode 100644
index 00000000000..585dc31806e
--- /dev/null
+++ b/sonar-maven-plugin/src/main/resources/org/sonar/maven/logback.xml
@@ -0,0 +1,14 @@
+<?xml version="1.0" encoding="UTF-8" ?>
+<configuration debug="false">
+
+  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
+    <encoder>
+      <pattern>[%level] %d{HH:mm:ss.SSS} %msg%n</pattern>
+    </encoder>
+  </appender>
+
+  <!-- Include definition of loggers. The appender STDOUT is not shared in sonar-batch because
+   format is slightly different between Maven and Ant logs -->
+  <include resource="/org/sonar/batch/logback-base.xml"/>
+
+</configuration>
\ No newline at end of file
diff --git a/sonar-maven3-plugin/src/main/java/org/sonar/maven3/SonarMojo.java b/sonar-maven3-plugin/src/main/java/org/sonar/maven3/SonarMojo.java
index 001378c7bb7..eabc913e42a 100644
--- a/sonar-maven3-plugin/src/main/java/org/sonar/maven3/SonarMojo.java
+++ b/sonar-maven3-plugin/src/main/java/org/sonar/maven3/SonarMojo.java
@@ -19,10 +19,6 @@
  */
 package org.sonar.maven3;
 
-import ch.qos.logback.classic.LoggerContext;
-import ch.qos.logback.classic.joran.JoranConfigurator;
-import ch.qos.logback.core.joran.spi.JoranException;
-import org.apache.commons.io.IOUtils;
 import org.apache.maven.artifact.factory.ArtifactFactory;
 import org.apache.maven.artifact.metadata.ArtifactMetadataSource;
 import org.apache.maven.artifact.repository.ArtifactRepository;
@@ -36,14 +32,12 @@ import org.apache.maven.plugin.MojoFailureException;
 import org.apache.maven.project.MavenProject;
 import org.apache.maven.project.MavenProjectBuilder;
 import org.apache.maven.shared.dependency.tree.DependencyTreeBuilder;
-import org.slf4j.LoggerFactory;
 import org.sonar.api.batch.bootstrap.ProjectDefinition;
 import org.sonar.api.batch.bootstrap.ProjectReactor;
 import org.sonar.batch.Batch;
 import org.sonar.batch.MavenProjectConverter;
 import org.sonar.batch.bootstrapper.EnvironmentInformation;
-
-import java.io.InputStream;
+import org.sonar.core.config.Logback;
 
 /**
  * @goal sonar
@@ -74,7 +68,7 @@ public final class SonarMojo extends AbstractMojo {
 
   /**
    * The artifact factory to use.
-   * 
+   *
    * @component
    * @required
    * @readonly
@@ -83,7 +77,7 @@ public final class SonarMojo extends AbstractMojo {
 
   /**
    * The artifact repository to use.
-   * 
+   *
    * @parameter expression="${localRepository}"
    * @required
    * @readonly
@@ -92,7 +86,7 @@ public final class SonarMojo extends AbstractMojo {
 
   /**
    * The artifact metadata source to use.
-   * 
+   *
    * @component
    * @required
    * @readonly
@@ -101,7 +95,7 @@ public final class SonarMojo extends AbstractMojo {
 
   /**
    * The artifact collector to use.
-   * 
+   *
    * @component
    * @required
    * @readonly
@@ -110,7 +104,7 @@ public final class SonarMojo extends AbstractMojo {
 
   /**
    * The dependency tree builder to use.
-   * 
+   *
    * @component
    * @required
    * @readonly
@@ -132,7 +126,7 @@ public final class SonarMojo extends AbstractMojo {
   private RuntimeInformation runtimeInformation;
 
   public void execute() throws MojoExecutionException, MojoFailureException {
-    initLogging();
+    configureLogback();
     executeBatch();
   }
 
@@ -152,22 +146,8 @@ public final class SonarMojo extends AbstractMojo {
     return new EnvironmentInformation("Maven", mavenVersion);
   }
 
-  private void initLogging() throws MojoExecutionException {
-    LoggerContext context = (LoggerContext) LoggerFactory.getILoggerFactory();
-    JoranConfigurator jc = new JoranConfigurator();
-    jc.setContext(context);
-    context.reset();
-    InputStream input = getClass().getResourceAsStream("/org/sonar/batch/logback.xml");
+  private void configureLogback() {
     System.setProperty("ROOT_LOGGER_LEVEL", getLog().isDebugEnabled() ? "DEBUG" : "INFO");
-    try {
-      jc.doConfigure(input);
-
-    } catch (JoranException e) {
-      throw new MojoExecutionException("can not initialize logging", e);
-
-    } finally {
-      IOUtils.closeQuietly(input);
-    }
+    Logback.configure("/org/sonar/maven3/logback.xml");
   }
-
 }
diff --git a/sonar-maven3-plugin/src/main/resources/org/sonar/maven3/logback.xml b/sonar-maven3-plugin/src/main/resources/org/sonar/maven3/logback.xml
new file mode 100644
index 00000000000..585dc31806e
--- /dev/null
+++ b/sonar-maven3-plugin/src/main/resources/org/sonar/maven3/logback.xml
@@ -0,0 +1,14 @@
+<?xml version="1.0" encoding="UTF-8" ?>
+<configuration debug="false">
+
+  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
+    <encoder>
+      <pattern>[%level] %d{HH:mm:ss.SSS} %msg%n</pattern>
+    </encoder>
+  </appender>
+
+  <!-- Include definition of loggers. The appender STDOUT is not shared in sonar-batch because
+   format is slightly different between Maven and Ant logs -->
+  <include resource="/org/sonar/batch/logback-base.xml"/>
+
+</configuration>
\ No newline at end of file
diff --git a/sonar-server/pom.xml b/sonar-server/pom.xml
index 4cd62ce8577..11343cbd402 100644
--- a/sonar-server/pom.xml
+++ b/sonar-server/pom.xml
@@ -122,31 +122,11 @@
       <groupId>jfree</groupId>
       <artifactId>jfreechart</artifactId>
     </dependency>
-
-    <!-- logging -->
     <dependency>
       <groupId>org.slf4j</groupId>
       <artifactId>slf4j-api</artifactId>
     </dependency>
     <dependency>
-      <groupId>ch.qos.logback</groupId>
-      <artifactId>logback-classic</artifactId>
-    </dependency>
-    <dependency>
-      <groupId>ch.qos.logback</groupId>
-      <artifactId>logback-core</artifactId>
-    </dependency>
-    <dependency>
-      <groupId>org.slf4j</groupId>
-      <artifactId>jcl-over-slf4j</artifactId>
-    </dependency>
-    <dependency>
-      <groupId>org.slf4j</groupId>
-      <artifactId>log4j-over-slf4j</artifactId>
-    </dependency>
-
-
-    <dependency>
       <groupId>commons-dbcp</groupId>
       <artifactId>commons-dbcp</artifactId>
     </dependency>
diff --git a/sonar-server/src/main/java/org/sonar/server/platform/PlatformLifecycleListener.java b/sonar-server/src/main/java/org/sonar/server/platform/PlatformLifecycleListener.java
index 10dcb45375c..1837223ae1b 100644
--- a/sonar-server/src/main/java/org/sonar/server/platform/PlatformLifecycleListener.java
+++ b/sonar-server/src/main/java/org/sonar/server/platform/PlatformLifecycleListener.java
@@ -19,13 +19,16 @@
  */
 package org.sonar.server.platform;
 
+import org.sonar.core.config.Logback;
+
 import javax.servlet.ServletContextEvent;
 import javax.servlet.ServletContextListener;
+import java.io.File;
 
 public final class PlatformLifecycleListener implements ServletContextListener {
 
   public void contextInitialized(ServletContextEvent event) {
-    Logback.configure();
+    configureLogback();
     Platform.getInstance().init(event.getServletContext());
     Platform.getInstance().start();
   }
@@ -33,4 +36,11 @@ public final class PlatformLifecycleListener implements ServletContextListener {
   public void contextDestroyed(ServletContextEvent event) {
     Platform.getInstance().stop();
   }
+
+  /**
+   * Configure Logback with $SONAR_HOME/conf/logback.xml
+   */
+  private void configureLogback() {
+    Logback.configure(new File(SonarHome.getHome(), "conf/logback.xml"));
+  }
 }