Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Coloured logs #4573

Merged
merged 39 commits into from
Feb 12, 2024
Merged

Coloured logs #4573

merged 39 commits into from
Feb 12, 2024

Conversation

ewels
Copy link
Member

@ewels ewels commented Dec 11, 2023

To do:

  • Don't use ANSI for the header when -ansi false is set
  • Respect env var NO_COLOR
  • Try harder to auto-detect tty / ansi support and switch off automatically
  • Look into adding colour to the task label (bit in brackets at the end)
  • More testing, refine colour use
  • Try to get exact Nextflow green RGB, at least for the header

See: #3976

pditommaso commented on May 29
That's very beautiful, but not sure exist something so cool as Rich for JVM world

pditommaso commented on May 30
Phil. I think this a great opportunity to improve your Groovy skills 😆

I was never going to be able to back down from such a challenge 😆

CleanShot.2023-12-12.at.00.01.19-converted.mp4

Does a few things:

  • Truncates the start / middle of the process name (instead of the end), so we can see the end. This is usually the interesting bit.
  • Hides processes with zero tasks if there are more rows to print than available in the terminal (with a message at the end saying how many are hidden)
  • Drops the (process > ) at < 180 cols width to save horizontal space
  • Drop the % age completion at < 120 cols to save horizontal space
  • Has oodles of colour 🌈 🌟

Known limitations:

  • Code is probably terrible style
  • Some of it isn't switched off when ANSI is set to false
  • Likely some nasty ansi codes will go to log files when there isn't a tty attached, should try to auto-detect and disable
  • Probably doesn't respect NO_COLOR env variables etc.

Copy link

netlify bot commented Dec 11, 2023

Deploy Preview for nextflow-docs-staging canceled.

Name Link
🔨 Latest commit 10049b2
🔍 Latest deploy log https://app.netlify.com/sites/nextflow-docs-staging/deploys/65ca587bb940ba0008560ac5

@pditommaso
Copy link
Member

@ewels
Copy link
Member Author

ewels commented Dec 12, 2023

Wondering if we can use the isAnsiSupported() function from jline to automatically disable ANSI log output when running in a non-interactive shell 🤔

https://jline.github.io/jline2/apidocs/reference/jline/Terminal.html#isAnsiSupported()

@ewels
Copy link
Member Author

ewels commented Dec 12, 2023

Updates since the video above:

  • Percentage only green when it gets to 100%
  • Processes with zero tasks hidden if we run out of terminal
  • Switched ... with to save a couple of characters width

CleanShot 2023-12-12 at 09 25 56@2x

@bentsherman
Copy link
Member

Phil, I had an idea about how we could improve the percentage tracking. Until a process receives all the tasks it will execute, the percentage is always overestimating the true percentage. What if we show the percentage as ??? or - at first, and when a process receives the poison pill (which usually happens long before it finishes all of its tasks), the ANSI log can receive that signal and start showing the percentage

@bentsherman
Copy link
Member

I already implemented this event hook for array jobs and automatic cleanup, so just need to copy some code from there

@ewels
Copy link
Member Author

ewels commented Dec 13, 2023

@bentsherman I go back and forth on this a little. I'm not sure which is best, the current output:

[-        ] NFCORE_RNASEQ:RNASEQ:FASTQ_FASTQC_UMITOOLS_TRIMGALORE:TRIMGALORE    [ 75%] 3 of 4 ✔
[-        ] NFCORE_RNASEQ:RNASEQ:ALIGN_STAR:STAR_ALIGN                          [ 33%] 1 of 3 ✔

or what you're proposing:

[-        ] NFCORE_RNASEQ:RNASEQ:FASTQ_FASTQC_UMITOOLS_TRIMGALORE:TRIMGALORE    [ 75%] 3 of 4 ✔
[-        ] NFCORE_RNASEQ:RNASEQ:ALIGN_STAR:STAR_ALIGN                          [ ???] 1 of ? ✔

Even if the of 3 is a lie, at least you can see how many tasks are currently running there. With 1 of ? you have no idea.

I guess you could go halfway and remove the percentages and keep the of n:

