Running together with Timestamper prevents AnsiColor 0.7.0 from working correctly, 0.6.3 ok

[alex-harvey-z3q]

Test environment

• Jenkins Version: 2.176.3
• AnsiColor Version: 0.7.0

How I installed

Showing it is installed:

I also restarted Jenkins (several times).

I have a build step that looks like this:

         wrap([$class: 'AnsiColorBuildWrapper', 'colorMapName': 'XTerm']) {
            sh "[ ${params.RUN_E2E} = true ] && (cd /src; TEMPLATE=${params.TEMPLATE} make e2e) || true"
          }

I also tried:

   options {
     ansiColor('xterm')
  }

Expected behavior

I expected coloured output from Sceptre and shUnit2.

Actual behavior

It's not coloured:

[alex-harvey-z3q]

For any tips for anything else I could try I would be most grateful!

[tszmytka]

Thanks for the report and providing detailed information. Unfortunately it is not immediately obvious what might be wrong. Could you then please:

1. Set up a job with the following pipeline. Run it and post your console output.

ansiColor('xterm') {
    echo '\033[32mHello World\033[0m'
}

2. Run your test locally, capture and post the output. I'm thinking something like:

make e2e > output.txt

[alex-harvey-z3q]

@tszmytka yeah that works

I also attached here the output file:
output.txt

Also my Jenkinsfile:
Jenkinsfile.groovy.txt

[alex-harvey-z3q]

@tszmytka Is it because I am using the Jenkinsfile Groovy plugin https://plugins.jenkins.io/workflow-cps/ ?

[tszmytka]

Basic Hello World example works which means the plugin is loaded and running.

I also attached here the output file:
output.txt

The output doesn't seem out of the ordinary.

Also my Jenkinsfile:
Jenkinsfile.groovy.txt

What plugin does the container('awscli') step come from? This is not a standard pipeline way of running docker images.

Is it because I am using the Jenkinsfile Groovy plugin https://plugins.jenkins.io/workflow-cps/ ?

I doubt it. It is used by probably all people utilizing pipelines so if there was an incompatibility with ansicolor we would have gotten a ton of bugtickets.

[joshdcox]

FWIW, AnsiColor 0.7.0 isn't working for us either. We reverted to 0.6.3, which still works works fine.

[alex-harvey-z3q]

Ok, many thanks to @joshdcox for that info. I have also confirmed that by downgrading to 0.6.3, the colouring is working fine for me.

[fishi0x01]

Same for me (downgrade to 0.6.3 works).

On 0.7.0 I have noticed that the log coloring works properly while the build is still running. When looking at logs of builds which have already finished the log coloring vanished.

[tszmytka]

I am still unable to reproduce the issue. I suspect (could be wrong) this has everything to do with jobs running on specific agents, although my local setup (with multiple agents) runs all the test cases fine.
I've prepared a simple pipeline

pipeline {
  agent {
    label "<your-agent>"
  }

  options {
    ansiColor('xterm')
  }

  stages {
    stage('Run') {
      steps {
          echo '\033[32mcolored output\033[0m'
          sh "echo -e '\\033[92;22mlightgreen and combined reset sgr \\033[0m'"
      }
    }
  }
}

@alexharv074 Would you be able to run this against your sceptre-builder agent and post results? Also, what kind of agent is run on that host? I was testing the plugin using the official inbound-agent docker image and still could not reproduce so I'm assuming you're using something else. Can you provide the name of the image?

@joshdcox and @fishi0x01 Thanks for your additional information. Could you please confirm that you are also running your jobs against a remote agent? If so could you also please run my test pipeline and post results?

[UzK98fYoE]

I have this issue/regression too (0.7.0 breaks but 0.6.3 works). In case it helps, I'm using this version of the Jenkins JNLP image. It was working fine on AnsiColor 0.6.3, until I migrated to the newer system on AnsiColor 0.7.0. That said, tszmytka's code works: I see the green output (see below).

Commit message: "try again 30"
 > /usr/bin/git rev-list --no-walk aac1fc3de5e2a4dba29379b8c3b095c3d8d1ee42 # timeout=10
