Repository: jenkinsci/ansicolor-plugin (java)

Issue:
Raw escape sequences in output while refreshing a long running build
There's still a situation where it's not working correctly so I made up a somewhat contrived pipeline script.

```groovy
pipeline {
  agent any

  options {
    ansiColor('xterm')
  }

  stages {
    stage('Run') {
      steps {
          echo '\033[32mcolored output\033[0m'
sh label: 'colors', script: '''echo start
for c in {30..37}; 
do
  printf "Time for $c\\n"
  sleep 3
  echo -e "\\e[31mHello World\\e[0m"
  echo -e "\\e[${c}m Loop $c \\e[0m"
  printf '\\033[32mcolored output\\033[0m\\n'
  printf "\\033[${c}mcolored output\\033[0m\\n" 
  for i in {000..199}
  do 
    printf "\\033[${c}mI\\\'m filler $i taking up a bunch of log space ####################################################################################\\033[0m\\n" 
  done
  echo next
done'''
    
    
      }
    }
  }
}
```

The problem for me now is when Jenkins truncates the output when it gets too long. 
After starting that pipeline mash refresh on the console output view every ~3 seconds. It's looping through colors 30 to 37 and at about 33 (refresh when it's on green) refreshing loses the color. I suspect it's hitting a case were an escape sequence is getting split by the console getting truncated and whatever is doing the parsing decides not to try past the invalid input but just a guess.
___
![Peek 2020-08-05 10-40 ansiColor](https://user-images.githubusercontent.com/5008161/89433584-21807b80-d708-11ea-8bb5-525ec9caaca0.gif)
Example where I hit refresh on the green step (there colors stop working) and then after it finishes (color works again).

Versions:
```
Jenkins 2.235.1
ansicolor 0.7.2
```

_Originally posted by @chder in https://github.com/jenkinsci/ansicolor-plugin/issues/193#issuecomment-669268756_

Pull request description:
Render logs correctly for long running jobs which generate lots of logs
Fixes #200 
All is pretty much described in the issue.
The PR adds a way for checking the currently active color map name in the currently running job run.

Patch:
diff --git a/CHANGELOG.md b/CHANGELOG.md
index 7b3928d..ecbc1d4 100644
--- a/CHANGELOG.md
+++ b/CHANGELOG.md
@@ -1,6 +1,7 @@
 0.7.3 (Next)
 ============
 
+* [#202](https://github.com/jenkinsci/ansicolor-plugin/pull/202): Render logs correctly for long running jobs which generate lots of output - [@tszmytka](https://github.com/tszmytka).
 * Your contribution here.
 
 
diff --git a/pom.xml b/pom.xml
index f8848ee..6caa6b6 100644
--- a/pom.xml
+++ b/pom.xml
@@ -93,6 +93,18 @@
       <version>3.16.1</version>
       <scope>test</scope>
     </dependency>
+    <dependency>
+      <groupId>org.awaitility</groupId>
+      <artifactId>awaitility</artifactId>
+      <version>4.0.3</version>
+      <scope>test</scope>
+      <exclusions>
+        <exclusion>
+          <groupId>org.hamcrest</groupId>
+          <artifactId>hamcrest</artifactId>
+        </exclusion>
+      </exclusions>
+    </dependency>
 
   </dependencies>
   <dependencyManagement>
diff --git a/src/main/java/hudson/plugins/ansicolor/AnsiColorBuildWrapper.java b/src/main/java/hudson/plugins/ansicolor/AnsiColorBuildWrapper.java
index d478a1f..af4babd 100644
--- a/src/main/java/hudson/plugins/ansicolor/AnsiColorBuildWrapper.java
+++ b/src/main/java/hudson/plugins/ansicolor/AnsiColorBuildWrapper.java
@@ -64,6 +64,7 @@ public final class AnsiColorBuildWrapper extends SimpleBuildWrapper implements S
 
     /**
      * Create a new {@link AnsiColorBuildWrapper}.
+     * @param colorMapName Name of the color map to use
      */
     @DataBoundConstructor
     public AnsiColorBuildWrapper(String colorMapName) {
diff --git a/src/main/java/hudson/plugins/ansicolor/AnsiColorConsoleLogFilter.java b/src/main/java/hudson/plugins/ansicolor/AnsiColorConsoleLogFilter.java
index 4e48859..3a81241 100644
--- a/src/main/java/hudson/plugins/ansicolor/AnsiColorConsoleLogFilter.java
+++ b/src/main/java/hudson/plugins/ansicolor/AnsiColorConsoleLogFilter.java
@@ -24,7 +24,7 @@ public final class AnsiColorConsoleLogFilter extends ConsoleLogFilter implements
 
     private static final long serialVersionUID = 1L;
 
-    private static final Logger LOG = Logger.getLogger(AnsiColorConsoleLogFilter.class.getName());
+    private static final Logger LOGGER = Logger.getLogger(AnsiColorConsoleLogFilter.class.getName());
 
     private AnsiColorMap colorMap;
     private final Map<String, byte[]> notes;
@@ -46,14 +46,14 @@ public final class AnsiColorConsoleLogFilter extends ConsoleLogFilter implements
         pregenerateNote(AnsiAttributeElement.framed());
         pregenerateNote(AnsiAttributeElement.overline());
         // TODO other cases, and other methods
-        LOG.log(Level.FINE, "Notes pregenerated for {0}", notes.keySet());
+        LOGGER.log(Level.FINE, "Notes pregenerated for {0}", notes.keySet());
     }
-    
+
     private void pregenerateNote(AnsiAttributeElement element) {
         element.emitOpen(html -> pregenerateNote(html));
         element.emitClose(html -> pregenerateNote(html));
     }
-    
+
     private void pregenerateNote(String html) {
         if (!notes.containsKey(html)) {
             JenkinsJVM.checkJenkinsJVM();
@@ -91,7 +91,7 @@ public final class AnsiColorConsoleLogFilter extends ConsoleLogFilter implements
                         new SimpleHtmlNote(html).encodeTo(logger);
                     }
                 } catch (IOException e) {
-                    LOG.log(Level.WARNING, "Failed to add HTML markup '" + html + "'", e);
+                    LOGGER.log(Level.WARNING, "Failed to add HTML markup '" + html + "'", e);
                 }
             }
         });