[-        ] NFCORE_RNASEQ:RNASEQ:FASTQ_FASTQC_UMITOOLS_TRIMGALORE:TRIMGALORE    [ 75%] 3 of 4 ✔
[-        ] NFCORE_RNASEQ:RNASEQ:ALIGN_STAR:STAR_ALIGN                          [ ???] 1 of 3 ✔

..but I sort of feel that you're still "lying" about the proportion of tasks done. So not sure how much of an improvement it is over the current behaviour.

Am I missing something / wrong about anything here?

@bentsherman
Copy link
Member

The third option is what I'm proposing, but without the check mark:

[-        ] NFCORE_RNASEQ:RNASEQ:FASTQ_FASTQC_UMITOOLS_TRIMGALORE:TRIMGALORE    [ 75%] 3 of 4 ✔
[-        ] NFCORE_RNASEQ:RNASEQ:ALIGN_STAR:STAR_ALIGN                          [ ???] 1 of 3

The question marks in the percentage and the lack of a check mark tell you that this process hasn't received all of its tasks yet, so the true progress is unknown. I think that's reasonable

@ewels
Copy link
Member Author

ewels commented Dec 13, 2023

Ah sorry, the check mark was me manually copying and pasting stuff for the example. That's not there in the current behaviour (see above screenshots).

@bentsherman
Copy link
Member

I see, well my point is basically the same

@ewels
Copy link
Member Author

ewels commented Dec 13, 2023

Yup, agreed. I like it! Feel free to push whatever to this branch to add it 👍🏻

@bentsherman bentsherman self-requested a review December 14, 2023 14:44
@bentsherman
Copy link
Member

Okay that is done. Another idea I had related to this is to not include failed tasks in the percentage and total count. When a task fails and is retried, the percentage increases slightly (e.g. it goes from 3/4 = 75% to 4/5=80%), giving the illusion that the pipeline made progress when it didn't.

Instead, the number of failed tasks should not influence either the total or completed count, they should just be noted to the side as they already are.

@bentsherman
Copy link
Member

Here's an example process that runs 4 tasks where 1 task fails and retries:

[70/0de758] process > bar (3) [ 75%] 3 of 4, retries: 1

Then the process shows 100% when the retried task succeeds:

[70/0de758] process > bar (3) [100%] 4 of 4, retries: 1 ✔

If instead the failed task is ignored, it simply reduces the number of total tasks, allowing the process to reach 100% while still noting the number of ignored tasks:

[f2/decd6c] process > bar (4) [ 75%] 2 of 3, ignored: 1
[98/47ff99] process > bar (4) [100%] 3 of 3, ignored: 1 ✔

@pditommaso
Copy link
Member

Can we keep change in the logic separated from the colouring?

@bentsherman
Copy link
Member

You mean like a separate PR? Sure

@pditommaso
Copy link
Member

Thanks

@ewels
Copy link
Member Author

ewels commented Dec 14, 2023

@bentsherman are you ok to yank your commits out of this PR again? I'll leave it to you to handle that bit. Shout if you want me to do anything.

@pditommaso
Copy link
Member

I've realised that on older version of org.fusesource.jansi.Ansi embedded with jline.

Keeping both on the classpath sounds a very bad thing, and version 2.4 was only used for the bgRgb and fgRbg methods. Think this should do the same.

final labelSpaces = tagMatch ? tagMatch.group(2) : ''
final labelNoTag = LBL_REPLACE.matcher(label).replaceFirst("")
final labelFinalProcess = labelNoTag.tokenize(':')[-1]
final labelNoFinalProcess = labelFinalProcess.length() > 0 ? labelNoTag - ~/$labelFinalProcess$/ : labelNoTag
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What labelNoTag - ~/$labelFinalProcess$/ does? just strips labelFinalProcess from labelNoTag?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yup - I'm basically breaking that string into components so that I can colour them differently. I wanted to highlight the final process name (after the last :) as that's usually the most interesting bit.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I added a chunk of comments a bit further up with an example, and what each variable will end up with.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think the regex is not necessary, have a look at feb0cc5


