Skip to content

Commit

Permalink
Add colours to ansi logs (#4573)
Browse files Browse the repository at this point in the history 

Signed-off-by: Phil Ewels <phil.ewels@seqera.io>
Signed-off-by: Ben Sherman <bentshermann@gmail.com>
Signed-off-by: Paolo Di Tommaso <paolo.ditommaso@gmail.com>
Co-authored-by: Ben Sherman <bentshermann@gmail.com>
Co-authored-by: Paolo Di Tommaso <paolo.ditommaso@gmail.com>
Co-authored-by: Dr Marco Claudio De La Pierre <marco.delapierre@gmail.com>
  • Loading branch information
@ewels @bentsherman
@pditommaso @marcodelapierre
4 people committed Feb 12, 2024
1 parent 192bf8d commit 5e2ce9e
Show file tree
Hide file tree
Showing 4 changed files with 199 additions and 49 deletions.
2 changes: 1 addition & 1 deletion build.gradle
View file
Expand Up @@ -108,7 +108,7 @@ allprojects {
}

// Documentation required libraries
groovyDoc 'org.fusesource.jansi:jansi:1.11'
groovyDoc 'org.fusesource.jansi:jansi:2.4.0'
groovyDoc "org.apache.groovy:groovy-groovydoc:4.0.18"
groovyDoc "org.apache.groovy:groovy-ant:4.0.18"
}
Expand Down
71 changes: 63 additions & 8 deletions modules/nextflow/src/main/groovy/nextflow/cli/CmdRun.groovy
View file
Expand Up @@ -16,6 +16,9 @@

package nextflow.cli


import static org.fusesource.jansi.Ansi.*

