SONAR-4898 improve logging

10 files changed, 109 insertions, 40 deletions

diff --git a/server/sonar-process/src/main/java/org/sonar/process/Process.java b/server/sonar-process/src/main/java/org/sonar/process/Process.java
index 848d2da3cd9..2c0b865bf0c 100644
--- a/server/sonar-process/src/main/java/org/sonar/process/Process.java
+++ b/server/sonar-process/src/main/java/org/sonar/process/Process.java
@@ -30,6 +30,7 @@ import javax.management.MBeanServer;
 import javax.management.MalformedObjectNameException;
 import javax.management.NotCompliantMBeanException;
 import javax.management.ObjectName;
+
 import java.io.File;
 import java.io.FileReader;
 import java.io.IOException;
@@ -150,17 +151,17 @@ public abstract class Process implements ProcessMXBean {
   public abstract void onTerminate();
 
   public final void start() {
-    LOGGER.debug("Process[{}]::start() START", name);
+    LOGGER.debug("Process[{}] starting", name);
     if (this.port != null) {
       lastPing = System.currentTimeMillis();
       pingTask = monitor.scheduleWithFixedDelay(breakOnMissingPing, 5, 5, TimeUnit.SECONDS);
     }
     this.onStart();
-    LOGGER.trace("Process[{}]::start() END", name);
+    LOGGER.debug("Process[{}] started", name);
   }
 
   public final void terminate() {
-    LOGGER.debug("Process[{}]::terminate() START", name);
+    LOGGER.debug("Process[{}] terminating", name);
     if (monitor != null) {
       this.monitor.shutdownNow();
       this.monitor = null;
@@ -170,6 +171,6 @@ public abstract class Process implements ProcessMXBean {
       }
       this.onTerminate();
     }
-    LOGGER.trace("Process[{}]::terminate() END", name);
+    LOGGER.debug("Process[{}] terminated", name);
   }
 }
diff --git a/server/sonar-process/src/main/java/org/sonar/process/ProcessWrapper.java b/server/sonar-process/src/main/java/org/sonar/process/ProcessWrapper.java
index 94c185562ff..24568612d7c 100644
--- a/server/sonar-process/src/main/java/org/sonar/process/ProcessWrapper.java
+++ b/server/sonar-process/src/main/java/org/sonar/process/ProcessWrapper.java
@@ -31,6 +31,7 @@ import javax.management.MBeanServerConnection;
 import javax.management.remote.JMXConnector;
 import javax.management.remote.JMXConnectorFactory;
 import javax.management.remote.JMXServiceURL;
+
 import java.io.BufferedReader;
 import java.io.File;
 import java.io.FileOutputStream;
