SONAR-17722 add post tag logs

server/sonar-ce-task-projectanalysis/src/main/java/org/sonar/ce/task/projectanalysis/api/posttask/PostProjectAnalysisTasksExecutor.java

@@ -45,6 +45,7 @@ import org.sonar.ce.task.projectanalysis.qualitygate.QualityGateHolder;
 import org.sonar.ce.task.projectanalysis.qualitygate.QualityGateStatus;
 import org.sonar.ce.task.projectanalysis.qualitygate.QualityGateStatusHolder;
 import org.sonar.ce.task.step.ComputationStepExecutor;
+import org.sonar.core.util.logs.Profiler;
 import org.sonar.core.util.stream.MoreCollectors;
 
 import static java.lang.String.format;
@@ -109,10 +110,17 @@ public class PostProjectAnalysisTasksExecutor implements ComputationStepExecutor
   }
 
   private static void executeTask(ProjectAnalysisImpl projectAnalysis, PostProjectAnalysisTask postProjectAnalysisTask) {
+    String status = "FAILED";
+    Profiler stepProfiler = Profiler.create(LOG).logTimeLast(true);
     try {
+      stepProfiler.start();
       postProjectAnalysisTask.finished(projectAnalysis);
+      status = "SUCCESS";
     } catch (Exception e) {
       LOG.error("Execution of task " + postProjectAnalysisTask.getClass() + " failed", e);
+    } finally {
+      stepProfiler.addContext("status", status);
+      stepProfiler.stopInfo("{}", postProjectAnalysisTask.getDescription());
     }
   }
 

server/sonar-ce-task-projectanalysis/src/main/java/org/sonar/ce/task/projectanalysis/webhook/WebhookPostTask.java

@@ -40,6 +40,11 @@ public class WebhookPostTask implements PostProjectAnalysisTask {
     this.webHooks = webHooks;
   }
 
