[JENKINS-58102] GlobalAnnotator does not annotate lines that are part of a multi-line color sequence

pom.xml

@@ -68,7 +68,7 @@
   <properties>
     <revision>1.10</revision>
     <changelist>-SNAPSHOT</changelist>
-    <jenkins.version>2.121.1</jenkins.version>
+    <jenkins.version>2.150.3</jenkins.version>
     <java.level>8</java.level>
     <useBeta>true</useBeta>
   </properties>
@@ -151,12 +151,24 @@
       <version>2.4.6</version>
       <scope>test</scope>
     </dependency>
+    <dependency>
+      <groupId>org.jenkins-ci.plugins</groupId>
+      <artifactId>ansicolor</artifactId>
+      <version>0.6.2</version>
+      <scope>test</scope>
+    </dependency>
     <dependency>
       <groupId>org.jenkins-ci.plugins.workflow</groupId>
       <artifactId>workflow-job</artifactId>
       <version>2.26</version>
       <scope>test</scope>
     </dependency>
+    <dependency>
+      <groupId>org.jenkins-ci.plugins.workflow</groupId>
+      <artifactId>workflow-basic-steps</artifactId>
+      <version>2.12</version>
+      <scope>test</scope>
+    </dependency>
     <dependency>
       <groupId>org.jenkins-ci.plugins.workflow</groupId>
       <artifactId>workflow-cps</artifactId>

src/main/java/hudson/plugins/timestamper/pipeline/GlobalAnnotator.java

@@ -77,11 +77,14 @@ public ConsoleAnnotator<Object> annotate(Object context, MarkupText text) {
         }
         long buildStartTime = build.getStartTimeInMillis();
         String html = text.toString(true);
