SONAR-10401 end of task log is always INFO and includes status

3 files changed, 51 insertions, 37 deletions

diff --git a/server/sonar-ce/src/main/java/org/sonar/ce/taskprocessor/CeWorkerImpl.java b/server/sonar-ce/src/main/java/org/sonar/ce/taskprocessor/CeWorkerImpl.java
index 2e5696782e5..3f609e1ca3b 100644
--- a/server/sonar-ce/src/main/java/org/sonar/ce/taskprocessor/CeWorkerImpl.java
+++ b/server/sonar-ce/src/main/java/org/sonar/ce/taskprocessor/CeWorkerImpl.java
@@ -179,20 +179,16 @@ public class CeWorkerImpl implements CeWorker {
 
   private static Profiler startActivityProfiler(CeTask task) {
     Profiler profiler = Profiler.create(LOG);
-    addContext(profiler, task);
+    addContext(profiler, task, null);
     return profiler.startInfo("Execute task");
   }
 
   private static void stopActivityProfiler(Profiler profiler, CeTask task, CeActivityDto.Status status) {
-    addContext(profiler, task);
-    if (status == CeActivityDto.Status.FAILED) {
-      profiler.stopError("Executed task");
-    } else {
-      profiler.stopInfo("Executed task");
-    }
+    addContext(profiler, task, status);
+    profiler.stopInfo("Executed task");
   }
 
-  private static void addContext(Profiler profiler, CeTask task) {
+  private static void addContext(Profiler profiler, CeTask task, @Nullable CeActivityDto.Status status) {
     profiler
       .logTimeLast(true)
       .addContext("project", task.getComponentKey())
@@ -202,5 +198,8 @@ public class CeWorkerImpl implements CeWorker {
     if (submitterLogin != null) {
       profiler.addContext("submitter", submitterLogin);
     }
+    if (status != null) {
+      profiler.addContext("status", status.name());
+    }
   }
 }
diff --git a/server/sonar-ce/src/test/java/org/sonar/ce/taskprocessor/CeWorkerImplTest.java b/server/sonar-ce/src/test/java/org/sonar/ce/taskprocessor/CeWorkerImplTest.java
index be6f45222d2..5f3643414a1 100644
--- a/server/sonar-ce/src/test/java/org/sonar/ce/taskprocessor/CeWorkerImplTest.java
+++ b/server/sonar-ce/src/test/java/org/sonar/ce/taskprocessor/CeWorkerImplTest.java
@@ -253,13 +253,12 @@ public class CeWorkerImplTest {
 
     verifyWorkerUuid();
     List<String> logs = logTester.logs(LoggerLevel.INFO);
-    assertThat(logs).hasSize(1);
+    assertThat(logs).hasSize(2);
     assertThat(logs.get(0)).doesNotContain(" | submitter=");
+    assertThat(logs.get(1)).doesNotContain(" | submitter=");
     logs = logTester.logs(LoggerLevel.ERROR);
-    assertThat(logs).hasSize(2);
-    for (int i = 0; i < 2; i++) {
-      assertThat(logs.get(i)).doesNotContain(" | submitter=");
-    }
+    assertThat(logs).hasSize(1);
+    assertThat(logs.iterator().next()).doesNotContain(" | submitter=");
     assertThat(logTester.logs(LoggerLevel.DEBUG)).isEmpty();
   }
 
@@ -274,7 +273,7 @@ public class CeWorkerImplTest {
     List<String> logs = logTester.logs(LoggerLevel.INFO);
     assertThat(logs).hasSize(2);
     assertThat(logs.get(0)).contains(" | submitter=FooBar");
-    assertThat(logs.get(1)).contains(" | submitter=FooBar | time=");
+    assertThat(logs.get(1)).contains(" | submitter=FooBar | status=SUCCESS | time=");
     assertThat(logTester.logs(LoggerLevel.ERROR)).isEmpty();
     assertThat(logTester.logs(LoggerLevel.DEBUG)).isEmpty();
   }
@@ -290,12 +289,12 @@ public class CeWorkerImplTest {
 
     verifyWorkerUuid();
     List<String> logs = logTester.logs(LoggerLevel.INFO);
-    assertThat(logs).hasSize(1);
-    assertThat(logs.iterator().next()).contains(" | submitter=FooBar");
-    logs = logTester.logs(LoggerLevel.ERROR);
     assertThat(logs).hasSize(2);
+    assertThat(logs.get(0)).contains(" | submitter=FooBar");
+    assertThat(logs.get(1)).contains(" | submitter=FooBar | status=FAILED | time=");
+    logs = logTester.logs(LoggerLevel.ERROR);
+    assertThat(logs).hasSize(1);
     assertThat(logs.get(0)).isEqualTo("Failed to execute task " + ceTask.getUuid());
-    assertThat(logs.get(1)).contains(" | submitter=FooBar | time=");
   }
 
   @Test
@@ -311,7 +310,7 @@ public class CeWorkerImplTest {
     List<String> logs = logTester.logs(LoggerLevel.INFO);
     assertThat(logs).hasSize(2);
     assertThat(logs.get(0)).contains(" | submitter=FooBar");
-    assertThat(logs.get(1)).contains(" | submitter=FooBar | time=");
+    assertThat(logs.get(1)).contains(" | submitter=FooBar | status=SUCCESS | time=");
     assertThat(logTester.logs(LoggerLevel.ERROR)).isEmpty();
     assertThat(logTester.logs(LoggerLevel.DEBUG)).isEmpty();
   }
@@ -329,12 +328,12 @@ public class CeWorkerImplTest {
 
     verifyWorkerUuid();
     List<String> logs = logTester.logs(LoggerLevel.INFO);
-    assertThat(logs).hasSize(1);
-    assertThat(logs.iterator().next()).contains(" | submitter=FooBar");
-    logs = logTester.logs(LoggerLevel.ERROR);
     assertThat(logs).hasSize(2);
-    assertThat(logs.get(0)).isEqualTo("Failed to execute task " + ceTask.getUuid());
-    assertThat(logs.get(1)).contains(" | submitter=FooBar | time=");
+    assertThat(logs.get(0)).contains(" | submitter=FooBar");
+    assertThat(logs.get(1)).contains(" | submitter=FooBar | status=FAILED | time=");
+    logs = logTester.logs(LoggerLevel.ERROR);
+    assertThat(logs).hasSize(1);
+    assertThat(logs.iterator().next()).isEqualTo("Failed to execute task " + ceTask.getUuid());
     assertThat(logTester.logs(LoggerLevel.DEBUG)).isEmpty();
   }
 
@@ -405,10 +404,13 @@ public class CeWorkerImplTest {
 
     underTest.call();
 
-    List<String> logs = logTester.logs(LoggerLevel.ERROR);
+    List<String> logs = logTester.logs(LoggerLevel.INFO);
     assertThat(logs).hasSize(2);
-    assertThat(logs.get(0)).isEqualTo("Failed to execute task " + ceTask.getUuid());
-    assertThat(logs.get(1)).contains(" | submitter=FooBar | time=");
+    assertThat(logs.get(0)).contains(" | submitter=FooBar");
+    assertThat(logs.get(1)).contains(" | submitter=FooBar | status=FAILED | time=");
+    logs = logTester.logs(LoggerLevel.ERROR);
+    assertThat(logs).hasSize(1);
+    assertThat(logs.iterator().next()).isEqualTo("Failed to execute task " + ceTask.getUuid());
   }
 
   @Test
@@ -420,9 +422,11 @@ public class CeWorkerImplTest {
 
     underTest.call();
 
-    List<String> logs = logTester.logs(LoggerLevel.ERROR);
-    assertThat(logs).hasSize(1);
-    assertThat(logs.get(0)).contains(" | submitter=FooBar | time=");
+    List<String> logs = logTester.logs(LoggerLevel.INFO);
+    assertThat(logs).hasSize(2);
+    assertThat(logs.get(1)).contains(" | submitter=FooBar");
+    assertThat(logs.get(1)).contains(" | submitter=FooBar | status=FAILED | time=");
+    assertThat(logTester.logs(LoggerLevel.ERROR)).isEmpty();
   }
 
   @Test
@@ -447,11 +451,14 @@ public class CeWorkerImplTest {
 
     underTest.call();
 
-    List<String> logs = logTester.logs(LoggerLevel.ERROR);
-    assertThat(logs).hasSize(3);
+    List<String> logs = logTester.logs(LoggerLevel.INFO);
+    assertThat(logs).hasSize(2);
+    assertThat(logs.get(0)).contains(" | submitter=FooBar");
+    assertThat(logs.get(1)).contains(" | submitter=FooBar | status=FAILED | time=");
+    logs = logTester.logs(LoggerLevel.ERROR);
+    assertThat(logs).hasSize(2);
     assertThat(logs.get(0)).isEqualTo("Failed to execute task " + ceTask.getUuid());
     assertThat(logs.get(1)).isEqualTo("Failed to finalize task with uuid '" + ceTask.getUuid() + "' and persist its state to db");
-    assertThat(logs.get(2)).contains(" | submitter=FooBar | time=");
   }
 
   @Test
@@ -464,11 +471,14 @@ public class CeWorkerImplTest {
 
     underTest.call();
 
-    List<String> logs = logTester.logs(LoggerLevel.ERROR);
+    List<String> logs = logTester.logs(LoggerLevel.INFO);
     assertThat(logs).hasSize(2);
+    assertThat(logs.get(0)).contains(" | submitter=FooBar");
+    assertThat(logs.get(1)).contains(" | submitter=FooBar | status=FAILED | time=");
+    logs = logTester.logs(LoggerLevel.ERROR);
+    assertThat(logs).hasSize(1);
     assertThat(logs.get(0)).isEqualTo("Failed to finalize task with uuid '" + ceTask.getUuid() + "' and persist its state to db. " +
       "Task failed with MessageException \"" + ex.getMessage() + "\"");
-    assertThat(logs.get(1)).contains(" | submitter=FooBar | time=");
   }
 
   private Thread createThreadNameVerifyingThread(String threadName) {
diff --git a/tests/src/test/java/org/sonarqube/tests/ce/CeShutdownTest.java b/tests/src/test/java/org/sonarqube/tests/ce/CeShutdownTest.java
index 1193f9e1008..62dabd40247 100644
--- a/tests/src/test/java/org/sonarqube/tests/ce/CeShutdownTest.java
+++ b/tests/src/test/java/org/sonarqube/tests/ce/CeShutdownTest.java
@@ -22,7 +22,6 @@ package org.sonarqube.tests.ce;
 import com.sonar.orchestrator.Orchestrator;
 import com.sonar.orchestrator.build.SonarScanner;
 import java.io.File;
-import java.io.IOException;
 import java.util.regex.Pattern;
 import org.apache.commons.io.FileUtils;
 import org.junit.Rule;
@@ -70,6 +69,7 @@ public class CeShutdownTest {
         ce.resumeTask();
         watch.waitForLog();
         assertThat(ce.hasTaskFinishedSuccessfully()).isTrue();
+        assertThat(ce.hasTaskFinishedInFailure()).isFalse();
         assertThat(ce.hasErrorLogs()).isFalse();
       }
     }
@@ -97,6 +97,7 @@ public class CeShutdownTest {
       try (LogsTailer.Watch watch = ce.logs().watch("Process [ce] is stopped")) {
         watch.waitForLog();
         assertThat(ce.hasTaskFinishedSuccessfully()).isFalse();
+        assertThat(ce.hasTaskFinishedInFailure()).isTrue();
         assertThat(ce.hasErrorLogs()).isTrue();
       }
     }
@@ -146,7 +147,11 @@ public class CeShutdownTest {
     }
 
     boolean hasTaskFinishedSuccessfully() {
-      return content.hasLineMatching(Pattern.compile(".* INFO .*Executed task \\| project=foo \\| type=REPORT.*"));
+      return content.hasLineMatching(Pattern.compile(".* INFO .*Executed task \\| project=foo \\| type=REPORT.*\\| status=SUCCESS.*"));
+    }
+
+    boolean hasTaskFinishedInFailure() {
+      return content.hasLineMatching(Pattern.compile(".* INFO .*Executed task \\| project=foo \\| type=REPORT.*\\| status=FAILED.*"));
     }
 
     boolean hasErrorLogs() {