def fmt = ansi()
fmt.a("\n")
fmt.bg(Color.CYAN).fg(Color.BLACK).bold().a(" N E X T F L O W ").reset()
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@pditommaso this isn't quite the same as the bgRgb that was here before. The previous RGB value was the exact Nextflow colour and would appear the same on every terminal - irrespective of what theme is being used. The same for the fgRbg with (0,0,0).

The problem with terminal colours is that "cyan" and "black" are interpreted differently by everyone's setup, depending on what theme they use. For example, in a dark mode termainal, "black" is actually... white 👀 By using the exact rgb values it always looks the same and it ensures that it'll be readable.

This is minor, but I wanted to point out why I did this particular bit the way I did (and why it was different to everything else).

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

To illustrate this, the output I get now looks like this: (not green and poor text contrast)

CleanShot 2024-02-10 at 19 46 53@2x

Whereas before it looked like this:

CleanShot 2024-02-10 at 19 49 24@2x

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Umm, this stuff is little more of a wrapper around an escape code. Considering this is the only place where it's used, is there any chance to find out the code and use it directly?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ok - Yup, can do 👍🏻

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ok, got it to work after a bit of trial and error in 32e3a16

Now looks exactly as in the second screenshot above.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Not working for me. Either we give up with the background color or we may need to use a different library for Ansi colors. This can be a better choice

Use raw ANSI codes to get precise RGB codes.

Signed-off-by: Phil Ewels <[email protected]>
ewels and others added 6 commits February 10, 2024 20:44
@ewels
Copy link
Member Author

ewels commented Feb 12, 2024

Ok, I see some difference in the Nextflow header RGB support based depending on which terminal program I use. Mac OSX basically doesn't support the background:

CleanShot 2024-02-12 at 15 37 49@2x

I guess that this is due to Apple Terminal lacking support. I'll try to take a look.

@pditommaso
Copy link
Member

I suspect they have different escape codes ..

@ewels
Copy link
Member Author

ewels commented Feb 12, 2024

I think it's because the Apple Terminal program only supports 256 colours, rather than truecolor (16.7 million). See this blog post, but I've also come across it before in the Python world I remember now.

Basically, Apple Terminal is kind of crap 😅

@ewels
Copy link
Member Author

ewels commented Feb 12, 2024

Ok, with a lot of trial and error and some help from ChatGPT, I think I found a solution which is close enough to the "true" Nextflow green that no-one will notice the difference, and is hopefully pretty consistent across terminals:

CleanShot 2024-02-12 at 17 55 37@2x

@pditommaso
Copy link
Member

You went wild! 😆

Signed-off-by: Paolo Di Tommaso <[email protected]>
@pditommaso
Copy link
Member

Let's do it!

@pditommaso pditommaso merged commit 5e2ce9e into nextflow-io:master Feb 12, 2024
5 checks passed
@ewels ewels deleted the coloured-logs branch February 12, 2024 21:48
nschan pushed a commit to nschan/nextflow that referenced this pull request Apr 3, 2024
Signed-off-by: Phil Ewels <[email protected]>
Signed-off-by: Ben Sherman <[email protected]>
Signed-off-by: Paolo Di Tommaso <[email protected]>
Co-authored-by: Ben Sherman <[email protected]>
Co-authored-by: Paolo Di Tommaso <[email protected]>
Co-authored-by: Dr Marco Claudio De La Pierre <[email protected]>
Signed-off-by: Niklas Schandry <[email protected]>
nschan pushed a commit to nschan/nextflow that referenced this pull request Apr 3, 2024
Signed-off-by: Phil Ewels <[email protected]>
Signed-off-by: Ben Sherman <[email protected]>
Signed-off-by: Paolo Di Tommaso <[email protected]>
Co-authored-by: Ben Sherman <[email protected]>
Co-authored-by: Paolo Di Tommaso <[email protected]>
Co-authored-by: Dr Marco Claudio De La Pierre <[email protected]>
Signed-off-by: Niklas Schandry <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Suggestion: Prettier terminal outputs
5 participants