refactor(logger): do not store entries in-memory unless needed

With this change, the logger only stores log entries on the logger
instance when the FancyWriter is enabled or when running tests. This
prevents large log data accumulating in-memory.

Also refactored the logger a litle bit so that it no longer extends the
log node class but rather implements it. It simplifies the relationship
between the root logger and the log entries.

cli/src/add-version-files.ts

@@ -8,8 +8,7 @@
 
 import { GitHandler } from "@garden-io/core/build/src/vcs/git"
 import { Garden } from "@garden-io/core/build/src/garden"
-import { Logger } from "@garden-io/core/build/src/logger/logger"
-import { LogLevel } from "@garden-io/core/build/src/logger/log-node"
+import { Logger, LogLevel } from "@garden-io/core/build/src/logger/logger"
 import { resolve, relative } from "path"
 import Bluebird from "bluebird"
 import { STATIC_DIR, GARDEN_VERSIONFILE_NAME } from "@garden-io/core/build/src/constants"
@@ -20,7 +19,7 @@ require("source-map-support").install()
 
 // make sure logger is initialized
 try {
-  Logger.initialize({ level: LogLevel.info })
+  Logger.initialize({ level: LogLevel.info, type: "quiet" })
 } catch (_) {}
 
 /**

cli/src/generate-docs.ts

@@ -8,8 +8,7 @@
 
 import { generateDocs } from "@garden-io/core/build/src/docs/generate"
 import { resolve } from "path"
-import { Logger } from "@garden-io/core/build/src/logger/logger"
-import { LogLevel } from "@garden-io/core/build/src/logger/log-node"
+import { Logger, LogLevel } from "@garden-io/core/build/src/logger/logger"
 import { GARDEN_CLI_ROOT } from "@garden-io/core/build/src/constants"
 import { getBundledPlugins } from "./cli"
 import { getSupportedPlugins } from "@garden-io/core/build/src/plugins/plugins"
@@ -20,6 +19,7 @@ require("source-map-support").install()
 try {
   Logger.initialize({
     level: LogLevel.info,
+    type: "quiet",
     // level: LogLevel.debug,
     // writers: [new BasicTerminalWriter()],
   })

core/src/cli/cli.ts

@@ -14,9 +14,7 @@ import { shutdown, sleep, getPackageVersion, uuidv4 } from "../util/util"
 import { Command, CommandResult, CommandGroup } from "../commands/base"
 import { GardenError, PluginError, toGardenError, GardenBaseError } from "../exceptions"
 import { Garden, GardenOpts, DummyGarden } from "../garden"
-import { getLogger, Logger, LoggerType, getWriterInstance, parseLogLevel } from "../logger/logger"
-import { LogLevel } from "../logger/log-node"
-import { BasicTerminalWriter } from "../logger/writers/basic-terminal-writer"
+import { getLogger, Logger, LoggerType, LogLevel, parseLogLevel } from "../logger/logger"
 import { FileWriter, FileWriterConfig } from "../logger/writers/file-writer"
 
 import {
@@ -63,22 +61,6 @@ export async function makeDummyGarden(root: string, gardenOpts: GardenOpts) {
   return DummyGarden.factory(root, { noEnterprise: true, ...gardenOpts })
 }
 
-function initLogger({
-  level,
-  loggerType,
-  emoji,
-  showTimestamps,
-}: {
-  level: LogLevel
-  loggerType: LoggerType
-  emoji: boolean
-  showTimestamps: boolean
-}) {
-  const writer = getWriterInstance(loggerType, level)
-  const writers = writer ? [writer] : undefined
-  return Logger.initialize({ level, writers, showTimestamps, useEmoji: emoji })
-}
-
 export interface RunOutput {
   argv: any
   code: number
@@ -134,7 +116,7 @@ ${renderCommands(commands)}
       },
     ]
     for (const config of logConfigs) {
-      logger.writers.push(await FileWriter.factory(config))
+      logger.addWriter(await FileWriter.factory(config))
     }
     this.fileWritersInitialized = true
   }
@@ -194,11 +176,9 @@ ${renderCommands(commands)}
 
     if (silent || output) {
       loggerType = "quiet"
-    } else if (loggerType === "fancy" && (level > LogLevel.info || showTimestamps)) {
-      loggerType = "basic"
     }
 
-    const logger = initLogger({ level, loggerType, emoji, showTimestamps })
+    const logger = Logger.initialize({ level, type: loggerType, useEmoji: emoji, showTimestamps })
 
     // Currently we initialise empty placeholder entries and pass those to the
     // framework as opposed to the logger itself. This is to give better control over where on
@@ -474,7 +454,7 @@ ${renderCommands(commands)}
     } catch (_) {
       logger = Logger.initialize({
         level: LogLevel.info,
-        writers: [new BasicTerminalWriter()],
+        type: "basic",
       })
     }
 
@@ -492,7 +472,7 @@ ${renderCommands(commands)}
         })
       }
 
-      if (logger.writers.find((w) => w instanceof FileWriter)) {
+      if (logger.getWriters().find((w) => w instanceof FileWriter)) {
         logger.info(`\nSee ${ERROR_LOG_FILENAME} for detailed error message`)
         await waitForOutputFlush()
       }

core/src/cli/params.ts

@@ -13,14 +13,14 @@ import stringify from "json-stringify-safe"
 import { joi, DeepPrimitiveMap } from "../config/common"
 import { ParameterError } from "../exceptions"
 import { parseEnvironment } from "../config/project"
-import { LOGGER_TYPES, getLogLevelChoices, envSupportsEmoji } from "../logger/logger"
+import { getLogLevelChoices, LOGGER_TYPES, LogLevel } from "../logger/logger"
 import { dedent, deline } from "../util/string"
 import chalk = require("chalk")
-import { LogLevel } from "../logger/log-node"
 import { safeDumpYaml } from "../util/util"
 import { resolve } from "path"
 import { isArray } from "lodash"
 import { gardenEnv } from "../constants"
+import { envSupportsEmoji } from "../logger/util"
 
 export const OUTPUT_RENDERERS = {
   json: (data: DeepPrimitiveMap) => {

core/src/commands/logs.ts

@@ -13,11 +13,10 @@ import { ServiceLogEntry } from "../types/plugin/service/getServiceLogs"
 import Bluebird = require("bluebird")
 import { GardenService } from "../types/service"
 import Stream from "ts-stream"
-import { LoggerType, logLevelMap, parseLogLevel } from "../logger/logger"
+import { LoggerType, logLevelMap, LogLevel, parseLogLevel } 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 hasAnsi = require("has-ansi")
 import { dedent } from "../util/string"
 import { formatSection } from "../logger/renderers"

core/src/commands/run/workflow.ts

@@ -28,7 +28,7 @@ import Bluebird from "bluebird"
 import { getDurationMsec, toEnvVars } from "../../util/util"
 import { runScript } from "../../util/util"
 import { ExecaError } from "execa"
-import { LogLevel } from "../../logger/log-node"
+import { LogLevel } from "../../logger/logger"
 import { registerWorkflowRun } from "../../enterprise/workflow-lifecycle"
 import { parseCliArgs, pickCommand, processCliArgs } from "../../cli/helpers"
 import { StringParameter } from "../../cli/params"

core/src/enterprise/buffered-event-stream.ts

@@ -13,7 +13,7 @@ import { Events, EventName, EventBus, eventNames } from "../events"
 import { LogEntryMetadata, LogEntry, LogEntryMessage } from "../logger/log-entry"
 import { got } from "../util/http"
 
-import { LogLevel } from "../logger/log-node"
+import { LogLevel } from "../logger/logger"
 import { Garden } from "../garden"
 import { EnterpriseApi, makeAuthHeader } from "./api"
 

core/src/logger/log-entry.ts

@@ -8,13 +8,14 @@
 
 import logSymbols from "log-symbols"
 import nodeEmoji from "node-emoji"
-import { cloneDeep, merge } from "lodash"
+import { cloneDeep, merge, round } from "lodash"
 
-import { LogNode, LogLevel, CreateNodeParams, PlaceholderOpts } from "./log-node"
+import { LogLevel, LogNode } from "./logger"
 import { Omit } from "../util/util"
 import { getChildEntries, findParentEntry } from "./util"
 import { GardenError } from "../exceptions"
-import { Logger } from "./logger"
+import { CreateNodeParams, Logger, PlaceholderOpts } from "./logger"
+import uniqid from "uniqid"
 
 export type EmojiName = keyof typeof nodeEmoji.emoji
 export type LogSymbol = keyof typeof logSymbols | "empty"
@@ -39,8 +40,6 @@ export interface WorkflowStepMetadata {
   index: number
 }
 
-export const EVENT_LOG_LEVEL = LogLevel.debug
-
 interface MessageBase {
   msg?: string
   emoji?: EmojiName
@@ -76,7 +75,14 @@ export interface LogEntryConstructor extends LogEntryParams {
   isPlaceholder?: boolean
 }
 
-function resolveParams(params?: string | UpdateLogEntryParams): UpdateLogEntryParams {
+function resolveCreateParams(level: LogLevel, params: string | LogEntryParams): CreateNodeParams {
+  if (typeof params === "string") {
+    return { msg: params, level }
+  }
+  return { ...params, level }
+}
+
+function resolveUpdateParams(params?: string | UpdateLogEntryParams): UpdateLogEntryParams {
   if (typeof params === "string") {
     return { msg: params }
   } else if (!params) {
@@ -86,25 +92,30 @@ function resolveParams(params?: string | UpdateLogEntryParams): UpdateLogEntryPa
   }
 }
 
-// FIXME: Refactor to better distinguish between normal log entries and placeholder
-// log entries and to get rid of these "god" interfaces.
-// We should also better distinguish between message data and log entry data
-// and enforce that some message data is set for non-placeholder entries.
-export class LogEntry extends LogNode {
+export class LogEntry implements LogNode {
   private messages: LogEntryMessage[]
   private metadata?: LogEntryMetadata
+  public readonly parent?: LogEntry
+  public readonly timestamp: Date
+  public readonly key: string
+  public readonly level: LogLevel
   public readonly root: Logger
   public readonly fromStdStream?: boolean
   public readonly indent?: number
   public readonly errorData?: GardenError
   public readonly childEntriesInheritLevel?: boolean
   public readonly id?: string
+  public children: LogEntry[]
   public isPlaceholder: boolean
   public revision: number
 
   constructor(params: LogEntryConstructor) {
-    super(params.level, params.parent, params.id)
-
+    this.key = uniqid()
+    this.children = []
+    this.timestamp = new Date()
+    this.level = params.level
+    this.parent = params.parent
+    this.id = params.id
     this.root = params.root
     this.fromStdStream = params.fromStdStream
     this.indent = params.indent
@@ -138,7 +149,7 @@ export class LogEntry extends LogNode {
    * 2. append is always set explicitly (the next message does not inherit the previous value)
    * 3. next metadata is merged with the previous metadata
    */
