Merge pull request #494 from garden-io/logger-fixes

Logger fixes (closes #493 and #452)

garden-service/src/cli/cli.ts

@@ -7,12 +7,12 @@
  */
 
 import * as sywac from "sywac"
-import { intersection, merge, range } from "lodash"
+import { intersection, merge } from "lodash"
 import { resolve } from "path"
 import { safeDump } from "js-yaml"
 import { coreCommands } from "../commands/commands"
 import { DeepPrimitiveMap } from "../config/common"
-import { getEnumKeys, shutdown, sleep } from "../util/util"
+import { shutdown, sleep } from "../util/util"
 import {
   BooleanParameter,
   ChoicesParameter,
@@ -22,7 +22,7 @@ import {
   Parameter,
   StringParameter,
 } from "../commands/base"
-import { GardenError, InternalError, PluginError, toGardenError } from "../exceptions"
+import { GardenError, PluginError, toGardenError } from "../exceptions"
 import { Garden, GardenOpts } from "../garden"
 import { getLogger, Logger, LoggerType } from "../logger/logger"
 import { LogLevel } from "../logger/log-node"
@@ -43,6 +43,8 @@ import {
   prepareOptionConfig,
   styleConfig,
   getPackageVersion,
+  getLogLevelChoices,
+  parseLogLevel,
 } from "./helpers"
 import { GardenConfig } from "../config/base"
 import { defaultEnvironments } from "../config/project"
@@ -87,11 +89,6 @@ export const MOCK_CONFIG: GardenConfig = {
   },
 }
 
-const getLogLevelNames = () => getEnumKeys(LogLevel)
-const getNumericLogLevels = () => range(getLogLevelNames().length)
-// Allow string or numeric log levels as CLI choices
-const getLogLevelChoices = () => [...getLogLevelNames(), ...getNumericLogLevels().map(String)]
-
 export const GLOBAL_OPTIONS = {
   root: new StringParameter({
     alias: "r",
@@ -125,23 +122,6 @@ export const GLOBAL_OPTIONS = {
   }),
 }
 
-function parseLogLevel(level: string): LogLevel {
-  let lvl: LogLevel
-  const parsed = parseInt(level, 10)
-  if (parsed) {
-    lvl = parsed
-  } else {
-    lvl = LogLevel[level]
-  }
-  if (!getNumericLogLevels().includes(lvl)) {
-    throw new InternalError(
-      `Unexpected log level, expected one of ${getLogLevelChoices().join(", ")}, got ${level}`,
-      {},
-    )
-  }
-  return lvl
-}
-
 function initLogger({ level, logEnabled, loggerType, emoji }: {
   level: LogLevel, logEnabled: boolean, loggerType: LoggerType, emoji: boolean,
 }) {
@@ -402,7 +382,7 @@ export class GardenCli {
 }
 
 export async function run(): Promise<void> {
-  let code
+  let code: number | undefined
   try {
     const cli = new GardenCli()
     const result = await cli.parse()

garden-service/src/cli/helpers.ts

@@ -7,7 +7,7 @@
  */
 
 import chalk from "chalk"
-import { difference, flatten, reduce } from "lodash"
+import { difference, flatten, range, reduce } from "lodash"
 import {
   ChoicesParameter,
   ParameterValues,
@@ -16,6 +16,8 @@ import {
 import {
   InternalError,
 } from "../exceptions"
+import { LogLevel } from "../logger/log-node"
+import { getEnumKeys } from "../util/util"
 
 // Parameter types T which map between the Parameter<T> class and the Sywac cli library.
 // In case we add types that aren't supported natively by Sywac, see: http://sywac.io/docs/sync-config.html#custom
@@ -108,6 +110,30 @@ export function getArgSynopsis(key: string, param: Parameter<any>) {
   return param.required ? `<${key}>` : `[${key}]`
 }
 
+const getLogLevelNames = () => getEnumKeys(LogLevel)
+const getNumericLogLevels = () => range(getLogLevelNames().length)
+// Allow string or numeric log levels as CLI choices
+export const getLogLevelChoices = () => [...getLogLevelNames(), ...getNumericLogLevels().map(String)]
+
+export function parseLogLevel(level: string): LogLevel {
+  let lvl: LogLevel
+  const parsed = parseInt(level, 10)
+  // Level is numeric
+  if (parsed || parsed === 0) {
+    lvl = parsed
+    // Level is a string
+  } else {
+    lvl = LogLevel[level]
+  }
+  if (!getNumericLogLevels().includes(lvl)) {
+    throw new InternalError(
+      `Unexpected log level, expected one of ${getLogLevelChoices().join(", ")}, got ${level}`,
+      {},
+    )
+  }
+  return lvl
+}
+
 export function prepareArgConfig(param: Parameter<any>) {
   return {
     desc: param.help,

garden-service/src/commands/logs.ts

@@ -95,7 +95,7 @@ export class LogsCommand extends Command<Args, Opts> {
     })
 
     await Bluebird.map(services, async (service: Service<any>) => {
-      const voidLog = log.placeholder(LogLevel.silly)
+      const voidLog = log.placeholder(LogLevel.silly, { preserveLevel: true })
       const status = await garden.actions.getServiceStatus({ log: voidLog, service, hotReload: false })
 
       if (status.state === "ready" || status.state === "outdated") {

garden-service/src/logger/log-entry.ts

@@ -11,7 +11,7 @@ import * as nodeEmoji from "node-emoji"
 import { flatten } from "lodash"
 
 import { LogNode, LogLevel } from "./log-node"
-import { getChildEntries } from "./util"
+import { getChildEntries, findParentEntry } from "./util"
 import { GardenError } from "../exceptions"
 import { Omit } from "../util/util"
 import { Logger } from "./logger"
@@ -31,6 +31,7 @@ export interface UpdateOpts {
   error?: GardenError
   status?: EntryStatus
   indent?: number
+  preserveLevel?: boolean
 }
 
 export interface CreateOpts extends UpdateOpts {
@@ -42,7 +43,8 @@ export type CreateParam = string | CreateOpts
 export interface LogEntryConstructor {
   level: LogLevel
   opts: CreateOpts
-  parent: LogNode
+  root: Logger
+  parent?: LogEntry
 }
 
 // TODO Fix any cast
@@ -54,9 +56,10 @@ export class LogEntry extends LogNode {
   public opts: UpdateOpts
   public root: Logger
 
-  constructor({ level, opts, parent }: LogEntryConstructor) {
+  constructor({ level, opts, root, parent }: LogEntryConstructor) {
     const { id, ...otherOpts } = opts
     super(level, parent, id)
+    this.root = root
     this.opts = otherOpts
     if (this.level === LogLevel.error) {
       this.opts.status = "error"
@@ -102,19 +105,32 @@ export class LogEntry extends LogNode {
   }
 
   protected createNode(level: LogLevel, param: CreateParam) {
-    // A child entry must not have a higher level than its parent
-    const childLevel = this.level > level ? this.level : level
     const opts = {
       indent: (this.opts.indent || 0) + 1,
       ...resolveParam(param),
     }
-    return new LogEntry({ level: childLevel, opts, parent: this })
+
+    // If preserveLevel is set to true, all children must have a level geq the level
+    // of the parent entry that set the flag.
+    const parentWithPreserveFlag = findParentEntry(this, entry => !!entry.opts.preserveLevel)
+    const childLevel = parentWithPreserveFlag ? Math.max(parentWithPreserveFlag.level, level) : level
+
+    return new LogEntry({
+      opts,
+      level: childLevel,
+      root: this.root,
+      parent: this,
+    })
+  }
+
+  protected onGraphChange(node: LogEntry) {
+    this.root.onGraphChange(node)
   }
 
-  placeholder(level: LogLevel = LogLevel.info): LogEntry {
+  placeholder(level: LogLevel = LogLevel.info, param?: CreateParam): LogEntry {
     // Ensure placeholder child entries align with parent context
     const indent = Math.max((this.opts.indent || 0) - 1, - 1)
-    return this.appendNode(level, { indent })
+    return this.appendNode(level, { ...resolveParam(param), indent })
   }
 
   // Preserves status

garden-service/src/logger/log-node.ts

@@ -9,7 +9,6 @@
 import * as uniqid from "uniqid"
 import { round } from "lodash"
 
-import { findLogNode } from "./util"
 import { LogEntry, CreateParam } from "./log-entry"
 
 export enum LogLevel {
@@ -21,64 +20,58 @@ export enum LogLevel {
   silly = 5,
 }
 
-export abstract class LogNode<T = LogEntry, U = CreateParam> {
+export abstract class LogNode {
   public readonly timestamp: number
   public readonly key: string
-  public readonly children: T[]
-  public readonly root: RootLogNode<T>
+  public readonly children: LogEntry[]
 
   constructor(
     public readonly level: LogLevel,
-    public readonly parent?: LogNode<T>,
+    public readonly parent?: LogEntry,
     public readonly id?: string,
   ) {
-    if (this instanceof RootLogNode) {
-      this.root = this
-    } else {
-      // Non-root nodes have a parent
-      this.root = parent!.root
-    }
     this.key = uniqid()
     this.timestamp = Date.now()
     this.children = []
   }
 
-  protected abstract createNode(level: LogLevel, param: U): T
+  protected abstract createNode(level: LogLevel, param: CreateParam): LogEntry
+  protected abstract onGraphChange(node: LogEntry): void
 
   /**
    * A placeholder entry is an empty entry whose children should be aligned with the parent context.
    * Useful for setting a placeholder in the middle of the log that can later be populated.
    */
-  abstract placeholder(level: LogLevel): T
+  abstract placeholder(level: LogLevel, param?: CreateParam): LogEntry
 
-  protected appendNode(level: LogLevel, param: U): T {
+  protected appendNode(level: LogLevel, param: CreateParam): LogEntry {
     const node = this.createNode(level, param)
     this.children.push(node)
-    this.root.onGraphChange(node)
+    this.onGraphChange(node)
     return node
   }
 
-  silly(param: U): T {
+  silly(param: CreateParam): LogEntry {
     return this.appendNode(LogLevel.silly, param)
   }
 
-  debug(param: U): T {
+  debug(param: CreateParam): LogEntry {
     return this.appendNode(LogLevel.debug, param)
   }
 
-  verbose(param: U): T {
+  verbose(param: CreateParam): LogEntry {
     return this.appendNode(LogLevel.verbose, param)
   }
 
-  info(param: U): T {
+  info(param: CreateParam): LogEntry {
     return this.appendNode(LogLevel.info, param)
   }
 
-  warn(param: U): T {
+  warn(param: CreateParam): LogEntry {
     return this.appendNode(LogLevel.warn, param)
   }
 
-  error(param: U): T {
+  error(param: CreateParam): LogEntry {
     return this.appendNode(LogLevel.error, param)
   }
 
@@ -90,12 +83,3 @@ export abstract class LogNode<T = LogEntry, U = CreateParam> {
   }
 
 }
-
-export abstract class RootLogNode<T = LogEntry> extends LogNode<T> {
-  abstract onGraphChange(node: T): void
-
-  findById(id: string): T | void {
-    return findLogNode(this, node => node.id === id)
-  }
-
-}

garden-service/src/logger/logger.ts

@@ -6,17 +6,15 @@
  * file, You can obtain one at http://mozilla.org/MPL/2.0/.
  */
 
-import chalk from "chalk"
-
-import { RootLogNode } from "./log-node"
+import { LogNode } from "./log-node"
 import { LogEntry, CreateOpts, resolveParam } from "./log-entry"
-import { getChildEntries } from "./util"
+import { getChildEntries, findLogNode } from "./util"
 import { Writer } from "./writers/base"
 import { InternalError, ParameterError } from "../exceptions"
 import { LogLevel } from "./log-node"
 import { FancyTerminalWriter } from "./writers/fancy-terminal-writer"
 import { BasicTerminalWriter } from "./writers/basic-terminal-writer"
-import { combine, printEmoji } from "./renderers"
+import { parseLogLevel } from "../cli/helpers"
 
 export enum LoggerType {
   quiet = "quiet",
@@ -47,7 +45,7 @@ export interface LoggerConfig {
   useEmoji?: boolean
 }
 
-export class Logger extends RootLogNode<LogEntry> {
+export class Logger extends LogNode {
   public writers: Writer[]
   public useEmoji: boolean
 
@@ -65,9 +63,20 @@ export class Logger extends RootLogNode<LogEntry> {
       throw new InternalError("Logger already initialized", {})
     }
 
-    let instance
+    let instance: Logger
+
+    // GARDEN_LOG_LEVEL env variable takes precedence over the config param
+    if (process.env.GARDEN_LOG_LEVEL) {
+      try {
+        config.level = parseLogLevel(process.env.GARDEN_LOG_LEVEL)
+      } catch (err) {
+        // Log warning if level invalid but continue process.
+        // Using console logger since Garden logger hasn't been intialised.
+        console.warn("Warning:", err.message)
+      }
+    }
 
-    // If GARDEN_LOGGER_TYPE env variable is set it takes precedence over the config param
+    // GARDEN_LOGGER_TYPE env variable takes precedence over the config param
     if (process.env.GARDEN_LOGGER_TYPE) {
       const loggerType = LoggerType[process.env.GARDEN_LOGGER_TYPE]
 
@@ -95,7 +104,7 @@ export class Logger extends RootLogNode<LogEntry> {
   }
 
   protected createNode(level: LogLevel, opts: CreateOpts): LogEntry {
-    return new LogEntry({ level, parent: this, opts: resolveParam(opts) })
+    return new LogEntry({ level, root: this, opts: resolveParam(opts) })
   }
 
   placeholder(level: LogLevel = LogLevel.info): LogEntry {
@@ -115,17 +124,8 @@ export class Logger extends RootLogNode<LogEntry> {
     return getChildEntries(this).filter(entry => entry.opts.section === section)
   }
 
-  // FIXME: This isn't currently used anywhere, we should find this another place and purpose.
-  finish(
-    { showDuration = true, level = LogLevel.info }: { showDuration?: boolean, level?: LogLevel } = {},
-  ): LogEntry {
-    const msg = combine([
-      [this.useEmoji ? `\n${printEmoji("sparkles")} Finished` : "Finished"],
-      [showDuration ? ` in ${chalk.bold(this.getDuration() + "s")}` : "!"],
-      ["\n"],
-    ])
-    const lvlStr = LogLevel[level]
-    return this[lvlStr](msg)
+  findById(id: string): LogEntry | void {
+    return findLogNode(this, node => node.id === id)
   }
 
   stop(): void {