[Pipeline] }
[Pipeline] // stage
[Pipeline] withEnv
[Pipeline] {
[Pipeline] ansiColor
[Pipeline] {
[Pipeline] stage
[Pipeline] { (Run)
[Pipeline] echo
colored output
[Pipeline] sh
+ echo '\033[92;22mlightgreen and combined reset sgr \033[0m'
\033[92;22mlightgreen and combined reset sgr \033[0m
[Pipeline] }
[Pipeline] // stage
[Pipeline] }
[Pipeline] // ansiColor
[Pipeline] }
[Pipeline] // withEnv
[Pipeline] }
[Pipeline] // node
[Pipeline] End of Pipeline

GitHub has been notified of this commit’s build result

Finished: SUCCESS

[tszmytka]

Another idea: Could you please temporarily restart your master with the following JVM option:

-Dorg.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep.USE_WATCHING=false

run your job again and report if this changes anything?

[reinholdfuereder]

(I am very happy with AnsiColor 0.7.0: colours are shown as expected in classic and Blue Ocean UI)

[faithlinpaul]

Doesn't work for me with version0.7.0 and Jenkins 2.235.1

[ant100]

It's not working for me either on version 0.7.0 and Jenkins 2.235.1

[eightnoneone]

Maybe small detail but I'm seeing that with truncated console output, the colors are not displayed. If I view full log, it displays correctly.

[chder]

Using the test case in #193 (comment) I see colors render on Jenkins 2.235.1.
But, if I add to the options block timestamps() it breaks.

Here's the raw log output showing a part that should be colorized run through xxd to show where the control sequences are:

$ grep --color=none lightgreen log | grep -v 'echo'
[2020-07-06T16:51:19.843Z] lightgreen and combined reset sgr 
$ grep --color=none lightgreen log | grep -v 'echo' | xxd
0000000: 5b32 3032 302d 3037 2d30 3654 3136 3a35  [2020-07-06T16:5
0000010: 313a 3139 2e38 3433 5a5d 201b 5b39 323b  1:19.843Z] .[92;
0000020: 3232 6d6c 6967 6874 6772 6565 6e20 616e  22mlightgreen an
0000030: 6420 636f 6d62 696e 6564 2072 6573 6574  d combined reset
0000040: 2073 6772 201b 5b30 6d0a                  sgr .[0m.
$

Here's a screenshot:

But even after a refresh in Jenkins, not rendering color:

Pipeline ran:

// Test pipeline from https://github.com/jenkinsci/ansicolor-plugin/issues/193#issuecomment-650812651
pipeline {
  agent any

  options {
    timestamps()
    ansiColor('xterm')
  }

  stages {
    stage('Run') {
      steps {
          echo '\033[32mcolored output\033[0m'
          sh "echo -e '\\033[92;22mlightgreen and combined reset sgr \\033[0m'"
      }
    }
  }
}

[dayer4b]

I just wanted to join the chorus of voices on this issue. 0.7.0 does not work for us. I rolled back and it works fine. Here's the test Jenkinsfile:

node {
  //timestamps
  timestamps{
    // This displays colors using the 'xterm' ansi color map.
    ansiColor('xterm') {
    stage ("Look for the colors!"){
      echo "\u001B[31mI'm Red\u001B[0m Now not"
      sleep 10
      echo "\u001B[31mI'm Red\u001B[0m Now not"
    }
    }
  }
}

With 0.6.2 this displays red for the "I'm Red" part, with 0.7.0 it prints like this:

09:28:22  �[31mI'm Red�[0m Now not

EDIT: I just wanted to add that with 0.7.0 this appeared to work fine in Blue Ocean, but we had to rollback because Blue Ocean is not usually the primary interface for our engineers.

[tszmytka]

@chder You hit the nail right on the head. Thank you a thousand times.

But, if I add to the options block timestamps() it breaks.

The timestamper-plugin is the missing piece of the puzzle I've been searching for. Adding it to the pipeline prevents any escape sequences from being correctly interpreted. I am able to reproduce it in a consistent manner and reverting back to ansicolor vansicolor-0.6.3 brings the functionality back.
In fact looking only now at the OP's "output.txt" from #193 (comment) also shows dates and times so he most likely is also using timestamper.

Quick tests on my dev setup show that while the following

options {
  timestamps()
  ansiColor('xterm')
}

breaks the escape codes,
this:

options {
  ansiColor('xterm')
  timestamps()
}

does not (in v0.7.0).
Suggest to try this as a quick work around. In the mean time I will try to find a permanent solution.

[maemile]

Hello,

Same issue here...
The workaround fix only in fully expanded in my case and not in truncated.

[tszmytka]

@maemile Let's stick to the main issue here.

The workaround fix only in fully expanded in my case and not in truncated.

Problem with rendering escape sequences on partial output is described in #185 .

[tszmytka]

The problem in this ticket is caused by the timestamper plugin decorating the logger in such a way that only lines which end with a LF character get written to the log file. Since ansicolor v0.7.0 we started annotating log lines with meta data in order to better work in situations where say, you want to use multiple color maps within one pipeline or you only want part of your output colored.

The actual fix will also need to be done in timestamper but till that happens ansicolor v0.7.1 will try to detect this situation and manually force the logger to actually print contents to the file. This will have a side effect of having an additional, empty line in the output but at least main functionality will get back to normal.

[tszmytka]

The newly released ansicolor v0.7.1 contains a method to work around timestamper swallowing up meta-data info (and thus disabling escape character recognition).

All is working fine on my dev setup but - as this was pretty hard to analyze in the wild - could any one of the reporters please review this on your system and confirm it is working for you too?
Please make sure you are using both plugins:

• ansicolor v0.7.1
• timestamper (any version)

[patricks]

I have updated to v0.7.1 but I didn't see any difference.

[08:32:19]: �[35m�[33m▸�[0m �[39;1mBuild�[0m Succeeded�[0m

[tszmytka]

How do I reproduce this? Care to provide a sample pipeline showing how you use both plugins? Also, which version of Jenkins and timestamper are you using?

…

On Wed, Jul 15, 2020, 08:33 Patrick ***@***.***> wrote: I have updated to v0.7.1 but I didn't see any difference. [08:32:19]: �[35m�[33m▸�[0m �[39;1mBuild�[0m Succeeded�[0m — You are receiving this because you were assigned. Reply to this email directly, view it on GitHub <#193 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AOQGV4KQG35BJBN3C5JLCOTR3VEURANCNFSM4N3TS2MA> .

[tszmytka]

Going through timestampers code I found it can be enabled also without explicitly setting it in the pipeline (through a global configuration).

@patricks Is this how you're using it?

[patricks]

I just exec a shell command to run a ruby script in my pipeline.

ansiColor("xterm") {
    sh "bundle exec fastlane test"
 }

[mscholze]

Colors still not rendered in declarative pipelines: Jenkins 2.235.2, AnsiColor 0.7.1, Timestamper 1.11.3. Downgrade to AnsiColor 0.6.3 looks fine.

[marslo]

my case:

• Jenkins: 2.2.245
• timestamps: 1.11.3
• ansiColor: 0.7.1

Colors cannot show up by:

ansiColor('xterm') { timestamps {
...
}}

but works in :

timestamps { ansiColor('xterm') {
...
}}

[mscholze]

@marslo It looks like scripted pipeline. But good to know. For testing I reordered the position in declarative pipeline configuration to meet your conditions ...

options {
    timestamps()
    ansiColor('xterm')
}

... but it doesn't change anything:

...
Running on ansicolortest-1-kmqt9-32xrk-33vmc in /home/jenkins/agent/workspace/ansiColorTest
[Pipeline] {
[Pipeline] timestamps
[Pipeline] {
[Pipeline] ansiColor
[Pipeline] {
[Pipeline] stage
[Pipeline] { (test)
[Pipeline] echo
07:36:42  �[31mI'm Red�[0m Now not
[Pipeline] }
[Pipeline] // stage
[Pipeline] }
[Pipeline] // ansiColor
[Pipeline] }
[Pipeline] // timestamps
[Pipeline] }
[Pipeline] // node
[Pipeline] }
[Pipeline] // podTemplate
[Pipeline] End of Pipeline
...

[dblock]

I would like to encourage someone from this thread to step up to being much more active in debugging, testing and fixing new/existing bugs. Write more unit tests. Try HEAD right now after #198 has been merged. Right now @tszmytka is doing solo work here with barely another pair of eyes on the code (I am not actively using Jenkins anymore, and am not familiar with recent versions and internals). This project needs another highly engaged programmer/co-maintainer to avoid having so many regressions.

I also want to say a huge thank you to @tszmytka for carrying this forward!

[tszmytka]

I just released v0.7.2 containing 2 important fixes that will hopefully help to sort out this issue.
I've tested the interaction between ansicolor and timestamper in all ways known to mankind and could see no problems. Here's the list of configurations I used:

1. By using pipeline-wide wrappers

options {
    timestamps()
    ansiColor('xterm')
}

and

options {
    ansiColor('xterm')
    timestamps()
}

2. By using ad-hoc steps:

ansiColor('xterm') {
    timestamps {
	
	}
}

and

timestamps {
    ansiColor('xterm')  {
	
	}
}

3. By enabling both plugins in Jenkins' global options.

A small suggestion to anyone suspecting they are suffering from this issue (as till now I can identify people reporting 3 separate issues in this thread - 2 of which fixed): Try disabling timestamper entirely (that means no timestamps in pipeline and no global Enabled for all Pipeline builds setting) and run your pipeline again. If the output is colored then you are - please comment on this thread providing details of how to reproduce what you are seeing.
But if your output is still not colored or you are not using timestamper then your issue is something else - please open up a separate ticket.

[patricks]

It looks like the latest timestamper and ansicolor updates fixed my problem. 👏

[mscholze]

I can confirm the fix 👍

successfully tested declarative pipeline on:

• jenkins 2.235.3
• ansicolor 0.7.2
• timestamper 1.11.5

[asantos-fuze]

Whatever fix was made it is now working

• jenkins 2.235.2
• ansicolor 0.7.2
• timestamper 1.11.5

[chder]

It's mostly fixed for me but there's still a situation where it's not so I made up a somewhat contrived pipeline script.

// Test pipeline for https://github.com/jenkinsci/ansicolor-plugin/issues/193
pipeline {
  agent any

  options {
    timestamps()
    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.

---

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
Timestamper 1.11.3

[julian-alarcon]

#196

[tszmytka]

@chder Thanks for a very nice pipeline. It has nothing to do with Timestamper so I moved it to a separate issue (#200).

Other than that I think it's clear to assume this issue has been fixed in v0.7.2.
Thank you to everyone who invested their time and tested various combinations.

[jjathman]

We seem to still be having problems. Our pipelines use this pattern:

options {
    timestamps()
}

// extra detailed removed

ansiColor('xterm') {
   // do work here
}

Should this use case be working?