diff --git a/src/main/java/hudson/plugins/ansicolor/AnsiColorStep.java b/src/main/java/hudson/plugins/ansicolor/AnsiColorStep.java
index fb53bd5..75eb537 100644
--- a/src/main/java/hudson/plugins/ansicolor/AnsiColorStep.java
+++ b/src/main/java/hudson/plugins/ansicolor/AnsiColorStep.java
@@ -72,6 +72,7 @@ public class AnsiColorStep extends Step {
         @Override
         public boolean start() throws Exception {
             StepContext context = getContext();
+
             EnvironmentExpander currentEnvironment = context.get(EnvironmentExpander.class);
             EnvironmentExpander terminalEnvironment = EnvironmentExpander.constant(Collections.singletonMap("TERM", colorMapName));
             context.newBodyInvoker()
@@ -157,6 +158,12 @@ public class AnsiColorStep extends Step {
                     run.addAction(action);
                     taskListener.annotate(new ActionNote(action));
                     ensureRendering(taskListener);
+                    final ColorizedAction currentAction = new ColorizedAction(action.getColorMapName(), ColorizedAction.Command.CURRENT);
+                    if (action.getCommand().equals(ColorizedAction.Command.START)) {
+                        run.addAction(currentAction);
+                    } else {
+                        run.removeAction(currentAction);
+                    }
                 }
             } catch (IOException | InterruptedException e) {
                 LOGGER.log(Level.WARNING, "Could not annotate. Ansicolor plugin will not work correctly.", e);
diff --git a/src/main/java/hudson/plugins/ansicolor/ColorConsoleAnnotator.java b/src/main/java/hudson/plugins/ansicolor/ColorConsoleAnnotator.java
index aaf7b9a..133a4a6 100644
--- a/src/main/java/hudson/plugins/ansicolor/ColorConsoleAnnotator.java
+++ b/src/main/java/hudson/plugins/ansicolor/ColorConsoleAnnotator.java
@@ -88,6 +88,7 @@ final class ColorConsoleAnnotator extends ConsoleAnnotator<Object> {
             : ColorizedAction.parseAction(text, run);
         switch (colorizedAction.getCommand()) {
             case START:
+            case CURRENT:
                 colorMapName = colorizedAction.getColorMapName();
                 break;
             case STOP:
diff --git a/src/main/java/hudson/plugins/ansicolor/action/ColorizedAction.java b/src/main/java/hudson/plugins/ansicolor/action/ColorizedAction.java
index a6e4969..6a08cfd 100644
--- a/src/main/java/hudson/plugins/ansicolor/action/ColorizedAction.java
+++ b/src/main/java/hudson/plugins/ansicolor/action/ColorizedAction.java
@@ -29,7 +29,9 @@ import hudson.model.InvisibleAction;
 import hudson.model.Run;
 import hudson.plugins.ansicolor.AnsiColorMap;
 
+import java.util.Optional;
 import java.util.UUID;
+import java.util.logging.Logger;
 
 import static hudson.plugins.ansicolor.action.ActionNote.TAG_ACTION_BEGIN;
 
@@ -37,6 +39,7 @@ import static hudson.plugins.ansicolor.action.ActionNote.TAG_ACTION_BEGIN;
  * Action for issuing commands to ColorConsoleAnnotator
  */
 public class ColorizedAction extends InvisibleAction {
+    private static final Logger LOGGER = Logger.getLogger(ColorizedAction.class.getName());
     private static final String TAG_PIPELINE_INTERNAL = "<span class=\"pipeline-new-node\"";
     static final ColorizedAction CONTINUE = new ColorizedAction("", Command.CONTINUE);
     static final ColorizedAction IGNORE = new ColorizedAction("", Command.IGNORE);
@@ -51,7 +54,12 @@ public class ColorizedAction extends InvisibleAction {
         START,
         STOP,
         CONTINUE,
-        IGNORE
+        IGNORE,
+
+        /**
+         * The running job's current action containing current color map name
+         */
+        CURRENT
     }
 
     public ColorizedAction(String colorMapName, Command command) {
@@ -87,7 +95,20 @@ public class ColorizedAction extends InvisibleAction {
             final String id = line.substring(from, to);
             return run.getActions(ColorizedAction.class).stream().filter(a -> id.equals(a.getId())).findAny().orElse(CONTINUE);
         }
-        return line.contains(TAG_PIPELINE_INTERNAL) ? IGNORE : CONTINUE;
+        if (line.contains(TAG_PIPELINE_INTERNAL)) {
+            return IGNORE;
+        }
+        final boolean isBuilding = run.isBuilding();
+        LOGGER.fine("Run is building: " + isBuilding);
+        if (isBuilding) {
+            Optional<ColorizedAction> currentAction = run.getActions(ColorizedAction.class).stream()
+                .filter(a -> Command.CURRENT.equals(a.getCommand()))
+                .findFirst();
+            if (currentAction.isPresent()) {
+                return currentAction.get();
+            }
+        }
+        return CONTINUE;
     }
 
     public static ColorizedAction parseAction(String lineContent, long lineNo, Run<?, ?> run, LineIdentifier lineIdentifier) {


Test patch:
diff --git a/src/test/java/hudson/plugins/ansicolor/AnsiColorStepTest.java b/src/test/java/hudson/plugins/ansicolor/AnsiColorStepTest.java
index 00858f0..69b0b55 100644
--- a/src/test/java/hudson/plugins/ansicolor/AnsiColorStepTest.java
+++ b/src/test/java/hudson/plugins/ansicolor/AnsiColorStepTest.java
@@ -1,5 +1,6 @@
 package hudson.plugins.ansicolor;
 
+import hudson.model.queue.QueueTaskFuture;
 import org.jenkinsci.plugins.workflow.cps.CpsFlowDefinition;
 import org.jenkinsci.plugins.workflow.job.WorkflowJob;
 import org.jenkinsci.plugins.workflow.job.WorkflowRun;
@@ -13,13 +14,14 @@ import org.jvnet.hudson.test.LoggerRule;
 import org.jvnet.hudson.test.RestartableJenkinsRule;
 
 import java.io.StringWriter;
+import java.time.Duration;
 import java.util.Arrays;
 import java.util.Collection;
 import java.util.logging.Level;
 
 import static org.assertj.core.api.Assertions.assertThat;
-import static org.junit.Assert.assertEquals;
-import static org.junit.Assert.assertTrue;
+import static org.awaitility.Awaitility.await;
+import static org.junit.Assert.*;
 
 public class AnsiColorStepTest {
 
@@ -136,6 +138,35 @@ public class AnsiColorStepTest {
         );
     }
 
+    @Issue("200")
+    @Test
+    public void canRenderLongOutputWhileBuildStillRunning() {
+        story.addStep(new Statement() {
+
+            @Override
+            public void evaluate() throws Throwable {
+                final String a1k = JenkinsTestSupport.repeat("a", 1024);
+                final String script = "ansiColor('xterm') {\n" +
+                    "for (i = 0; i < 1000; i++) {" +
+                    "echo '\033[32m" + a1k + "\033[0m'\n" +
+                    "}" +
+                    "}";
+                final WorkflowJob project = story.j.jenkins.createProject(WorkflowJob.class, "canRenderLongOutputWhileBuildStillRunning");
+                project.setDefinition(new CpsFlowDefinition(script, true));
+                QueueTaskFuture<WorkflowRun> runFuture = project.scheduleBuild2(0);
+                assertNotNull(runFuture);
+                final WorkflowRun lastBuild = runFuture.waitForStart();
+                await().pollInterval(Duration.ofSeconds(5)).atMost(Duration.ofSeconds(150)).until(() -> {
+                    StringWriter writer = new StringWriter();
+                    final int skipInitialStartAction = 3000;
+                    assertTrue(lastBuild.getLogText().writeHtmlTo(skipInitialStartAction, writer) > 0);
+                    final String html = writer.toString().replaceAll("<!--.+?-->", "");
+                    return !runFuture.isDone() && html.contains("<span style=\"color: #00CD00;\">" + a1k + "</span>") && !html.contains("\033[32m");
+                });
+            }
+        });
+    }
+
     private void assertOutputOnRunningPipeline(Collection<String> expectedOutput, Collection<String> notExpectedOutput, String pipelineScript) {
         story.addStep(new Statement() {
 
diff --git a/src/test/java/hudson/plugins/ansicolor/ColorConsoleAnnotatorTest.java b/src/test/java/hudson/plugins/ansicolor/ColorConsoleAnnotatorTest.java
index 6596e0e..63db219 100644
--- a/src/test/java/hudson/plugins/ansicolor/ColorConsoleAnnotatorTest.java
+++ b/src/test/java/hudson/plugins/ansicolor/ColorConsoleAnnotatorTest.java
@@ -3,6 +3,7 @@ package hudson.plugins.ansicolor;
 import jenkins.model.Jenkins;
 import org.jenkinsci.plugins.workflow.cps.CpsFlowDefinition;
 import org.jenkinsci.plugins.workflow.job.WorkflowJob;
+import org.jenkinsci.plugins.workflow.job.WorkflowRun;
 import org.junit.ClassRule;
 import org.junit.Rule;
 import org.junit.Test;
@@ -11,9 +12,11 @@ import org.jvnet.hudson.test.BuildWatcher;
 import org.jvnet.hudson.test.LoggerRule;
 import org.jvnet.hudson.test.RestartableJenkinsRule;
 
+import java.io.File;
 import java.io.StringWriter;
 import java.util.logging.Level;
 
+import static org.assertj.core.api.Assertions.assertThat;
 import static org.junit.Assert.assertFalse;
 import static org.junit.Assert.assertTrue;
 
diff --git a/src/test/java/hudson/plugins/ansicolor/JenkinsTestSupport.java b/src/test/java/hudson/plugins/ansicolor/JenkinsTestSupport.java
index a67b683..0fc6259 100644
--- a/src/test/java/hudson/plugins/ansicolor/JenkinsTestSupport.java
+++ b/src/test/java/hudson/plugins/ansicolor/JenkinsTestSupport.java
@@ -45,7 +45,7 @@ public class JenkinsTestSupport {
         });
     }
 
-    protected static String repeat(String s, int times) {
+    public static String repeat(String s, int times) {
         return IntStream.range(0, times).mapToObj(i -> s).collect(Collectors.joining());
     }
 }
diff --git a/src/test/java/hudson/plugins/ansicolor/action/ColorizedActionTest.java b/src/test/java/hudson/plugins/ansicolor/action/ColorizedActionTest.java
index b62382b..817c124 100644
--- a/src/test/java/hudson/plugins/ansicolor/action/ColorizedActionTest.java
+++ b/src/test/java/hudson/plugins/ansicolor/action/ColorizedActionTest.java
@@ -25,6 +25,7 @@ public class ColorizedActionTest {
     private static final ColorizedAction ACTION_2 = new ColorizedAction("map0", ColorizedAction.Command.STOP);
     private static final ColorizedAction ACTION_3 = new ColorizedAction("map3", ColorizedAction.Command.START);
     private static final ColorizedAction ACTION_4 = new ColorizedAction("map3", ColorizedAction.Command.STOP);
+    private static final ColorizedAction ACTION_5 = new ColorizedAction("map0", ColorizedAction.Command.CURRENT);
 
     private ColorizedAction colorizedAction;
 
@@ -34,6 +35,9 @@ public class ColorizedActionTest {
     @Mock
     private FreeStyleBuild buildRunMultipleStarts;
 
+    @Mock
+    private FreeStyleBuild buildRunOneCurrent;
+
     @Before
     public void setUp() throws Exception {
         when(buildRunSingleStart.getActions(eq(ColorizedAction.class))).thenReturn(Arrays.asList(
@@ -48,6 +52,11 @@ public class ColorizedActionTest {
             ACTION_3,
             ACTION_4
         ));
+        when(buildRunOneCurrent.getActions(eq(ColorizedAction.class))).thenReturn(Arrays.asList(
+            ACTION_0,
+            ACTION_5
+        ));
+
         colorizedAction = new ColorizedAction("vga", ColorizedAction.Command.START);
     }
 
@@ -113,4 +122,25 @@ public class ColorizedActionTest {
         final ColorizedAction colorizedAction = ColorizedAction.parseAction(markupText, buildRunMultipleStarts);
         assertEquals(ColorizedAction.Command.IGNORE, colorizedAction.getCommand());
     }
+
+    @Test
+    public void canParseActionCurrentWhileBuildRunning() {
+        when(buildRunOneCurrent.isBuilding()).thenReturn(true);
+        final MarkupText markupText = new MarkupText("Log line");
+        assertEquals(ACTION_5, ColorizedAction.parseAction(markupText, buildRunOneCurrent));
+    }
+
+    @Test
+    public void wontParseActionCurrentWhileBuildNotRunning() {
+        when(buildRunOneCurrent.isBuilding()).thenReturn(false);
+        final MarkupText markupText = new MarkupText("Log line");
+        assertEquals(CONTINUE, ColorizedAction.parseAction(markupText, buildRunOneCurrent));
+    }
+
+    @Test
+    public void wontParseActionCurrentWhileBuildRunningButNoCurrentAction() {
+        when(buildRunSingleStart.isBuilding()).thenReturn(true);
+        final MarkupText markupText = new MarkupText("Log line");
+        assertEquals(CONTINUE, ColorizedAction.parseAction(markupText, buildRunSingleStart));
+    }
 }