-        int start;
-        if (html.startsWith("<span class=\"pipeline-new-node\" ")) { // cf. LogStorage.startStep
-            start = html.indexOf('>') + 1;
-        } else {
-            start = 0;
+        int start = 0;
+        // cf. LogStorage.startStep
+        if (html.startsWith("<span class=\"pipeline-new-node\" ", start)) {
+            start = html.indexOf('>', start) + 1;
+        }
+        // cf. AnsiHtmlOutputStream.setForegroundColor
+        if (html.startsWith("<span style=\"color", start)) {
+            start = html.indexOf('>', start) + 1;
         }
         if (html.startsWith("[", start)) {
             int end = html.indexOf(']', start);

src/test/java/hudson/plugins/timestamper/TimestampNoteTest.java

@@ -33,6 +33,7 @@
 
 import org.apache.commons.lang.SerializationUtils;
 import org.apache.commons.lang.builder.ToStringBuilder;
+import org.junit.After;
 import org.junit.Before;
 import org.junit.Test;
 import org.junit.runner.RunWith;
@@ -64,6 +65,8 @@ public class TimestampNoteTest {
 
   private static final long TIME = 3;
 
+  private Supplier<TimestampFormat> originalSupplier;
+
   /** @return the test cases */
   @Parameters(name = "{0}, {1}")
   public static Iterable<Object[]> data() {
@@ -116,6 +119,7 @@ private static TimestampNote note(Long elapsedMillis, long millisSinceEpoch) {
   public void setUp() throws Exception {
     MockitoAnnotations.initMocks(this);
 
+    originalSupplier = Whitebox.getInternalState(TimestampFormatProvider.class, Supplier.class);
     Whitebox.setInternalState(
         TimestampFormatProvider.class,
         new Supplier<TimestampFormat>() {
@@ -126,6 +130,11 @@ public TimestampFormat get() {
         });
   }
 
+  @After
+  public void tearDown() {
+    Whitebox.setInternalState(TimestampFormatProvider.class, Supplier.class, originalSupplier);
+  }
+
   /** */
   @Test
   public void testGetTimestamp() {

src/test/java/hudson/plugins/timestamper/annotator/TimestampAnnotatorTest.java

@@ -181,17 +181,24 @@ private List<Timestamp> writeTimestamps(int count) throws Exception {
   private List<Timestamp> annotate() throws Exception {
     ConsoleLogParser logParser = new MockConsoleLogParser();
     ConsoleAnnotator annotator = new TimestampAnnotator(logParser);
+    Supplier<TimestampFormat> originalSupplier =
+        Whitebox.getInternalState(TimestampFormatProvider.class, Supplier.class);
+
     captureFormattedTimestamps();
-    int iterations = 0;
-    while (annotator != null) {
-      if (serialize) {
-        annotator = (ConsoleAnnotator) SerializationUtils.clone(annotator);
-      }
-      annotator = annotator.annotate(build, mock(MarkupText.class));
-      iterations++;
-      if (iterations > 100) {
-        throw new AssertionError("annotator is not terminating");
+    try {
+      int iterations = 0;
+      while (annotator != null) {
+        if (serialize) {
+          annotator = (ConsoleAnnotator) SerializationUtils.clone(annotator);
+        }
+        annotator = annotator.annotate(build, mock(MarkupText.class));
+        iterations++;
+        if (iterations > 100) {
+          throw new AssertionError("annotator is not terminating");
+        }
       }
+    } finally {
+      Whitebox.setInternalState(TimestampFormatProvider.class, Supplier.class, originalSupplier);
     }
     return capturedTimestamps;
   }

src/test/java/hudson/plugins/timestamper/pipeline/PipelineTest.java

@@ -0,0 +1,143 @@
+package hudson.plugins.timestamper.pipeline;
+
+import static org.junit.Assert.assertEquals;
+import static org.junit.Assert.assertNotNull;
+import static org.junit.Assert.assertTrue;
+
+import com.gargoylesoftware.htmlunit.WebClientUtil;
+import com.gargoylesoftware.htmlunit.html.HtmlPage;
+import com.gargoylesoftware.htmlunit.html.HtmlPreformattedText;
+import com.gargoylesoftware.htmlunit.html.HtmlSpan;
+import hudson.plugins.timestamper.TimestamperConfig;
+import java.io.BufferedReader;
+import java.io.StringReader;
+import java.time.ZonedDateTime;
+import java.util.ArrayList;
+import java.util.List;
+import java.util.stream.Collectors;
+import org.jenkinsci.plugins.workflow.cps.CpsFlowDefinition;
+import org.jenkinsci.plugins.workflow.job.WorkflowJob;
+import org.jenkinsci.plugins.workflow.job.WorkflowRun;
+import org.junit.After;
+import org.junit.Before;
+import org.junit.Rule;
+import org.junit.Test;
+import org.jvnet.hudson.test.JenkinsRule;
+
+public class PipelineTest {
+
+    private boolean originalAllPipelines;
+
+    @Rule public JenkinsRule r = new JenkinsRule();
+
+    @Before
+    public void setAllPipelines() {
+        TimestamperConfig config = TimestamperConfig.get();
+        originalAllPipelines = config.isAllPipelines();
+        config.setAllPipelines(true);
+    }
+
+    @After
+    public void restoreAllPipelines() {
+        TimestamperConfig config = TimestamperConfig.get();
+        config.setAllPipelines(originalAllPipelines);
+    }
+
+    @Test
+    public void globalDecoratorAnnotator() throws Exception {
+        WorkflowJob project = r.createProject(WorkflowJob.class);
+        project.setDefinition(
+                new CpsFlowDefinition(
+                        "node {\n"
+                                + "  ansiColor('xterm') {\n"
+                                + "    echo 'foo'\n"
+                                + "    echo \"\\u001B[31mBeginning multi-line color\"\n"
+                                + "    echo \"More color\"\n"
+                                + "    echo \"Ending multi-line color\\u001B[39m\"\n"
+                                + "  }\n"
+                                + "}",
+                        true));
+        WorkflowRun build = r.buildAndAssertSuccess(project);
+        r.assertLogContains("foo", build);
+        r.assertLogContains("Beginning multi-line color", build);
+        r.assertLogContains("More color", build);
+        r.assertLogContains("Ending multi-line color", build);
+
+        /*
+         * Ensure that each line of the console log is decorated with a valid timestamp decoration.
+         * While doing so, save the raw timestamps for later comparison with the annotated console
+         * output.
+         */
+        List<String> rawTimestamps = new ArrayList<>();
+        for (String line : build.getLog(Integer.MAX_VALUE)) {
+            assertTrue(line, line.startsWith("["));
+            int end = line.indexOf(']');
+            assertEquals(line, 25, end);
+            assertNotNull(
+                    line, ZonedDateTime.parse(line.substring(1, end), GlobalDecorator.UTC_MILLIS));
+
+            rawTimestamps.add(line.substring(0, 26));
+        }
+
+        // Fetch the annotated console output.
+        HtmlPage page = r.createWebClient().getPage(build, "consoleFull");
+        WebClientUtil.waitForJSExec(page.getWebClient());
+        HtmlPreformattedText consoleOutput = page.getFirstByXPath("//pre[@class='console-output']");
+        String consoleText = consoleOutput.asText();
+
+        /*
+         * Ensure that each line of the console output is annotated with a timestamp and a raw
+         * timestamp. While doing so, save the raw timestamps for later comparison with the
+         * decorated console log.
+         */
+        List<String> annotatedLines =
+                new BufferedReader(new StringReader(consoleText))
+                        .lines()
+                        .collect(Collectors.toList());
+
+        List<String> annotatedTimestamps =
+                getTimestamps(consoleOutput, "//span[@class='timestamp']");
+        assertEquals(consoleText, annotatedLines.size(), annotatedTimestamps.size());
+
+        List<String> annotatedRawTimestamps =
+                getTimestamps(consoleOutput, "//span[contains(@style, 'display: none')]");
+        assertEquals(consoleText, annotatedLines.size(), annotatedRawTimestamps.size());
+
+        for (int i = 0; i < annotatedLines.size(); i++) {
+            String annotatedLine = annotatedLines.get(i);
+            String prefix = annotatedTimestamps.get(i) + annotatedRawTimestamps.get(i) + ' ';
+            assertTrue(
+                    String.format("annotatedLine: '%s', prefix: '%s'", annotatedLine, prefix),
+                    annotatedLine.startsWith(prefix));
+
+            /*
+             * The annotated console output contains "Terminated" lines which don't appear in the
+             * decorated console log. In order to do the raw timestamp comparison below, we ignore
+             * such lines.
+             */
+            if (annotatedLine.substring(prefix.length()).equals("Terminated")) {
+                annotatedTimestamps.remove(i);
+                annotatedRawTimestamps.remove(i);
+                annotatedLines.remove(i);
+            }
+        }
+
+        /*
+         * Ensure that the raw timestamps were correctly propagated from the decorated console log
+         * to the annotated console output.
+         */
+        assertEquals(rawTimestamps, annotatedRawTimestamps);
+    }
+
+    private static List<String> getTimestamps(
+            HtmlPreformattedText consoleOutput, String xpathExpr) {
+        List<String> timestamps = new ArrayList<>();
+
+        List<HtmlSpan> nodes = consoleOutput.getByXPath(xpathExpr);
+        for (HtmlSpan node : nodes) {
+            timestamps.add(node.getTextContent());
+        }
+
+        return timestamps;
+    }
+}