+  @Override
+  public String getDescription() {
+    return "Webhooks";
+  }
+
   @Override
   public void finished(ProjectAnalysis analysis) {
     webHooks.sendProjectAnalysisUpdate(

server/sonar-ce-task-projectanalysis/src/test/java/org/sonar/ce/task/projectanalysis/api/posttask/PostProjectAnalysisTasksExecutorTest.java

@@ -37,6 +37,8 @@ import org.mockito.InOrder;
 import org.sonar.api.ce.posttask.PostProjectAnalysisTask;
 import org.sonar.api.ce.posttask.Project;
 import org.sonar.api.utils.System2;
+import org.sonar.api.utils.log.LogTester;
+import org.sonar.api.utils.log.LoggerLevel;
 import org.sonar.ce.task.CeTask;
 import org.sonar.ce.task.projectanalysis.analysis.AnalysisMetadataHolderRule;
 import org.sonar.ce.task.projectanalysis.analysis.Branch;
@@ -80,6 +82,8 @@ public class PostProjectAnalysisTasksExecutorTest {
   public MutableQualityGateStatusHolderRule qualityGateStatusHolder = new MutableQualityGateStatusHolderRule();
   @Rule
   public BatchReportReaderRule reportReader = new BatchReportReaderRule();
+  @Rule
+  public LogTester logTester = new LogTester();
 
   private String organizationUuid = "org1";
   private String organizationKey = organizationUuid + "_key";
@@ -94,7 +98,7 @@ public class PostProjectAnalysisTasksExecutorTest {
     .setComponent(component)
     .setMainComponent(component)
     .build();
-  private PostProjectAnalysisTask postProjectAnalysisTask = mock(PostProjectAnalysisTask.class);
+  private PostProjectAnalysisTask postProjectAnalysisTask = newPostProjectAnalysisTask("PT1");
   private PostProjectAnalysisTasksExecutor underTest = new PostProjectAnalysisTasksExecutor(
     ceTask, analysisMetadataHolder, qualityGateHolder, qualityGateStatusHolder,
     reportReader, system2,
@@ -127,8 +131,8 @@ public class PostProjectAnalysisTasksExecutorTest {
   @Test
   @UseDataProvider("booleanValues")
   public void finished_calls_all_PostProjectAnalysisTask_in_order_of_the_array_and_passes_the_same_object_to_all(boolean allStepsExecuted) {
-    PostProjectAnalysisTask postProjectAnalysisTask1 = mock(PostProjectAnalysisTask.class);
-    PostProjectAnalysisTask postProjectAnalysisTask2 = mock(PostProjectAnalysisTask.class);
+    PostProjectAnalysisTask postProjectAnalysisTask1 = newPostProjectAnalysisTask("PT1");
+    PostProjectAnalysisTask postProjectAnalysisTask2 = newPostProjectAnalysisTask("PT2");
     InOrder inOrder = inOrder(postProjectAnalysisTask1, postProjectAnalysisTask2);
 
     new PostProjectAnalysisTasksExecutor(
@@ -137,12 +141,20 @@ public class PostProjectAnalysisTasksExecutorTest {
       .finished(allStepsExecuted);
 
     inOrder.verify(postProjectAnalysisTask1).finished(projectAnalysisArgumentCaptor.capture());
+    inOrder.verify(postProjectAnalysisTask1).getDescription();
     inOrder.verify(postProjectAnalysisTask2).finished(projectAnalysisArgumentCaptor.capture());
+    inOrder.verify(postProjectAnalysisTask2).getDescription();
     inOrder.verifyNoMoreInteractions();
 
     List<PostProjectAnalysisTask.ProjectAnalysis> allValues = projectAnalysisArgumentCaptor.getAllValues();
     assertThat(allValues).hasSize(2);
     assertThat(allValues.get(0)).isSameAs(allValues.get(1));
+
+    assertThat(logTester.logs()).hasSize(2);
+    List<String> logs = logTester.logs(LoggerLevel.INFO);
+    assertThat(logs).hasSize(2);
+    assertThat(logs.get(0)).matches("^PT1 \\| status=SUCCESS \\| time=\\d+ms$");
+    assertThat(logs.get(1)).matches("^PT2 \\| status=SUCCESS \\| time=\\d+ms$");
   }
 
   @Test
@@ -364,9 +376,9 @@ public class PostProjectAnalysisTasksExecutorTest {
   @Test
   @UseDataProvider("booleanValues")
   public void finished_does_not_fail_if_listener_throws_exception_and_execute_subsequent_listeners(boolean allStepsExecuted) {
-    PostProjectAnalysisTask postProjectAnalysisTask1 = mock(PostProjectAnalysisTask.class);
-    PostProjectAnalysisTask postProjectAnalysisTask2 = mock(PostProjectAnalysisTask.class);
-    PostProjectAnalysisTask postProjectAnalysisTask3 = mock(PostProjectAnalysisTask.class);
+    PostProjectAnalysisTask postProjectAnalysisTask1 = newPostProjectAnalysisTask("PT1");
+    PostProjectAnalysisTask postProjectAnalysisTask2 = newPostProjectAnalysisTask("PT2");
+    PostProjectAnalysisTask postProjectAnalysisTask3 = newPostProjectAnalysisTask("PT3");
     InOrder inOrder = inOrder(postProjectAnalysisTask1, postProjectAnalysisTask2, postProjectAnalysisTask3);
 
     doThrow(new RuntimeException("Faking a listener throws an exception"))
@@ -379,9 +391,19 @@ public class PostProjectAnalysisTasksExecutorTest {
       .finished(allStepsExecuted);
 
     inOrder.verify(postProjectAnalysisTask1).finished(projectAnalysisArgumentCaptor.capture());
+    inOrder.verify(postProjectAnalysisTask1).getDescription();
     inOrder.verify(postProjectAnalysisTask2).finished(projectAnalysisArgumentCaptor.capture());
+    inOrder.verify(postProjectAnalysisTask2).getDescription();
     inOrder.verify(postProjectAnalysisTask3).finished(projectAnalysisArgumentCaptor.capture());
+    inOrder.verify(postProjectAnalysisTask3).getDescription();
     inOrder.verifyNoMoreInteractions();
+
+    assertThat(logTester.logs()).hasSize(4);
+    List<String> logs = logTester.logs(LoggerLevel.INFO);
+    assertThat(logs).hasSize(3);
+    assertThat(logs.get(0)).matches("^PT1 \\| status=SUCCESS \\| time=\\d+ms$");
+    assertThat(logs.get(1)).matches("^PT2 \\| status=FAILED \\| time=\\d+ms$");
+    assertThat(logs.get(2)).matches("^PT3 \\| status=SUCCESS \\| time=\\d+ms$");
   }
 
   @DataProvider
@@ -398,4 +420,10 @@ public class PostProjectAnalysisTasksExecutorTest {
     return new Condition(metric, Condition.Operator.LESS_THAN.getDbValue(), "error threshold");
   }
 
+  private static PostProjectAnalysisTask newPostProjectAnalysisTask(String description) {
+    PostProjectAnalysisTask res = mock(PostProjectAnalysisTask.class);
+    when(res.getDescription()).thenReturn(description);
+    return res;
+  }
+
 }

server/sonar-ce-task-projectanalysis/src/test/java/org/sonar/ce/task/projectanalysis/webhook/WebhookPostTaskTest.java

@@ -76,6 +76,11 @@ public class WebhookPostTaskTest {
     when(configurationRepository.getConfiguration()).thenReturn(configuration);
   }
 
+  @Test
+  public void has_description() {
+    assertThat(underTest.getDescription()).isNotEmpty();
+  }
+
   @Test
   public void call_webhooks_when_no_analysis_not_qualitygate() {
     callWebHooks(null, null);

sonar-plugin-api/src/main/java/org/sonar/api/ce/posttask/PostProjectAnalysisTask.java

@@ -41,6 +41,14 @@ import org.sonar.api.ce.ComputeEngineSide;
 @ExtensionPoint
 @ComputeEngineSide
 public interface PostProjectAnalysisTask {
+
+  /**
+   * A short description or name for the task.
+   * <p>
+   * This will be used (but not limited to) in logs reporting the execution of the task.
+   */
+  String getDescription();
+
   /**
    * This method is called whenever the processing of a Project analysis has finished, whether successfully or not.
    */

sonar-plugin-api/src/test/java/org/sonar/api/ce/posttask/PostProjectAnalysisTaskTesterTest.java

@@ -144,6 +144,11 @@ public class PostProjectAnalysisTaskTesterTest {
   private static class CaptorPostProjectAnalysisTask implements PostProjectAnalysisTask {
     private ProjectAnalysis projectAnalysis;
 
+    @Override
+    public String getDescription() {
+      return "captor";
+    }
+
     @Override
     public void finished(ProjectAnalysis analysis) {
       this.projectAnalysis = analysis;