Add colours to ansi logs (nextflow-io#4573)

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]>

Author: 4 people

build.gradle

@@ -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"
     }

modules/nextflow/src/main/groovy/nextflow/cli/CmdRun.groovy

@@ -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
@@ -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
@@ -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
@@ -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
@@ -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>
@@ -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) {

modules/nextflow/src/main/groovy/nextflow/trace/AnsiLogObserver.groovy

@@ -16,6 +16,8 @@
 
 package nextflow.trace
 
+import java.util.regex.Pattern
+
 import groovy.transform.CompileStatic
 import jline.TerminalFactory
 import nextflow.Session
@@ -85,6 +87,8 @@ class AnsiLogObserver implements TraceObserver {
 
     private volatile int cols = 80
 
+    private volatile int rows = 24
+
     private long startTimestamp
 
     private long endTimestamp
@@ -181,7 +185,7 @@ class AnsiLogObserver implements TraceObserver {
                 wait(200)
             }
         }
-        // 
+        //
         final stats = statsObserver.getStats()
         renderProgress(stats)
         renderSummary(stats)
@@ -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 = ''
@@ -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()
         }
     }
@@ -251,6 +255,7 @@ class AnsiLogObserver implements TraceObserver {
         }
 
         cols = TerminalFactory.get().getWidth()
+        rows = TerminalFactory.get().getHeight()
 
         // calc max width
         final now = System.currentTimeMillis()
@@ -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
     }
@@ -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"
@@ -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
@@ -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