-  protected update(updateParams: UpdateLogEntryParams): void {
+  private update(updateParams: UpdateLogEntryParams): void {
     this.revision = this.revision + 1
     const latestMessage = this.getLatestMessage()
 
@@ -196,7 +207,7 @@ export class LogEntry extends LogNode {
     }
   }
 
-  protected createNode(params: CreateNodeParams) {
+  private createNode(params: CreateNodeParams) {
     const indent = params.indent !== undefined ? params.indent : (this.indent || 0) + 1
 
     // If childEntriesInheritLevel is set to true, all children must have a level geq to the level
@@ -219,8 +230,37 @@ export class LogEntry extends LogNode {
     })
   }
 
-  protected onGraphChange(node: LogEntry) {
-    this.root.onGraphChange(node)
+  private addNode(params: CreateNodeParams): LogEntry {
+    const entry = this.createNode(params)
+    if (this.root.storeEntries) {
+      this.children.push(entry)
+    }
+    this.root.onGraphChange(entry)
+    return entry
+  }
+
+  silly(params: string | LogEntryParams): LogEntry {
+    return this.addNode(resolveCreateParams(LogLevel.silly, params))
+  }
+
+  debug(params: string | LogEntryParams): LogEntry {
+    return this.addNode(resolveCreateParams(LogLevel.debug, params))
+  }
+
+  verbose(params: string | LogEntryParams): LogEntry {
+    return this.addNode(resolveCreateParams(LogLevel.verbose, params))
+  }
+
+  info(params: string | LogEntryParams): LogEntry {
+    return this.addNode(resolveCreateParams(LogLevel.info, params))
+  }
+
+  warn(params: string | LogEntryParams): LogEntry {
+    return this.addNode(resolveCreateParams(LogLevel.warn, params))
+  }
+
+  error(params: string | LogEntryParams): LogEntry {
+    return this.addNode(resolveCreateParams(LogLevel.error, params))
   }
 
   getMetadata() {
@@ -265,44 +305,44 @@ export class LogEntry extends LogNode {
 
   // Preserves status
   setState(params?: string | UpdateLogEntryParams): LogEntry {
-    this.deepUpdate({ ...resolveParams(params) })
-    this.onGraphChange(this)
+    this.deepUpdate({ ...resolveUpdateParams(params) })
+    this.root.onGraphChange(this)
     return this
   }
 
   setDone(params?: string | Omit<UpdateLogEntryParams, "status">): LogEntry {
-    this.deepUpdate({ ...resolveParams(params), status: "done" })
-    this.onGraphChange(this)
+    this.deepUpdate({ ...resolveUpdateParams(params), status: "done" })
+    this.root.onGraphChange(this)
     return this
   }
 
   setSuccess(params?: string | Omit<UpdateLogEntryParams, "status" & "symbol">): LogEntry {
     this.deepUpdate({
-      ...resolveParams(params),
+      ...resolveUpdateParams(params),
       symbol: "success",
       status: "success",
     })
-    this.onGraphChange(this)
+    this.root.onGraphChange(this)
     return this
   }
 
   setError(params?: string | Omit<UpdateLogEntryParams, "status" & "symbol">): LogEntry {
     this.deepUpdate({
-      ...resolveParams(params),
+      ...resolveUpdateParams(params),
       symbol: "error",
       status: "error",
     })
-    this.onGraphChange(this)
+    this.root.onGraphChange(this)
     return this
   }
 
   setWarn(param?: string | Omit<UpdateLogEntryParams, "status" & "symbol">): LogEntry {
     this.deepUpdate({
-      ...resolveParams(param),
+      ...resolveUpdateParams(param),
       symbol: "warning",
       status: "warn",
     })
-    this.onGraphChange(this)
+    this.root.onGraphChange(this)
     return this
   }
 
@@ -314,7 +354,7 @@ export class LogEntry extends LogNode {
     // Stop gracefully if still in active state
     if (this.getLatestMessage().status === "active") {
       this.update({ symbol: "empty", status: "done" })
-      this.onGraphChange(this)
+      this.root.onGraphChange(this)
     }
     return this
   }
@@ -335,4 +375,11 @@ export class LogEntry extends LogNode {
       .flatMap((entry) => entry.getMessages()?.map((message) => message.msg))
       .join("\n")
   }
+
+  /**
+   * Returns the duration in seconds, defaults to 2 decimal precision
+   */
+  getDuration(precision: number = 2): number {
+    return round((new Date().getTime() - this.timestamp.getTime()) / 1000, precision)
+  }
 }