import java.nio.file.NoSuchFileException
import java.nio.file.Path
import java.util.regex.Pattern
Expand Down Expand Up @@ -45,6 +48,7 @@ import nextflow.secret.SecretsLoader
import nextflow.util.CustomPoolFactory
import nextflow.util.Duration
import nextflow.util.HistoryFile
import org.fusesource.jansi.AnsiConsole
import org.yaml.snakeyaml.Yaml
/**
* CLI sub-command RUN
Expand All @@ -60,8 +64,8 @@ class CmdRun extends CmdBase implements HubOptions {

static final public List<String> VALID_PARAMS_FILE = ['json', 'yml', 'yaml']

static final public DSL2 = '2'
static final public DSL1 = '1'
static final public String DSL2 = '2'
static final public String DSL1 = '1'

static {
// install the custom pool factory for GPars threads
Expand Down Expand Up @@ -310,7 +314,7 @@ class CmdRun extends CmdBase implements HubOptions {

checkRunName()

log.info "N E X T F L O W ~ version ${BuildInfo.version}"
printBanner()
Plugins.init()

// -- specify the arguments
Expand Down Expand Up @@ -372,6 +376,37 @@ class CmdRun extends CmdBase implements HubOptions {
runner.execute(scriptArgs, this.entryName)
}

protected void printBanner() {
if( launcher.options.ansiLog ){
// Plain header for verbose log
log.debug "N E X T F L O W ~ version ${BuildInfo.version}"

// Fancy coloured header for the ANSI console output
def fmt = ansi()
fmt.a("\n")
// Use exact colour codes so that they render the same on every terminal,
// irrespective of terminal colour scheme.
// Nextflow green RGB (13, 192, 157) and exact black text (0,0,0),
// Apple Terminal only supports 256 colours, so use the closest match:
// light sea green | #20B2AA | 38;5;0
// Don't use black for text as terminals mess with this in their colour schemes.
// Use very dark grey, which is more reliable.
// Jansi library bundled in Jline can't do exact RGBs,
// so just do the ANSI codes manually
final BACKGROUND = "\033[1m\033[38;5;232m\033[48;5;43m"
fmt.a("$BACKGROUND N E X T F L O W ").reset()

// Show Nextflow version
fmt.a(Attribute.INTENSITY_FAINT).a(" ~ ").reset().a("version " + BuildInfo.version).reset()
fmt.a("\n")
AnsiConsole.out.println(fmt.eraseLine())
}
else {
// Plain header to the console if ANSI is disabled
log.info "N E X T F L O W ~ version ${BuildInfo.version}"
}
}

protected checkConfigEnv(ConfigMap config) {
// Warn about setting NXF_ environment variables within env config scope
final env = config.env as Map<String, String>
Expand All @@ -396,12 +431,32 @@ class CmdRun extends CmdBase implements HubOptions {
NextflowMeta.instance.enableDsl(dsl)
// -- show launch info
final ver = NF.dsl2 ? DSL2 : DSL1
final repo = scriptFile.repository ?: scriptFile.source
final repo = scriptFile.repository ?: scriptFile.source.toString()
final head = preview ? "* PREVIEW * $scriptFile.repository" : "Launching `$repo`"
if( scriptFile.repository )
log.info "${head} [$runName] DSL${ver} - revision: ${scriptFile.revisionInfo}"
else
log.info "${head} [$runName] DSL${ver} - revision: ${scriptFile.getScriptId()?.substring(0,10)}"
final revision = scriptFile.repository
? scriptFile.revisionInfo.toString()
: scriptFile.getScriptId()?.substring(0,10)
printLaunchInfo(ver, repo, head, revision)
}

protected void printLaunchInfo(String ver, String repo, String head, String revision) {
if( launcher.options.ansiLog ){
log.debug "${head} [$runName] DSL${ver} - revision: ${revision}"

def fmt = ansi()
fmt.a(" ┃ Launching").fg(Color.MAGENTA).a(" `$repo` ").reset()
fmt.a(Attribute.INTENSITY_FAINT).a("[").reset()
fmt.bold().fg(Color.CYAN).a(runName).reset()
fmt.a(Attribute.INTENSITY_FAINT).a("]")
fmt.a(" DSL${ver} - ")
fmt.fg(Color.CYAN).a("revision: ").reset()
fmt.fg(Color.CYAN).a(revision).reset()
fmt.a("\n")
AnsiConsole.out().println(fmt.eraseLine())
}
else {
log.info "${head} [$runName] DSL${ver} - revision: ${revision}"
}
}

static String detectDslMode(ConfigMap config, String scriptText, Map sysEnv) {
Expand Down
134 changes: 111 additions & 23 deletions modules/nextflow/src/main/groovy/nextflow/trace/AnsiLogObserver.groovy
View file
Expand Up @@ -16,6 +16,8 @@

package nextflow.trace

import java.util.regex.Pattern

import groovy.transform.CompileStatic
import jline.TerminalFactory
import nextflow.Session
Expand Down Expand Up @@ -85,6 +87,8 @@ class AnsiLogObserver implements TraceObserver {

private volatile int cols = 80

private volatile int rows = 24

private long startTimestamp

private long endTimestamp
Expand Down Expand Up @@ -181,7 +185,7 @@ class AnsiLogObserver implements TraceObserver {
wait(200)
}
}
//
//
final stats = statsObserver.getStats()
renderProgress(stats)
renderSummary(stats)
Expand Down Expand Up @@ -227,7 +231,7 @@ class AnsiLogObserver implements TraceObserver {
protected String getExecutorName(String key) {
session.getExecutorFactory().getDisplayName(key)
}

protected void renderExecutors(Ansi term) {
int count=0
def line = ''
Expand All @@ -237,7 +241,7 @@ class AnsiLogObserver implements TraceObserver {
}

if( count ) {
term.a("executor > " + line)
term.a(Attribute.INTENSITY_FAINT).a("executor > " + line).reset()
term.newline()
}
}
Expand All @@ -251,6 +255,7 @@ class AnsiLogObserver implements TraceObserver {
}

cols = TerminalFactory.get().getWidth()
rows = TerminalFactory.get().getHeight()

// calc max width
final now = System.currentTimeMillis()
Expand All @@ -265,9 +270,25 @@ class AnsiLogObserver implements TraceObserver {
lastWidthReset = now

// render line
def renderedLines = 0
def skippedLines = 0
for( ProgressRecord entry : processes ) {
term.a(line(entry))
term.newline()
// Only show line if we have space in the visible terminal area
// or if the process has some submitted tasks
if( renderedLines <= rows - 5 || entry.getTotalCount() > 0 ) {
term.a(line(entry))
term.newline()
renderedLines += 1
}
// Process with no active tasks and we're out of screen space, skip
else {
skippedLines += 1
}
}
// Tell the user how many processes without active tasks were hidden
if( skippedLines > 0 ){
term.a(Attribute.ITALIC).a(Attribute.INTENSITY_FAINT).a("Plus ").bold().a(skippedLines).reset()
term.a(Attribute.ITALIC).a(Attribute.INTENSITY_FAINT).a(" more processes waiting for tasks…").reset().newline()
}
rendered = true
}
Expand Down Expand Up @@ -322,7 +343,7 @@ class AnsiLogObserver implements TraceObserver {
return
if( enableSummary == null && delta <= 60*1_000 )
return

if( session.isSuccess() && stats.progressLength>0 ) {
def report = ""
report += "Completed at: ${new Date(endTimestamp).format('dd-MMM-yyyy HH:mm:ss')}\n"
Expand Down Expand Up @@ -350,13 +371,13 @@ class AnsiLogObserver implements TraceObserver {
if( color ) fmt = fmt.fg(Color.DEFAULT)
AnsiConsole.out.println(fmt.eraseLine())
}

protected void printAnsiLines(String lines) {
final text = lines
.replace('\r','')
.replace(NEWLINE, ansi().eraseLine().toString() + NEWLINE)
AnsiConsole.out.print(text)
}
}

protected String fmtWidth(String name, int width, int cols) {
assert name.size() <= width
Expand All @@ -369,36 +390,103 @@ class AnsiLogObserver implements TraceObserver {
}

protected String fmtChop(String str, int cols) {
// Truncate the process name to fit the terminal width
if( str.size() <= cols )
return str
return cols>3 ? str[0..(cols-3-1)] + '...' : str[0..cols-1]
// Take the first 3 characters and the final chunk of text
// eg. for: NFCORE_RNASEQ:RNASEQ:FASTQ_SUBSAMPLE_FQ_SALMON:FQ_SUBSAMPLE
// truncate to: NFC…_SALMON:FQ_SUBSAMPLE
return cols>5 ? str.take(3) + '…' + str.takeRight(cols-1-3) : str[0..cols-1]
}

protected String line(ProgressRecord stats) {
private final static Pattern TAG_REGEX = ~/ \((.+)\)( *)$/
private final static Pattern LBL_REPLACE = ~/ \(.+\) *$/

protected Ansi line(ProgressRecord stats) {
final term = ansi()
final float tot = stats.getTotalCount()
final float com = stats.getCompletedCount()
// Truncate or pad the label to the correct width
final label = fmtWidth(stats.taskName, labelWidth, Math.max(cols-50, 5))
// Break up the process label into components for styling. eg:
// NFCORE_RNASEQ:RNASEQ:PREPARE_GENOME:GUNZIP_GTF (genes.gtf.gz)
// labelTag = genes.gtf.gz
// labelSpaces = whitespace padding after process name
// labelFinalProcess = GUNZIP_GTF
// labelNoFinalProcess = NFCORE_RNASEQ:RNASEQ:PREPARE_GENOME:
final tagMatch = TAG_REGEX.matcher(label)
final labelTag = tagMatch ? tagMatch.group(1) : ''
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
final hh = (stats.hash && tot>0 ? stats.hash : '-').padRight(9)

if( tot == 0 )
return "[$hh] process > $label -"

final x = tot ? Math.floor(com / tot * 100f).toInteger() : 0
final pct = "[${String.valueOf(x).padLeft(3)}%]".toString()
// eg. 100% (whitespace padded for alignment)
final pct = "${String.valueOf(x).padLeft(3)}%".toString()
// eg. 1 of 1
final numbs = " ${(int)com} of ${(int)tot}".toString()

// Task hash, eg: [fa/71091a]
term.a(Attribute.INTENSITY_FAINT).a('[').reset()
term.fg(Color.BLUE).a(hh).reset()
term.a(Attribute.INTENSITY_FAINT).a('] ').reset()

// Only show 'process > ' if the terminal has lots of width
if( cols > 180 )
term.a(Attribute.INTENSITY_FAINT).a('process > ').reset()
// Stem of process name, dim text
term.a(Attribute.INTENSITY_FAINT).a(labelNoFinalProcess).reset()
// Final process name, regular text
term.a(labelFinalProcess)
// Active process with a tag, eg: (genes.gtf.gz)
if( labelTag ){
// Tag in yellow, () dim but tag text regular
term.fg(Color.YELLOW).a(Attribute.INTENSITY_FAINT).a(' (').reset()
term.fg(Color.YELLOW).a(labelTag)
term.a(Attribute.INTENSITY_FAINT).a(')').reset().a(labelSpaces)
}

// No tasks
if( tot == 0 ) {
term.a(' -')
return term
}

final numbs = "${(int)com} of ${(int)tot}".toString()
def result = "[${hh}] process > $label $pct $numbs"
// Progress percentage, eg: [ 80%]
if( cols > 120 ) {
// Only show the percentage if we have lots of width
// Percentage text in green if 100%, otherwise blue
term.a(Attribute.INTENSITY_FAINT).a(' [').reset()
.fg(pct == '100%' ? Color.GREEN : Color.BLUE).a(pct).reset()
.a(Attribute.INTENSITY_FAINT).a(']').reset()
}
else {
// If narrow terminal, show single pipe char instead of percentage to save space
term.a(Attribute.INTENSITY_FAINT).a(' |').reset()
}
// Progress active task count, eg: 8 of 10
term.a(numbs)

// Completed task counts and status
// Dim text for cached, otherwise regular
if( stats.cached )
result += ", cached: $stats.cached"
term.a(Attribute.INTENSITY_FAINT).a(", cached: $stats.cached").reset()
if( stats.stored )
result += ", stored: $stats.stored"
term.a(", stored: $stats.stored")
if( stats.failed )
result += ", failed: $stats.failed"
term.a(", failed: $stats.failed")
if( stats.retries )
result += ", retries: $stats.retries"
if( stats.terminated && tot )
result += stats.errored ? ' \u2718' : ' \u2714'
return fmtChop(result, cols)
term.a(", retries: $stats.retries")
// Show red cross ('✘') or green tick ('✔') according to status
if( stats.terminated && tot ) {
if( stats.errored )
term.fg(Color.RED).a(' \u2718').reset()
else
term.fg(Color.GREEN).a(' \u2714').reset()
}
return term
}

@Override
Expand Down

0 comments on commit 5e2ce9e

Please sign in to comment.