improvement(core): better logs command

This PR makes some improvements to the logs stream. E.g.:

- More resilient logs follow mode
- Color code logs
- Add --since flag
- Interleave logs when not in follow mode

core/package.json

@@ -111,6 +111,7 @@
     "normalize-url": "^5.0.0",
     "open": "^7.0.4",
     "p-retry": "^4.2.0",
+    "parse-duration": "^1.0.0",
     "parse-git-config": "^3.0.0",
     "path-is-inside": "^1.0.2",
     "pluralize": "^8.0.0",
@@ -134,7 +135,7 @@
     "tmp-promise": "^3.0.2",
     "toposort": "^2.0.2",
     "tough-cookie": "^4.0.0",
-    "ts-stream": "^2.0.1",
+    "ts-stream": "^3.0.0",
     "typeorm-with-better-sqlite3": "^0.2.27",
     "typescript-memoize": "^1.0.0-alpha.3",
     "uniqid": "^5.2.0",
@@ -262,4 +263,4 @@
     ]
   },
   "gitHead": "b0647221a4d2ff06952bae58000b104215aed922"
-}
+}

core/src/cli/params.ts

@@ -14,7 +14,7 @@ import { joi, DeepPrimitiveMap } from "../config/common"
 import { ParameterError } from "../exceptions"
 import { parseEnvironment } from "../config/project"
 import { LOGGER_TYPES, getLogLevelChoices, envSupportsEmoji } from "../logger/logger"
-import { deline } from "../util/string"
+import { dedent, deline } from "../util/string"
 import chalk = require("chalk")
 import { LogLevel } from "../logger/log-node"
 import { safeDumpYaml } from "../util/util"
@@ -32,6 +32,15 @@ export const OUTPUT_RENDERERS = {
   },
 }
 
+export const validDurationUnits = ["d", "h", "m", "s"]
+
+function splitDuration(duration: string) {
+  return duration
+    .trim()
+    .split(/([0-9]+)/)
+    .filter(Boolean)
+}
+
 export interface ParameterConstructor<T> {
   help: string
   required?: boolean
@@ -158,6 +167,49 @@ export class PathParameter extends Parameter<string> {
   }
 }
 