@@ -130,7 +131,7 @@ public class ProcessWrapper extends Thread {
     processBuilder.environment().putAll(envProperties);
 
     try {
-      LOGGER.debug("ProcessWrapper::executeProcess() -- Starting process with command '{}'", StringUtils.join(command, " "));
+      LOGGER.debug("Execute command: {}", StringUtils.join(command, " "));
       process = processBuilder.start();
       errorGobbler = new StreamGobbler(process.getErrorStream(), this.getName() + "-ERROR");
       outputGobbler = new StreamGobbler(process.getInputStream(), this.getName());
@@ -253,11 +254,6 @@ public class ProcessWrapper extends Thread {
   public void terminate() {
     if (processMXBean != null) {
       processMXBean.terminate();
-//      try {
-//        Thread.sleep(10000L);
-//      } catch (InterruptedException e) {
-//        LOGGER.warn("Could bnit", e);
-//      }
       this.interrupt();
     }
   }
diff --git a/sonar-application/assembly.xml b/sonar-application/assembly.xml
index 728a152b68c..2304815d061 100644
--- a/sonar-application/assembly.xml
+++ b/sonar-application/assembly.xml
@@ -100,7 +100,7 @@
     </dependencySet>
     <!-- Server -->
     <dependencySet>
-      <outputDirectory>lib/web</outputDirectory>
+      <outputDirectory>web</outputDirectory>
       <includes>
         <include>org.codehaus.sonar:sonar-web</include>
       </includes>
diff --git a/sonar-application/src/main/java/org/sonar/application/AppLogging.java b/sonar-application/src/main/java/org/sonar/application/AppLogging.java
new file mode 100644
index 00000000000..1d0b576ecab
--- /dev/null
+++ b/sonar-application/src/main/java/org/sonar/application/AppLogging.java
@@ -0,0 +1,44 @@
+/*
+ * SonarQube, open source software quality management tool.
+ * Copyright (C) 2008-2014 SonarSource
+ * mailto:contact AT sonarsource DOT com
+ *
+ * SonarQube 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.
+ *
+ * SonarQube 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.sonar.application;
+
+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.slf4j.LoggerFactory;
+
+class AppLogging {
+
+  void configure(Installation installation) {
+    LoggerContext context = (LoggerContext) LoggerFactory.getILoggerFactory();
+    try {
+      context.putProperty(DefaultSettings.PATH_LOGS_KEY, installation.logsDir().getAbsolutePath());
+      JoranConfigurator configurator = new JoranConfigurator();
+      configurator.setContext(context);
+      context.reset();
+      configurator.doConfigure(getClass().getResource("/org/sonar/application/logback.xml"));
+    } catch (JoranException je) {
+      // StatusPrinter will handle this
+    }
+    StatusPrinter.printInCaseOfErrorsOrWarnings(context);
+
+  }
+}
diff --git a/sonar-application/src/main/java/org/sonar/application/DefaultSettings.java b/sonar-application/src/main/java/org/sonar/application/DefaultSettings.java
index 22d31ddef17..eb414f71272 100644
--- a/sonar-application/src/main/java/org/sonar/application/DefaultSettings.java
+++ b/sonar-application/src/main/java/org/sonar/application/DefaultSettings.java
@@ -28,6 +28,8 @@ class DefaultSettings {
     // only static stuff
   }
 
+  static final String PATH_LOGS_KEY = "sonar.path.logs";
+
   static final String ES_PORT_KEY = "sonar.es.port";
   private static final int ES_PORT_DEFVAL = 9001;
 
diff --git a/sonar-application/src/main/java/org/sonar/application/Installation.java b/sonar-application/src/main/java/org/sonar/application/Installation.java
index 2705a3d58fe..35142b46e11 100644
--- a/sonar-application/src/main/java/org/sonar/application/Installation.java
+++ b/sonar-application/src/main/java/org/sonar/application/Installation.java
@@ -22,12 +22,11 @@ package org.sonar.application;
 import org.apache.commons.io.FileUtils;
 import org.apache.commons.io.FilenameUtils;
 import org.apache.commons.io.IOUtils;
-import org.slf4j.Logger;
-import org.slf4j.LoggerFactory;
 import org.sonar.process.Props;
 
 import javax.annotation.CheckForNull;
 import javax.annotation.Nullable;
+
 import java.io.File;
 import java.io.FileReader;
 import java.io.IOException;
@@ -35,8 +34,6 @@ import java.net.URISyntaxException;
 import java.util.Properties;
 
 public class Installation {
-  private static final Logger LOG = LoggerFactory.getLogger(Installation.class);
-
   private final File homeDir;
   private final File tempDir, logsDir;
   private final Props props;
@@ -50,7 +47,7 @@ public class Installation {
 
     // init file system
     initExistingDir("sonar.path.data", "data");
-    initExistingDir("sonar.path.web", "lib/web");
+    initExistingDir("sonar.path.web", "web");
     this.tempDir = initTempDir("sonar.path.temp", "temp");
     this.logsDir = initExistingDir("sonar.path.logs", "logs");
   }
@@ -73,8 +70,6 @@ public class Installation {
       } finally {
         IOUtils.closeQuietly(reader);
       }
-    } else {
-      LOG.info("Configuration file not found: " + propsFile.getAbsolutePath());
     }
     p.putAll(System.getenv());
     p.putAll(System.getProperties());
diff --git a/sonar-application/src/main/java/org/sonar/application/StartServer.java b/sonar-application/src/main/java/org/sonar/application/StartServer.java
index ebdd4e7fa02..80076761497 100644
--- a/sonar-application/src/main/java/org/sonar/application/StartServer.java
+++ b/sonar-application/src/main/java/org/sonar/application/StartServer.java
@@ -19,7 +19,6 @@
  */
 package org.sonar.application;
 
-import com.google.common.annotations.VisibleForTesting;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 import org.sonar.process.Monitor;
@@ -32,6 +31,7 @@ import javax.management.InstanceAlreadyExistsException;
 import javax.management.MBeanRegistrationException;
 import javax.management.MBeanServer;
 import javax.management.NotCompliantMBeanException;
+
 import java.lang.management.ManagementFactory;
 
 public class StartServer implements ProcessMXBean {
@@ -45,11 +45,6 @@ public class StartServer implements ProcessMXBean {
 
   private static Logger LOGGER = LoggerFactory.getLogger(StartServer.class);
 
-  public StartServer() throws Exception {
-    this(new Installation());
-  }
-
-  @VisibleForTesting
   StartServer(Installation installation) throws Exception {
     this.installation = installation;
 
@@ -75,17 +70,15 @@ public class StartServer implements ProcessMXBean {
     }
 
     monitor = new Monitor();
-
   }
 
-  private void start(){
-
+  private void start() {
     elasticsearch = new ProcessWrapper("ES")
       .setWorkDir(installation.homeDir())
       .setJmxPort(Integer.parseInt(installation.prop(DefaultSettings.ES_JMX_PORT_KEY)))
       .addJavaOpts(installation.prop(DefaultSettings.ES_JAVA_OPTS_KEY))
-      .addJavaOpts("-Djava.io.tmpdir=" + installation.tempDir().getAbsolutePath())
-      .addJavaOpts("-Dsonar.path.logs=" + installation.logsDir().getAbsolutePath())
+      .addJavaOpts(String.format("-Djava.io.tmpdir=%s", installation.tempDir().getAbsolutePath()))
+      .addJavaOpts(String.format("-D%s=%s", DefaultSettings.PATH_LOGS_KEY, installation.logsDir().getAbsolutePath()))
       .setClassName("org.sonar.search.ElasticSearch")
       .setProperties(installation.props().cryptedProperties())
       .addClasspath(installation.starPath("lib/common"))
@@ -93,14 +86,13 @@ public class StartServer implements ProcessMXBean {
       .execute();
     monitor.registerProcess(elasticsearch);
 
-
     server = new ProcessWrapper("SQ")
       .setWorkDir(installation.homeDir())
       .setJmxPort(Integer.parseInt(installation.prop(DefaultSettings.WEB_JMX_PORT_KEY)))
       .addJavaOpts(installation.prop(DefaultSettings.WEB_JAVA_OPTS_KEY))
       .addJavaOpts(DefaultSettings.WEB_JAVA_OPTS_APPENDED_VAL)
-      .addJavaOpts("-Djava.io.tmpdir=" + installation.tempDir().getAbsolutePath())
-      .addJavaOpts("-Dsonar.path.logs=" + installation.logsDir().getAbsolutePath())
+      .addJavaOpts(String.format("-Djava.io.tmpdir=%s", installation.tempDir().getAbsolutePath()))
+      .addJavaOpts(String.format("-D%s=%s", DefaultSettings.PATH_LOGS_KEY, installation.logsDir().getAbsolutePath()))
       .setClassName("org.sonar.server.app.ServerProcess")
       .setProperties(installation.props().cryptedProperties())
       .addClasspath(installation.starPath("extensions/jdbc-driver/mysql"))
@@ -153,10 +145,6 @@ public class StartServer implements ProcessMXBean {
     }
   }
 
-  public static void main(String[] args) throws Exception {
-    new StartServer().start();
-  }
-
   @Override
   public boolean isReady() {
     return monitor.isAlive();
@@ -166,4 +154,10 @@ public class StartServer implements ProcessMXBean {
   public long ping() {
     return System.currentTimeMillis();
   }
+
+  public static void main(String[] args) throws Exception {
+    Installation installation = new Installation();
+    new AppLogging().configure(installation);
+    new StartServer(installation).start();
+  }
 }
diff --git a/sonar-application/src/main/resources/logback.xml b/sonar-application/src/main/resources/org/sonar/application/logback.xml
index 5a19d946cd5..51aaa17a6be 100644
--- a/sonar-application/src/main/resources/logback.xml
+++ b/sonar-application/src/main/resources/org/sonar/application/logback.xml
@@ -10,9 +10,9 @@
   <contextListener class="ch.qos.logback.classic.jul.LevelChangePropagator"/>
 
   <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
-    <File>${SONAR_HOME}/logs/sonar.log</File>
+    <File>${sonar.path.logs}/sonar.log</File>
     <rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">
-      <param name="FileNamePattern" value="${SONAR_HOME}/logs/sonar.%i.log"/>
+      <param name="FileNamePattern" value="${sonar.path.logs}/sonar.%i.log"/>
       <param name="MinIndex" value="1"/>
       <param name="MaxIndex" value="3"/>
     </rollingPolicy>
diff --git a/sonar-application/src/test/java/org/sonar/application/StartServerTest.java b/sonar-application/src/test/java/org/sonar/application/StartServerTest.java
index bf22443ccff..c410b840ff1 100644
--- a/sonar-application/src/test/java/org/sonar/application/StartServerTest.java
+++ b/sonar-application/src/test/java/org/sonar/application/StartServerTest.java
@@ -58,7 +58,6 @@ public class StartServerTest {
 
   @Test
   public void should_register_mbean() throws Exception {
-
     Installation installation = mock(Installation.class);
     when(installation.detectHomeDir()).thenReturn(sonarHome.getRoot());
 
@@ -95,4 +94,4 @@ public class StartServerTest {
       assertThat(e.getMessage()).isEqualTo("No such operation: xoxo");
     }
   }
-}
\ No newline at end of file
+}
diff --git a/sonar-application/src/test/resources/logback-test.xml b/sonar-application/src/test/resources/logback-test.xml
new file mode 100644
index 00000000000..ff2270cc122
--- /dev/null
+++ b/sonar-application/src/test/resources/logback-test.xml
@@ -0,0 +1,38 @@
+<?xml version="1.0" encoding="UTF-8" ?>
+
+<!--
+  Configuration for default logger. Only used while embedded server is starting,
+  before proper logging configuration is loaded.
+
+  See http://logback.qos.ch/manual/configuration.html
+-->
+<configuration debug="false">
+  <contextListener class="ch.qos.logback.classic.jul.LevelChangePropagator"/>
+
+  <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
+    <filter class="ch.qos.logback.classic.filter.LevelFilter">
+      <level>INFO</level>
+      <onMatch>ACCEPT</onMatch>
+      <onMismatch>DENY</onMismatch>
+    </filter>
+    <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
+      <pattern>
+        %d{yyyy.MM.dd HH:mm:ss} %-5level %msg%n
+      </pattern>
+    </encoder>
+  </appender>
+
+  <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
+    <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
+      <pattern>
+        %d{yyyy.MM.dd HH:mm:ss} %-5level %msg%n
+      </pattern>
+    </encoder>
+  </appender>
+
+  <root>
+    <level value="DEBUG"/>
+    <appender-ref ref="CONSOLE"/>
+  </root>
+
+</configuration>