SONAR-7960 add task UUID to logs

8 files changed, 49 insertions, 38 deletions

diff --git a/server/sonar-process/src/test/java/org/sonar/process/LogbackHelperTest.java b/server/sonar-process/src/test/java/org/sonar/process/LogbackHelperTest.java
index 6eeacdebea9..389a4c4f395 100644
--- a/server/sonar-process/src/test/java/org/sonar/process/LogbackHelperTest.java
+++ b/server/sonar-process/src/test/java/org/sonar/process/LogbackHelperTest.java
@@ -46,12 +46,12 @@ import static org.mockito.Mockito.mock;
 
 public class LogbackHelperTest {
 
-  Props props = new Props(new Properties());
-  LogbackHelper underTest = new LogbackHelper();
-
   @Rule
   public TemporaryFolder temp = new TemporaryFolder();
 
+  private Props props = new Props(new Properties());
+  private LogbackHelper underTest = new LogbackHelper();
+
   @Before
   public void setUp() throws Exception {
     File dir = temp.newFolder();
diff --git a/server/sonar-search/src/main/java/org/sonar/search/SearchLogging.java b/server/sonar-search/src/main/java/org/sonar/search/SearchLogging.java
index 6bbf88ab2c8..ec3ac8fc78b 100644
--- a/server/sonar-search/src/main/java/org/sonar/search/SearchLogging.java
+++ b/server/sonar-search/src/main/java/org/sonar/search/SearchLogging.java
@@ -28,7 +28,7 @@ import org.sonar.process.LogbackHelper;
 
 public class SearchLogging {
 
-  private static final String LOG_FORMAT = "%d{yyyy.MM.dd HH:mm:ss} %-5level  es[%logger{20}] %X %msg%n";
+  private static final String LOG_FORMAT = "%d{yyyy.MM.dd HH:mm:ss} %-5level  es[][%logger{20}] %X %msg%n";
 
   private LogbackHelper helper = new LogbackHelper();
 
diff --git a/server/sonar-server/src/main/java/org/sonar/ce/log/CeLogging.java b/server/sonar-server/src/main/java/org/sonar/ce/log/CeLogging.java
index 7cdf1c9ff04..406bad585aa 100644
--- a/server/sonar-server/src/main/java/org/sonar/ce/log/CeLogging.java
+++ b/server/sonar-server/src/main/java/org/sonar/ce/log/CeLogging.java
@@ -42,17 +42,18 @@ public class CeLogging {
 
   private static final String CE_ACTIVITY_APPENDER_NAME = "ce_activity";
   private static final String CE_ACTIVITY_FILE_NAME_PREFIX = "ce_activity";
-  private static final String CE_ACTIVITY_ENCODER_PATTERN = "%d{yyyy.MM.dd HH:mm:ss} %-5level [%logger{20}] %msg%n";
+  private static final String CE_ACTIVITY_ENCODER_PATTERN = "%d{yyyy.MM.dd HH:mm:ss} %-5level [%X{ceTaskUuid}][%logger{20}] %msg%n";
 
   static final String MDC_CE_ACTIVITY_FLAG = "ceActivityFlag";
+  static final String MDC_CE_TASK_UUID = "ceTaskUuid";
   public static final String MAX_LOGS_PROPERTY = "sonar.ce.maxLogsPerTask";
 
   public void initForTask(CeTask task) {
-    // TODO put task UUID in MDC (cf. SONAR-7960)
+    MDC.put(MDC_CE_TASK_UUID, task.getUuid());
   }
 
   public void clearForTask() {
-    // TODO clear task UUID from MDF (cf. SONAR-7960)
+    MDC.remove(MDC_CE_TASK_UUID);
   }
 
   public void logCeActivity(Logger logger, Runnable logProducer) {
diff --git a/server/sonar-server/src/main/java/org/sonar/server/app/ServerProcessLogging.java b/server/sonar-server/src/main/java/org/sonar/server/app/ServerProcessLogging.java
index 783d46bac4a..7e2125c99fe 100644
--- a/server/sonar-server/src/main/java/org/sonar/server/app/ServerProcessLogging.java
+++ b/server/sonar-server/src/main/java/org/sonar/server/app/ServerProcessLogging.java
@@ -30,7 +30,7 @@ import org.sonar.server.platform.ServerLogging;
 
 public abstract class ServerProcessLogging {
   private static final String LOG_LEVEL_PROPERTY = "sonar.log.level";
-  private static final String LOG_FORMAT = "%d{yyyy.MM.dd HH:mm:ss} %-5level XXXX[%logger{20}] %msg%n";
+  private static final String LOG_FORMAT = "%d{yyyy.MM.dd HH:mm:ss} %-5level XXXX[%X{ceTaskUuid}][%logger{20}] %msg%n";
   private final String processName;
   private final LogbackHelper helper = new LogbackHelper();
 
diff --git a/server/sonar-server/src/test/java/org/sonar/ce/log/CeLoggingTest.java b/server/sonar-server/src/test/java/org/sonar/ce/log/CeLoggingTest.java
index c72d3b31f6f..b2347ffa8c5 100644
--- a/server/sonar-server/src/test/java/org/sonar/ce/log/CeLoggingTest.java
+++ b/server/sonar-server/src/test/java/org/sonar/ce/log/CeLoggingTest.java
@@ -40,6 +40,7 @@ import org.junit.rules.TemporaryFolder;
 import org.mockito.Mockito;
 import org.slf4j.MDC;
 import org.sonar.api.utils.log.Logger;
+import org.sonar.ce.queue.CeTask;
 import org.sonar.process.LogbackHelper;
 import org.sonar.process.ProcessProperties;
 import org.sonar.process.Props;
@@ -50,8 +51,10 @@ import static ch.qos.logback.classic.Level.INFO;
 import static ch.qos.logback.classic.Level.TRACE;
 import static ch.qos.logback.classic.Level.WARN;
 import static org.assertj.core.api.Assertions.assertThat;
+import static org.mockito.Mockito.mock;
 import static org.mockito.Mockito.when;
 import static org.sonar.ce.log.CeLogging.MDC_CE_ACTIVITY_FLAG;
+import static org.sonar.ce.log.CeLogging.MDC_CE_TASK_UUID;
 
 public class CeLoggingTest {
 
@@ -81,6 +84,30 @@ public class CeLoggingTest {
   }
 
   @Test
+  public void initForTask_stores_task_uuid_in_MDC() {
+    String uuid = "ce_task_uuid";
+
+    underTest.initForTask(createCeTask(uuid));
+
+    assertThat(MDC.get(MDC_CE_TASK_UUID)).isEqualTo(uuid);
+  }
+
+  private CeTask createCeTask(String uuid) {
+    CeTask ceTask = Mockito.mock(CeTask.class);
+    when(ceTask.getUuid()).thenReturn(uuid);
+    return ceTask;
+  }
+
+  @Test
+  public void clearForTask_removes_task_uuid_from_MDC() {
+    MDC.put(MDC_CE_TASK_UUID, "some_value");
+
+    underTest.clearForTask();
+
+    assertThat(MDC.get(MDC_CE_TASK_UUID)).isNull();
+  }
+
+  @Test
   public void createCeConfigurationConfiguration_fails_if_log_directory_is_not_set_in_Props() {
     LogbackHelper helper = new LogbackHelper();
     LoggerContext ctx = new LoggerContext();
@@ -149,7 +176,7 @@ public class CeLoggingTest {
   }
 
   private static Logger createLogger(Level info) {
-    Logger logger = Mockito.mock(Logger.class);
+    Logger logger = mock(Logger.class);
     when(logger.isDebugEnabled()).thenReturn(DEBUG.isGreaterOrEqual(info));
     when(logger.isTraceEnabled()).thenReturn(TRACE.isGreaterOrEqual(info));
     return logger;
diff --git a/server/sonar-server/src/test/java/org/sonar/server/computation/task/projectanalysis/step/ExecuteVisitorsStepTest.java b/server/sonar-server/src/test/java/org/sonar/server/computation/task/projectanalysis/step/ExecuteVisitorsStepTest.java
index d28939958f3..e48f66b3db1 100644
--- a/server/sonar-server/src/test/java/org/sonar/server/computation/task/projectanalysis/step/ExecuteVisitorsStepTest.java
+++ b/server/sonar-server/src/test/java/org/sonar/server/computation/task/projectanalysis/step/ExecuteVisitorsStepTest.java
@@ -145,39 +145,21 @@ public class ExecuteVisitorsStepTest {
     assertThat(logs.get(3)).startsWith("  - VisitorC | time=");
   }
 
-  private static class VisitorA implements ComponentVisitor {
-    @Override
-    public Order getOrder() {
-      return Order.PRE_ORDER;
-    }
-
-    @Override
-    public CrawlerDepthLimit getMaxDepth() {
-      return CrawlerDepthLimit.PROJECT;
+  private static class VisitorA extends TypeAwareVisitorAdapter {
+    public VisitorA() {
+      super(CrawlerDepthLimit.PROJECT, Order.PRE_ORDER);
     }
   }
 
-  private static class VisitorB implements ComponentVisitor {
-    @Override
-    public Order getOrder() {
-      return Order.PRE_ORDER;
-    }
-
-    @Override
-    public CrawlerDepthLimit getMaxDepth() {
-      return CrawlerDepthLimit.PROJECT;
+  private static class VisitorB extends TypeAwareVisitorAdapter {
+    public VisitorB() {
+      super(CrawlerDepthLimit.PROJECT, Order.PRE_ORDER);
     }
   }
 
-  private static class VisitorC implements ComponentVisitor {
-    @Override
-    public Order getOrder() {
-      return Order.PRE_ORDER;
-    }
-
-    @Override
-    public CrawlerDepthLimit getMaxDepth() {
-      return CrawlerDepthLimit.PROJECT;
+  private static class VisitorC extends TypeAwareVisitorAdapter {
+    public VisitorC() {
+      super(CrawlerDepthLimit.PROJECT, Order.PRE_ORDER);
     }
   }
 
diff --git a/server/sonar-server/src/test/java/org/sonar/server/computation/taskprocessor/CeWorkerCallableImplTest.java b/server/sonar-server/src/test/java/org/sonar/server/computation/taskprocessor/CeWorkerCallableImplTest.java
index 1460f3f6e39..d8182ed2324 100644
--- a/server/sonar-server/src/test/java/org/sonar/server/computation/taskprocessor/CeWorkerCallableImplTest.java
+++ b/server/sonar-server/src/test/java/org/sonar/server/computation/taskprocessor/CeWorkerCallableImplTest.java
@@ -38,6 +38,7 @@ import org.sonar.server.computation.task.projectanalysis.taskprocessor.ReportTas
 import static org.assertj.core.api.Assertions.assertThat;
 import static org.mockito.Mockito.doThrow;
 import static org.mockito.Mockito.mock;
+import static org.mockito.Mockito.spy;
 import static org.mockito.Mockito.verifyZeroInteractions;
 import static org.mockito.Mockito.when;
 
@@ -50,7 +51,7 @@ public class CeWorkerCallableImplTest {
 
   InternalCeQueue queue = mock(InternalCeQueue.class);
   ReportTaskProcessor taskProcessor = mock(ReportTaskProcessor.class);
-  CeLogging ceLogging = mock(CeLogging.class);
+  CeLogging ceLogging = spy(CeLogging.class);
   CeWorkerCallable underTest = new CeWorkerCallableImpl(queue, ceLogging, taskProcessorRepository);
   InOrder inOrder = Mockito.inOrder(ceLogging, taskProcessor, queue);
 
diff --git a/sonar-application/src/main/java/org/sonar/application/AppLogging.java b/sonar-application/src/main/java/org/sonar/application/AppLogging.java
index 5679f75d56f..12cad324f57 100644
--- a/sonar-application/src/main/java/org/sonar/application/AppLogging.java
+++ b/sonar-application/src/main/java/org/sonar/application/AppLogging.java
@@ -40,7 +40,7 @@ class AppLogging {
   static final String CONSOLE_APPENDER = "CONSOLE";
   static final String GOBBLER_LOGGER = "gobbler";
   static final String GOBBLER_APPENDER = "GOBBLER";
-  static final String APP_PATTERN = "%d{yyyy.MM.dd HH:mm:ss} %-5level app[%logger{20}] %msg%n";
+  static final String APP_PATTERN = "%d{yyyy.MM.dd HH:mm:ss} %-5level app[][%logger{20}] %msg%n";
 
   private final LogbackHelper helper = new LogbackHelper();