+export class DurationParameter extends Parameter<string> {
+  type = "moment"
+  schema = joi.string()
+
+  coerce(input: string): string {
+    const parts = splitDuration(input)
+    const expectedType = dedent`
+      Duration where unit is one of ${validDurationUnits.join(
+        ", "
+      )} and length is an integer. For example '1d', '10m', '20s'.
+    `
+    if (parts.length !== 2) {
+      throw new ParameterError(`Could not parse "${input}" as duration`, {
+        expectedType,
+        input,
+      })
+    }
+    const length = parseInt(parts[0], 10)
+    const unit = parts[1]
+    if (isNaN(length)) {
+      throw new ParameterError(
+        `Could not parse "${input}" as duration, length must be an integer. Received ${length}`,
+        {
+          expectedType,
+          input,
+        }
+      )
+    }
+    if (!validDurationUnits.includes(unit)) {
+      throw new ParameterError(
+        `Could not parse "${input}" as duration, unit must be one of ${validDurationUnits.join(
+          ", "
+        )}. Received ${unit}`,
+        {
+          expectedType,
+          input,
+        }
+      )
+    }
+    return input
+  }
+}
+
 export class PathsParameter extends StringsParameter {
   type = "array:path"
 

core/src/commands/enterprise/enterprise.ts

@@ -15,8 +15,8 @@ import { UsersCommand } from "./users/users"
 export class EnterpriseCommand extends CommandGroup {
   name = "enterprise"
   help = dedent`
-    [EXPERIMENTAL] Manage Garden Enterprise resources such as users, groups and secrets. Requires
-    Garden Enterprise 1.14.0 or higher.
+    [EXPERIMENTAL] Manage Garden Enterprise resources such as users, groups and secrets.
+    Requires Garden Enterprise 1.14.0 or higher.
   `
 
   subCommands = [SecretsCommand, UsersCommand, GroupsCommand]

core/src/commands/logs.ts

@@ -8,17 +8,19 @@
 
 import { Command, CommandResult, CommandParams } from "./base"
 import chalk from "chalk"
-import { maxBy } from "lodash"
+import { maxBy, sortBy } from "lodash"
 import { ServiceLogEntry } from "../types/plugin/service/getServiceLogs"
 import Bluebird = require("bluebird")
 import { GardenService } from "../types/service"
 import Stream from "ts-stream"
-import { LoggerType } from "../logger/logger"
-import dedent = require("dedent")
+import { LoggerType, logLevelMap } from "../logger/logger"
+import { StringsParameter, BooleanParameter, IntegerParameter, DurationParameter } from "../cli/params"
+import { printHeader, renderDivider } from "../logger/util"
+import stripAnsi = require("strip-ansi")
 import { LogLevel } from "../logger/log-node"
-import { emptyRuntimeContext } from "../runtime-context"
-import { StringsParameter, BooleanParameter, IntegerParameter } from "../cli/params"
-import { printHeader } from "../logger/util"
+import hasAnsi = require("has-ansi")
+import { dedent } from "../util/string"
+import { formatSection } from "../logger/renderers"
 
 const logsArgs = {
   services: new StringsParameter({
@@ -29,35 +31,70 @@ const logsArgs = {
 }
 
 const logsOpts = {
-  follow: new BooleanParameter({
+  "follow": new BooleanParameter({
     help: "Continuously stream new logs from the service(s).",
     alias: "f",
     cliOnly: true,
   }),
-  tail: new IntegerParameter({
-    help: "Number of lines to show for each service. Defaults to -1, showing all log lines.",
+  "tail": new IntegerParameter({
+    help: dedent`
+      Number of lines to show for each service. Defaults to showing all log lines (up to a certain limit). Takes precedence over
+      the \`--since\` flag if both are set. Note that we don't recommend using a large value here when in follow mode.
+    `,
     alias: "t",
-    defaultValue: -1,
   }),
-  // TODO
-  // since: new MomentParameter({ help: "Retrieve logs from the specified point onwards" }),
+  "show-container": new BooleanParameter({
+    help: "Show the name of the container with log output. May not apply to all providers",
+    defaultValue: false,
+  }),
+  "timestamps": new BooleanParameter({
+    help: "Show timestamps with log output.",
+  }),
+  "since": new DurationParameter({
+    help: dedent`
+      Only show logs newer than a relative duration like 5s, 2m, or 3h. Defaults to \`"1m"\` when \`--follow\` is true
+      unless \`--tail\` is set. Note that we don't recommend using a large value here when in follow mode.
+    `,
+  }),
+  "original-color": new BooleanParameter({
+    help: "Show the original color output of the logs instead of color coding them.",
+    defaultValue: false,
+  }),
+  "hide-service": new BooleanParameter({
+    help: "Hide the service name and render the logs directly.",
+    defaultValue: false,
+  }),
 }
 
 type Args = typeof logsArgs
 type Opts = typeof logsOpts
 
+export const colors = ["green", "cyan", "magenta", "yellow", "blueBright", "red"]
+
+/**
+ * Skip empty entries.
+ */
+function skipEntry(entry: ServiceLogEntry) {
+  const validDate = entry.timestamp && entry.timestamp instanceof Date && !isNaN(entry.timestamp.getTime())
+  return !entry.msg && !validDate
+}
+
 export class LogsCommand extends Command<Args, Opts> {
   name = "logs"
   help = "Retrieves the most recent logs for the specified service(s)."
 
   description = dedent`
-    Outputs logs for all or specified services, and optionally waits for news logs to come in.
+    Outputs logs for all or specified services, and optionally waits for news logs to come in. Defaults
+    to getting logs from the last minute when in \`--follow\` mode. You can change this with the \`--since\` option.
 
     Examples:
 
-        garden logs               # prints latest logs from all services
-        garden logs my-service    # prints latest logs for my-service
-        garden logs -t            # keeps running and streams all incoming logs to the console
+        garden logs                       # interleaves color-coded logs from all services (up to a certain limit)
+        garden logs --since 2d            # interleaves color-coded logs from all services from the last 2 days
+        garden logs --tail 100            # interleaves the last 100 log lines from all services
+        garden logs service-a,service-b   # interleaves color-coded logs for service-a and service-b
+        garden logs --follow              # keeps running and streams all incoming logs to the console
+        garden logs --original-color      # interleaves logs from all services and prints the original output color
   `
 
   arguments = logsArgs
@@ -72,61 +109,129 @@ export class LogsCommand extends Command<Args, Opts> {
   }
 
   async action({ garden, log, args, opts }: CommandParams<Args, Opts>): Promise<CommandResult<ServiceLogEntry[]>> {
-    const { follow, tail } = opts
+    const { follow, timestamps } = opts
+    let tail = opts.tail as number | undefined
+    let since = opts.since as string | undefined
+    const originalColor = opts["original-color"]
+    const showContainer = opts["show-container"]
+    const hideService = opts["hide-service"]
+
+    if (tail) {
+      // Tail takes precedence over since...
+      since = undefined
+    } else if (follow && !since) {
+      // ...but if tail is not set and we're in follow mode, we default to getting the most recent logs.
+      since = "1m"
+    }
+
     const graph = await garden.getConfigGraph(log)
-    const services = graph.getServices({ names: args.services })
+    const allServices = graph.getServices()
+    const services = args.services ? allServices.filter((s) => args.services?.includes(s.name)) : allServices
+
     const serviceNames = services.map((s) => s.name).filter(Boolean)
     const maxServiceName = (maxBy(serviceNames, (serviceName) => serviceName.length) || "").length
+    // If the container name should be displayed, we align the output wrt to the longest container name
+    let maxContainerName = 1
 
     const result: ServiceLogEntry[] = []
     const stream = new Stream<ServiceLogEntry>()
-
-    void stream.forEach((entry) => {
-      // TODO: color each service differently for easier visual parsing
-      let timestamp = "                        "
-
-      // bad timestamp values can cause crash if not caught
-      if (entry.timestamp) {
+    let details: string = ""
+
+    if (tail) {
+      details = ` (showing last ${tail} lines from each service)`
+    } else if (since) {
+      details = ` (from the last '${since}' for each service)`
+    }
+
+    log.info("")
+    log.info(chalk.white.bold("Service logs" + details + ":"))
+    log.info(chalk.white.bold(renderDivider()))
+    log.root.stop()
+
+    // Map all service names in the project to a specific color. This ensures
+    // that in most cases services have the same color (unless any have been added/removed),
+    // regardless of what params you pass to the command.
+    const allServiceNames = allServices
+      .map((s) => s.name)
+      .filter(Boolean)
+      .sort()
+    const colorMap = allServiceNames.reduce((acc, serviceName, idx) => {
+      const color = colors[idx % colors.length]
+      acc[serviceName] = color
+      return acc
+    }, {})
+
+    const formatEntry = (entry: ServiceLogEntry) => {
+      const style = chalk[colorMap[entry.serviceName]]
+      const sectionStyle = style.bold
+      const serviceLog = originalColor ? entry.msg : stripAnsi(entry.msg)
+
+      let timestamp: string | undefined
+      let container: string | undefined
+
+      if (timestamps && entry.timestamp) {
+        timestamp = "                        "
         try {
           timestamp = entry.timestamp.toISOString()
         } catch {}
       }
 
-      log.info({
-        section: entry.serviceName,
-        msg: `${chalk.yellowBright(timestamp)} → ${chalk.white(entry.msg)}`,
-        maxSectionWidth: maxServiceName,
-      })
+      if (showContainer && entry.containerName) {
+        maxContainerName = Math.max(maxContainerName, entry.containerName.length)
+        container = entry.containerName
+      }
 
-      if (!follow) {
+      let out = ""
+      if (!hideService) {
+        out += `${sectionStyle(formatSection(entry.serviceName, maxServiceName))} → `
+      }
+      if (container) {
+        out += `${sectionStyle(formatSection(container, maxContainerName))} → `
+      }
+      if (timestamp) {
+        out += `${chalk.gray(timestamp)} → `
+      }
+      if (originalColor) {
+        // If the line doesn't have ansi encoding, we color it white to prevent logger from applying styles.
+        out += hasAnsi(serviceLog) ? serviceLog : chalk.white(serviceLog)
+      } else {
+        out += style(serviceLog)
+      }
+
+      return out
+    }
+
+    void stream.forEach((entry) => {
+      // Skip emtpy entries
+      if (skipEntry(entry)) {
+        return
+      }
+
+      if (follow) {
+        const levelStr = logLevelMap[entry.level || LogLevel.info] || "info"
+        const msg = formatEntry(entry)
+        log[levelStr]({ msg })
+      } else {
         result.push(entry)
       }
     })
 
     const actions = await garden.getActionRouter()
-    const voidLog = log.placeholder({ level: LogLevel.silly, childEntriesInheritLevel: true })
 
     await Bluebird.map(services, async (service: GardenService<any>) => {
-      const status = await actions.getServiceStatus({
-        devMode: false,
-        hotReload: false,
-        log: voidLog,
-        // This shouldn't matter for this context, we're just checking if the service is up or not
-        runtimeContext: emptyRuntimeContext,
-        service,
-      })
-
-      if (status.state === "ready" || status.state === "outdated") {
-        await actions.getServiceLogs({ log, service, stream, follow, tail })
-      } else {
-        await stream.write({
-          serviceName: service.name,
-          timestamp: new Date(),
-          msg: chalk.yellow(`<Service not running (state: ${status.state}). Please deploy the service and try again.>`),
-        })
-      }
+      await actions.getServiceLogs({ log, service, stream, follow, tail, since })
     })
 
-    return { result }
+    const sorted = sortBy(result, "timestamp")
+
+    if (!follow) {
+      for (const entry of sorted) {
+        const levelStr = logLevelMap[entry.level || LogLevel.info] || "info"
+        const msg = formatEntry(entry)
+        log[levelStr]({ msg })
+      }
+    }
+
+    return { result: sorted }
   }
 }

core/src/logger/logger.ts

@@ -25,6 +25,14 @@ import { range } from "lodash"
 export type LoggerType = "quiet" | "basic" | "fancy" | "fullscreen" | "json"
 export const LOGGER_TYPES = new Set<LoggerType>(["quiet", "basic", "fancy", "fullscreen", "json"])
 
+export const logLevelMap = {
+  [LogLevel.error]: "error",
+  [LogLevel.warn]: "warn",
+  [LogLevel.info]: "info",
+  [LogLevel.verbose]: "verbose",
+  [LogLevel.debug]: "debug",
+  [LogLevel.silly]: "silly",
+}
 const getLogLevelNames = () => getEnumKeys(LogLevel)
 const getNumericLogLevels = () => range(getLogLevelNames().length)
 // Allow string or numeric log levels as CLI choices