From e9710e51a29d519ad0e1935c6c8f3c2fd088de63 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ey=C3=BE=C3=B3r=20Magn=C3=BAsson?= Date: Mon, 4 Jan 2021 20:33:25 +0100 Subject: [PATCH] improvement(enterprise): include message metadata with log entries --- core/src/enterprise/buffered-event-stream.ts | 40 ++++++--- core/src/events.ts | 4 +- core/src/logger/log-entry.ts | 70 ++++++++-------- core/src/logger/log-node.ts | 6 +- core/src/logger/logger.ts | 2 +- core/src/logger/renderers.ts | 34 ++++---- core/src/logger/util.ts | 2 +- .../logger/writers/fancy-terminal-writer.ts | 2 +- .../writers/fullscreen-terminal-writer.ts | 2 +- core/test/helpers.ts | 2 +- core/test/unit/src/cli/cli.ts | 4 +- core/test/unit/src/commands/run/workflow.ts | 2 +- .../src/enterprise/buffered-event-stream.ts | 14 ++-- core/test/unit/src/logger/log-entry.ts | 82 ++++++++++--------- core/test/unit/src/logger/log-node.ts | 7 +- core/test/unit/src/logger/logger.ts | 15 ++-- core/test/unit/src/logger/renderers.ts | 20 +++-- .../logger/writers/basic-terminal-writer.ts | 7 +- .../logger/writers/fancy-terminal-writer.ts | 7 +- .../unit/src/logger/writers/file-writer.ts | 7 +- .../logger/writers/json-terminal-writer.ts | 7 +- core/test/unit/src/server/server.ts | 6 +- core/test/unit/src/util/util.ts | 4 +- 23 files changed, 186 insertions(+), 160 deletions(-) diff --git a/core/src/enterprise/buffered-event-stream.ts b/core/src/enterprise/buffered-event-stream.ts index 0aae8e15e6..d2def002c6 100644 --- a/core/src/enterprise/buffered-event-stream.ts +++ b/core/src/enterprise/buffered-event-stream.ts @@ -7,8 +7,10 @@ */ import Bluebird from "bluebird" +import { omit } from "lodash" + import { Events, EventName, EventBus, eventNames } from "../events" -import { LogEntryMetadata, LogEntry } from "../logger/log-entry" +import { LogEntryMetadata, LogEntry, LogEntryMessage } from "../logger/log-entry" import { chainMessages } from "../logger/renderers" import { got } from "../util/http" import { makeAuthHeader } from "./auth" @@ -21,26 +23,38 @@ export type StreamEvent = { timestamp: Date } -export interface LogEntryEvent { +// TODO: Remove data, section, timestamp and msg once we've updated GE (it's included in the message) +export interface LogEntryEventPayload { key: string parentKey: string | null revision: number msg: string | string[] timestamp: Date level: LogLevel + message: Omit data?: any section?: string metadata?: LogEntryMetadata } -export function formatLogEntryForEventStream(entry: LogEntry): LogEntryEvent { - const { section, data } = entry.getMessageState() +export function formatLogEntryForEventStream(entry: LogEntry): LogEntryEventPayload { + const message = entry.getLatestMessage() const { key, revision, level } = entry const parentKey = entry.parent ? entry.parent.key : null const metadata = entry.getMetadata() - const msg = chainMessages(entry.getMessageStates() || []) - const timestamp = new Date() - return { key, parentKey, revision, msg, data, metadata, section, timestamp, level } + const msg = chainMessages(entry.getMessages() || []) + return { + key, + parentKey, + revision, + msg, + data: message.data, + metadata, + section: message.section, + timestamp: message.timestamp, + level, + message: omit(message, "timestamp"), + } } interface StreamTarget { @@ -70,7 +84,7 @@ export interface ApiEventBatch extends ApiBatchBase { } export interface ApiLogBatch extends ApiBatchBase { - logEntries: LogEntryEvent[] + logEntries: LogEntryEventPayload[] } export const controlEventNames: Set = new Set(["_workflowRunRegistered"]) @@ -103,7 +117,7 @@ export class BufferedEventStream { private intervalId: NodeJS.Timer | null private bufferedEvents: StreamEvent[] - private bufferedLogEntries: LogEntryEvent[] + private bufferedLogEntries: LogEntryEventPayload[] protected intervalMsec = 1000 /** @@ -116,7 +130,7 @@ export class BufferedEventStream { constructor(log: LogEntry, sessionId: string) { this.sessionId = sessionId this.log = log - this.log.root.events.onAny((_name: string, payload: LogEntryEvent) => { + this.log.root.events.onAny((_name: string, payload: LogEntryEventPayload) => { this.streamLogEntry(payload) }) this.bufferedEvents = [] @@ -153,7 +167,7 @@ export class BufferedEventStream { // We maintain this map to facilitate unsubscribing from events when the Garden instance is closed. const gardenEventListeners = {} for (const gardenEventName of eventNames) { - const listener = (payload: LogEntryEvent) => this.streamEvent(gardenEventName, payload) + const listener = (payload: LogEntryEventPayload) => this.streamEvent(gardenEventName, payload) gardenEventListeners[gardenEventName] = listener eventBus.on(gardenEventName, listener) } @@ -205,7 +219,7 @@ export class BufferedEventStream { } } - streamLogEntry(logEntry: LogEntryEvent) { + streamLogEntry(logEntry: LogEntryEventPayload) { if (this.streamLogEntries) { this.bufferedLogEntries.push(logEntry) } @@ -232,7 +246,7 @@ export class BufferedEventStream { await this.postToTargets(`${events.length} events`, "events", data) } - async flushLogEntries(logEntries: LogEntryEvent[]) { + async flushLogEntries(logEntries: LogEntryEventPayload[]) { if (logEntries.length === 0 || !this.garden) { return } diff --git a/core/src/events.ts b/core/src/events.ts index e23544fa92..35b01b7479 100644 --- a/core/src/events.ts +++ b/core/src/events.ts @@ -9,7 +9,7 @@ import { omit } from "lodash" import { EventEmitter2 } from "eventemitter2" import { GraphResult } from "./task-graph" -import { LogEntryEvent } from "./enterprise/buffered-event-stream" +import { LogEntryEventPayload } from "./enterprise/buffered-event-stream" import { ServiceStatus } from "./types/service" import { RunStatus } from "./types/plugin/base" import { Omit } from "./util/util" @@ -55,7 +55,7 @@ export class EventBus extends EventEmitter2 { */ export interface LoggerEvents { _test: any - logEntry: LogEntryEvent + logEntry: LogEntryEventPayload } export type LoggerEventName = keyof LoggerEvents diff --git a/core/src/logger/log-entry.ts b/core/src/logger/log-entry.ts index e2b77eb8fc..9043eb40fe 100644 --- a/core/src/logger/log-entry.ts +++ b/core/src/logger/log-entry.ts @@ -53,8 +53,8 @@ interface MessageBase { maxSectionWidth?: number } -export interface MessageState extends MessageBase { - timestamp: number +export interface LogEntryMessage extends MessageBase { + timestamp: Date } export interface UpdateLogEntryParams extends MessageBase { @@ -63,8 +63,6 @@ export interface UpdateLogEntryParams extends MessageBase { export interface LogEntryParams extends UpdateLogEntryParams { error?: GardenError - data?: any // to be rendered as e.g. YAML or JSON - dataFormat?: "json" | "yaml" // how to render the data object indent?: number childEntriesInheritLevel?: boolean fromStdStream?: boolean @@ -89,7 +87,7 @@ function resolveParams(params?: string | UpdateLogEntryParams): UpdateLogEntryPa } export class LogEntry extends LogNode { - private messageStates?: MessageState[] + private messages?: LogEntryMessage[] private metadata?: LogEntryMetadata public readonly root: Logger public readonly fromStdStream?: boolean @@ -130,38 +128,38 @@ export class LogEntry extends LogNode { /** * Updates the log entry with a few invariants: * 1. msg, emoji, section, status, and symbol can only be replaced with a value of same type, not removed - * 2. append is always set explicitly (the next message state does not inherit the previous value) + * 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 { this.revision = this.revision + 1 - const messageState = this.getMessageState() + const latestMessage = this.getLatestMessage() // Explicitly set all the fields so the shape stays consistent - const nextMessageState: MessageState = { + const nextMessage: LogEntryMessage = { // Ensure empty string gets set - msg: typeof updateParams.msg === "string" ? updateParams.msg : messageState.msg, - emoji: updateParams.emoji || messageState.emoji, - section: updateParams.section || messageState.section, - status: updateParams.status || messageState.status, - symbol: updateParams.symbol || messageState.symbol, - data: updateParams.data || messageState.data, - dataFormat: updateParams.dataFormat || messageState.dataFormat, - // Next state does not inherit the append field + msg: typeof updateParams.msg === "string" ? updateParams.msg : latestMessage.msg, + emoji: updateParams.emoji || latestMessage.emoji, + section: updateParams.section || latestMessage.section, + status: updateParams.status || latestMessage.status, + symbol: updateParams.symbol || latestMessage.symbol, + data: updateParams.data || latestMessage.data, + dataFormat: updateParams.dataFormat || latestMessage.dataFormat, + // Next message does not inherit the append field append: updateParams.append, - timestamp: Date.now(), + timestamp: new Date(), maxSectionWidth: - updateParams.maxSectionWidth !== undefined ? updateParams.maxSectionWidth : messageState.maxSectionWidth, + updateParams.maxSectionWidth !== undefined ? updateParams.maxSectionWidth : latestMessage.maxSectionWidth, } // Hack to preserve section alignment if spinner disappears - const hadSpinner = messageState.status === "active" - const hasSymbolOrSpinner = nextMessageState.symbol || nextMessageState.status === "active" - if (nextMessageState.section && hadSpinner && !hasSymbolOrSpinner) { - nextMessageState.symbol = "empty" + const hadSpinner = latestMessage.status === "active" + const hasSymbolOrSpinner = nextMessage.symbol || nextMessage.status === "active" + if (nextMessage.section && hadSpinner && !hasSymbolOrSpinner) { + nextMessage.symbol = "empty" } - this.messageStates = [...(this.messageStates || []), nextMessageState] + this.messages = [...(this.messages || []), nextMessage] if (updateParams.metadata) { this.metadata = { ...(this.metadata || {}), ...updateParams.metadata } @@ -170,14 +168,14 @@ export class LogEntry extends LogNode { // Update node and child nodes private deepUpdate(updateParams: UpdateLogEntryParams): void { - const wasActive = this.getMessageState().status === "active" + const wasActive = this.getLatestMessage().status === "active" this.update(updateParams) // Stop active child nodes if no longer active if (wasActive && updateParams.status !== "active") { getChildEntries(this).forEach((entry) => { - if (entry.getMessageState().status === "active") { + if (entry.getLatestMessage().status === "active") { entry.update({ status: "done" }) } }) @@ -210,23 +208,23 @@ export class LogEntry extends LogNode { return this.metadata } - getMessageStates() { - return this.messageStates + getMessages() { + return this.messages } /** - * Returns a deep copy of the latest message state, if availble. - * Otherwise return an empty object of type MessageState for convenience. + * Returns a deep copy of the latest message, if availble. + * Otherwise returns an empty object of type LogEntryMessage for convenience. */ - getMessageState() { - if (!this.messageStates) { - return {} + getLatestMessage() { + if (!this.messages) { + return {} } // Use spread operator to clone the array - const msgState = [...this.messageStates][this.messageStates.length - 1] + const message = [...this.messages][this.messages.length - 1] // ...and the object itself - return { ...msgState } + return { ...message } } placeholder({ @@ -296,7 +294,7 @@ export class LogEntry extends LogNode { stop() { // Stop gracefully if still in active state - if (this.getMessageState().status === "active") { + if (this.getLatestMessage().status === "active") { this.update({ symbol: "empty", status: "done" }) this.onGraphChange(this) } @@ -316,7 +314,7 @@ export class LogEntry extends LogNode { toString(filter?: (log: LogEntry) => boolean) { return this.getChildEntries() .filter((entry) => (filter ? filter(entry) : true)) - .flatMap((entry) => entry.getMessageStates()?.map((state) => state.msg)) + .flatMap((entry) => entry.getMessages()?.map((message) => message.msg)) .join("\n") } } diff --git a/core/src/logger/log-node.ts b/core/src/logger/log-node.ts index 4e979e805b..8f6c2e0c20 100644 --- a/core/src/logger/log-node.ts +++ b/core/src/logger/log-node.ts @@ -40,13 +40,13 @@ export function resolveParams(level: LogLevel, params: string | LogEntryParams): } export abstract class LogNode { - public readonly timestamp: number + public readonly timestamp: Date public readonly key: string public readonly children: LogEntry[] constructor(public readonly level: LogLevel, public readonly parent?: LogEntry, public readonly id?: string) { this.key = uniqid() - this.timestamp = Date.now() + this.timestamp = new Date() this.children = [] } @@ -94,6 +94,6 @@ export abstract class LogNode { * Returns the duration in seconds, defaults to 2 decimal precision */ getDuration(precision: number = 2): number { - return round((Date.now() - this.timestamp) / 1000, precision) + return round((new Date().getTime() - this.timestamp.getTime()) / 1000, precision) } } diff --git a/core/src/logger/logger.ts b/core/src/logger/logger.ts index bafd04afe2..8ea41abefa 100644 --- a/core/src/logger/logger.ts +++ b/core/src/logger/logger.ts @@ -176,7 +176,7 @@ export class Logger extends LogNode { } filterBySection(section: string): LogEntry[] { - return getChildEntries(this).filter((entry) => entry.getMessageState().section === section) + return getChildEntries(this).filter((entry) => entry.getLatestMessage().section === section) } findById(id: string): LogEntry | void { diff --git a/core/src/logger/renderers.ts b/core/src/logger/renderers.ts index e24d75f756..2444b256f9 100644 --- a/core/src/logger/renderers.ts +++ b/core/src/logger/renderers.ts @@ -14,7 +14,7 @@ import cliTruncate = require("cli-truncate") import stringWidth = require("string-width") import hasAnsi = require("has-ansi") -import { LogEntry, MessageState } from "./log-entry" +import { LogEntry, LogEntryMessage } from "./log-entry" import { JsonLogEntry } from "./writers/json-terminal-writer" import { highlightYaml, PickFromUnion, safeDumpYaml } from "../util/util" import { printEmoji, formatGardenError } from "./util" @@ -62,8 +62,8 @@ export function getLeftOffset(entry: LogEntry) { * Returns the most recent message's `msg` field if it has `append` set to `false`. * Otherwise returns longest chain of messages with `append: true` (starting from the most recent message). */ -export function chainMessages(messageStates: MessageState[], chain: string[] = []): string | string[] { - const latestState = messageStates[messageStates.length - 1] +export function chainMessages(messages: LogEntryMessage[], chain: string[] = []): string | string[] { + const latestState = messages[messages.length - 1] if (!latestState) { return chain.length === 1 ? chain[0] : chain.reverse() } @@ -71,7 +71,7 @@ export function chainMessages(messageStates: MessageState[], chain: string[] = [ chain = latestState.msg !== undefined ? [...chain, latestState.msg] : chain if (latestState.append) { - return chainMessages(messageStates.slice(0, -1), chain) + return chainMessages(messages.slice(0, -1), chain) } return chain.reverse() } @@ -82,7 +82,7 @@ export function leftPad(entry: LogEntry): string { } export function renderEmoji(entry: LogEntry): string { - const { emoji } = entry.getMessageState() + const { emoji } = entry.getLatestMessage() if (emoji) { return printEmoji(emoji, entry) + " " } @@ -95,12 +95,12 @@ export function renderError(entry: LogEntry) { return formatGardenError(error) } - const msg = chainMessages(entry.getMessageStates() || []) + const msg = chainMessages(entry.getMessages() || []) return isArray(msg) ? msg.join(" ") : msg || "" } export function renderSymbolBasic(entry: LogEntry): string { - let { symbol, status } = entry.getMessageState() + let { symbol, status } = entry.getLatestMessage() if (symbol === "empty") { return " " @@ -113,7 +113,7 @@ export function renderSymbolBasic(entry: LogEntry): string { } export function renderSymbol(entry: LogEntry): string { - const { symbol } = entry.getMessageState() + const { symbol } = entry.getLatestMessage() if (symbol === "empty") { return " " @@ -129,10 +129,10 @@ export function renderTimestamp(entry: LogEntry): string { } export function getTimestamp(entry: LogEntry): string { - const { timestamp } = entry.getMessageState() + const { timestamp } = entry.getLatestMessage() let formatted = "" try { - formatted = new Date(timestamp).toISOString() + formatted = timestamp.toISOString() } catch (_err) {} return formatted @@ -140,8 +140,8 @@ export function getTimestamp(entry: LogEntry): string { export function renderMsg(entry: LogEntry): string { const { fromStdStream } = entry - const { status } = entry.getMessageState() - const msg = chainMessages(entry.getMessageStates() || []) + const { status } = entry.getLatestMessage() + const msg = chainMessages(entry.getMessages() || []) if (fromStdStream) { return isArray(msg) ? msg.join(" ") : msg || "" @@ -157,7 +157,7 @@ export function renderMsg(entry: LogEntry): string { } export function renderData(entry: LogEntry): string { - const { data, dataFormat } = entry.getMessageState() + const { data, dataFormat } = entry.getLatestMessage() if (!data) { return "" } @@ -169,7 +169,7 @@ export function renderData(entry: LogEntry): string { } export function renderSection(entry: LogEntry): string { - const { msg, section, maxSectionWidth } = entry.getMessageState() + const { msg: msg, section, maxSectionWidth } = entry.getLatestMessage() if (section && msg) { return `${styleSection(section, maxSectionWidth)} → ` } else if (section) { @@ -182,7 +182,7 @@ export function renderSection(entry: LogEntry): string { * Formats entries for both fancy writer and basic terminal writer. */ export function formatForTerminal(entry: LogEntry, type: PickFromUnion): string { - const { msg, emoji, section, symbol, data } = entry.getMessageState() + const { msg: msg, emoji, section, symbol, data } = entry.getLatestMessage() const empty = [msg, section, emoji, symbol, data].every((val) => val === undefined) if (empty) { @@ -227,9 +227,9 @@ export function basicRender(entry: LogEntry, logger: Logger): string | null { // TODO: Include individual message states with timestamp export function formatForJson(entry: LogEntry): JsonLogEntry { - const { section, data } = entry.getMessageState() + const { section, data } = entry.getLatestMessage() const metadata = entry.getMetadata() - const msg = chainMessages(entry.getMessageStates() || []) + const msg = chainMessages(entry.getMessages() || []) return { msg: cleanForJSON(msg), data, diff --git a/core/src/logger/util.ts b/core/src/logger/util.ts index a41c14b8e5..d763bce3e0 100644 --- a/core/src/logger/util.ts +++ b/core/src/logger/util.ts @@ -83,7 +83,7 @@ export function tailChildEntries(node: LogNode | LogEntry, level: LogLevel, line traverseChildren(node, (entry) => { if (entry.level <= level) { output.push(entry) - const msg = entry.getMessageState().msg || "" + const msg = entry.getLatestMessage().msg || "" outputLines += msg.length > 0 ? msg.split("\n").length : 0 if (outputLines >= lines) { diff --git a/core/src/logger/writers/fancy-terminal-writer.ts b/core/src/logger/writers/fancy-terminal-writer.ts index 29ad28cddf..15d2eb3546 100644 --- a/core/src/logger/writers/fancy-terminal-writer.ts +++ b/core/src/logger/writers/fancy-terminal-writer.ts @@ -181,7 +181,7 @@ export class FancyTerminalWriter extends Writer { let spinnerX: number let spinnerCoords: Coords | undefined - if (entry.getMessageState().status === "active") { + if (entry.getLatestMessage().status === "active") { spinnerX = getLeftOffset(entry) spinnerFrame = this.tickSpinner(entry.key) spinnerCoords = [spinnerX, currentLineNumber] diff --git a/core/src/logger/writers/fullscreen-terminal-writer.ts b/core/src/logger/writers/fullscreen-terminal-writer.ts index 7ac7956610..ac1749ca29 100644 --- a/core/src/logger/writers/fullscreen-terminal-writer.ts +++ b/core/src/logger/writers/fullscreen-terminal-writer.ts @@ -464,7 +464,7 @@ export class FullscreenTerminalWriter extends Writer { let spinnerFrame = "" let spinnerX: number | undefined - if (entry.getMessageState().status === "active") { + if (entry.getLatestMessage().status === "active") { spinnerX = leftPad(entry).length spinnerFrame = this.tickSpinner(entry.key) } else { diff --git a/core/test/helpers.ts b/core/test/helpers.ts index bb1f78c480..bf31f237f9 100644 --- a/core/test/helpers.ts +++ b/core/test/helpers.ts @@ -517,7 +517,7 @@ export function getLogMessages(log: LogEntry, filter?: (log: LogEntry) => boolea return log .getChildEntries() .filter((entry) => (filter ? filter(entry) : true)) - .flatMap((entry) => entry.getMessageStates()?.map((state) => stripAnsi(state.msg || "")) || []) + .flatMap((entry) => entry.getMessages()?.map((state) => stripAnsi(state.msg || "")) || []) } const skipGroups = gardenEnv.GARDEN_SKIP_TESTS.split(" ") diff --git a/core/test/unit/src/cli/cli.ts b/core/test/unit/src/cli/cli.ts index b77f016c41..f8dafb4df6 100644 --- a/core/test/unit/src/cli/cli.ts +++ b/core/test/unit/src/cli/cli.ts @@ -414,7 +414,7 @@ describe("cli", () => { await cli.run({ args, exitOnError: false }) - const serverStatus = cmd.server!["statusLog"].getMessageState().msg! + const serverStatus = cmd.server!["statusLog"].getLatestMessage().msg! expect(stripAnsi(serverStatus)).to.equal(`Garden dashboard running at ${cmd.server!.getUrl()}`) }) @@ -468,7 +468,7 @@ describe("cli", () => { await server.close() } - const serverStatus = cmd.server!["statusLog"].getMessageState().msg! + const serverStatus = cmd.server!["statusLog"].getLatestMessage().msg! expect(stripAnsi(serverStatus)).to.equal(`Garden dashboard running at ${server.getUrl()}`) }) diff --git a/core/test/unit/src/commands/run/workflow.ts b/core/test/unit/src/commands/run/workflow.ts index c61dc4e9be..c4b4553a20 100644 --- a/core/test/unit/src/commands/run/workflow.ts +++ b/core/test/unit/src/commands/run/workflow.ts @@ -150,7 +150,7 @@ describe("RunWorkflowCommand", () => { }) function filterLogEntries(entries: LogEntry[], msgRegex: RegExp): LogEntry[] { - return entries.filter((e) => msgRegex.test(e.getMessageState().msg || "")) + return entries.filter((e) => msgRegex.test(e.getLatestMessage().msg || "")) } it("should collect log outputs from a command step", async () => { diff --git a/core/test/unit/src/enterprise/buffered-event-stream.ts b/core/test/unit/src/enterprise/buffered-event-stream.ts index 68c95dd0e5..ed39c84d69 100644 --- a/core/test/unit/src/enterprise/buffered-event-stream.ts +++ b/core/test/unit/src/enterprise/buffered-event-stream.ts @@ -7,7 +7,11 @@ */ import { expect } from "chai" -import { StreamEvent, LogEntryEvent, BufferedEventStream } from "../../../../src/enterprise/buffered-event-stream" +import { + StreamEvent, + LogEntryEventPayload, + BufferedEventStream, +} from "../../../../src/enterprise/buffered-event-stream" import { getLogger } from "../../../../src/logger/logger" import { Garden } from "../../../../src/garden" import { makeTestGardenA } from "../../../helpers" @@ -32,7 +36,7 @@ describe("BufferedEventStream", () => { it("should flush events and log entries emitted by a connected event emitter", async () => { const flushedEvents: StreamEvent[] = [] - const flushedLogEntries: LogEntryEvent[] = [] + const flushedLogEntries: LogEntryEventPayload[] = [] const log = getLogger().placeholder() @@ -42,7 +46,7 @@ describe("BufferedEventStream", () => { flushedEvents.push(...events) return Promise.resolve() } - bufferedEventStream["flushLogEntries"] = (logEntries: LogEntryEvent[]) => { + bufferedEventStream["flushLogEntries"] = (logEntries: LogEntryEventPayload[]) => { flushedLogEntries.push(...logEntries) return Promise.resolve() } @@ -61,7 +65,7 @@ describe("BufferedEventStream", () => { it("should only flush events or log entries emitted by the last connected Garden bus", async () => { const flushedEvents: StreamEvent[] = [] - const flushedLogEntries: LogEntryEvent[] = [] + const flushedLogEntries: LogEntryEventPayload[] = [] const log = getLogger().placeholder() @@ -71,7 +75,7 @@ describe("BufferedEventStream", () => { flushedEvents.push(...events) return Promise.resolve() } - bufferedEventStream["flushLogEntries"] = (logEntries: LogEntryEvent[]) => { + bufferedEventStream["flushLogEntries"] = (logEntries: LogEntryEventPayload[]) => { flushedLogEntries.push(...logEntries) return Promise.resolve() } diff --git a/core/test/unit/src/logger/log-entry.ts b/core/test/unit/src/logger/log-entry.ts index 0595b1a015..1d6f2ddb1e 100644 --- a/core/test/unit/src/logger/log-entry.ts +++ b/core/test/unit/src/logger/log-entry.ts @@ -8,14 +8,15 @@ import { expect } from "chai" -import { getLogger } from "../../../../src/logger/logger" +import { getLogger, Logger } from "../../../../src/logger/logger" import { freezeTime } from "../../../helpers" -import { TaskMetadata } from "../../../../src/logger/log-entry" +import { LogEntryMetadata, TaskMetadata } from "../../../../src/logger/log-entry" -const logger: any = getLogger() +const logger: Logger = getLogger() beforeEach(() => { - logger.children = [] + // tslint:disable-next-line: prettier + (logger["children"] as any) = [] }) describe("LogEntry", () => { @@ -46,28 +47,29 @@ describe("LogEntry", () => { expect(indents).to.eql([undefined, 1, 2, 3, 2, 3]) }) context("metadata", () => { + const metadata: LogEntryMetadata = { workflowStep: { index: 1 } } it("should pass on any metadata to placeholder or child nodes", () => { - const ph1 = logger.placeholder({ metadata: { foo: "bar" } }) + const ph1 = logger.placeholder({ metadata }) const ph2 = ph1.placeholder() - const entry = logger.info({ msg: "hello", metadata: { foo: "bar" } }) + const entry = logger.info({ msg: "hello", metadata }) const ph3 = entry.placeholder() const nested = entry.info("nested") const entry2 = logger.info("hello") - const ph4 = entry2.placeholder({ msg: "placeholder", metadata: { foo: "bar" } }) - expect(ph1.metadata).to.eql({ foo: "bar" }) - expect(ph2.metadata).to.eql({ foo: "bar" }) - expect(ph3.metadata).to.eql({ foo: "bar" }) - expect(ph4.metadata).to.eql({ foo: "bar" }, "ph4") - expect(entry.metadata).to.eql({ foo: "bar" }) - expect(entry2.metadata).to.eql(undefined) - expect(nested.metadata).to.eql({ foo: "bar" }) + const ph4 = entry2.placeholder({ metadata }) + expect(ph1.getMetadata()).to.eql(metadata) + expect(ph2.getMetadata()).to.eql(metadata) + expect(ph3.getMetadata()).to.eql(metadata) + expect(ph4.getMetadata()).to.eql(metadata) + expect(entry.getMetadata()).to.eql(metadata) + expect(entry2.getMetadata()).to.eql(undefined) + expect(nested.getMetadata()).to.eql(metadata) }) it("should not set metadata on parent when creating placeholders or child nodes", () => { const entry = logger.info("hello") - const ph = entry.placeholder({ metadata: { foo: "bar" } }) - expect(entry.metadata).to.eql(undefined) - expect(ph.metadata).to.eql({ foo: "bar" }) + const ph = entry.placeholder({ metadata }) + expect(entry.getMetadata()).to.eql(undefined) + expect(ph.getMetadata()).to.eql(metadata) }) }) context("childEntriesInheritLevel is set to true", () => { @@ -104,7 +106,7 @@ describe("LogEntry", () => { maxSectionWidth: undefined, } it("should update entry state", () => { - const timestamp = freezeTime().valueOf() + const timestamp = freezeTime() const taskMetadata: TaskMetadata = { type: "a", key: "a", @@ -125,7 +127,7 @@ describe("LogEntry", () => { maxSectionWidth: 8, }) - expect(entry.getMessageStates()).to.eql([ + expect(entry.getMessages()).to.eql([ { msg: "hello", emoji: "haircut", @@ -142,7 +144,7 @@ describe("LogEntry", () => { expect(entry.getMetadata()).to.eql({ task: taskMetadata }) }) it("should update maxSectionWidth to zero", () => { - const timestamp = freezeTime().valueOf() + const timestamp = freezeTime() const entry = logger.placeholder() entry.setState({ msg: "hello", @@ -154,7 +156,7 @@ describe("LogEntry", () => { maxSectionWidth: 0, }) - expect(entry.getMessageStates()).to.eql([ + expect(entry.getMessages()).to.eql([ { msg: "hello", emoji: "haircut", @@ -170,7 +172,7 @@ describe("LogEntry", () => { ]) }) it("should overwrite previous values", () => { - const timestamp = freezeTime().valueOf() + const timestamp = freezeTime() const entry = logger.placeholder() entry.setState({ msg: "hello", @@ -191,7 +193,7 @@ describe("LogEntry", () => { entry.setState({ maxSectionWidth: 0, }) - expect(entry.getMessageStates()).to.eql([ + expect(entry.getMessages()).to.eql([ { msg: "hello", emoji: "haircut", @@ -231,20 +233,20 @@ describe("LogEntry", () => { ]) }) it("should set the 'append' field separately for each message state", () => { - const timestamp = freezeTime().valueOf() + const timestamp = freezeTime() const entry = logger.placeholder() entry.setState({ append: true }) - expect(entry.getMessageStates()).to.eql([{ ...emptyState, append: true, timestamp }]) + expect(entry.getMessages()).to.eql([{ ...emptyState, append: true, timestamp }]) entry.setState({ msg: "boo" }) - expect(entry.getMessageStates()).to.eql([ + expect(entry.getMessages()).to.eql([ { ...emptyState, append: true, timestamp }, { ...emptyState, append: undefined, msg: "boo", timestamp }, ]) entry.setState({ append: true }) - expect(entry.getMessageStates()).to.eql([ + expect(entry.getMessages()).to.eql([ { ...emptyState, append: true, timestamp }, { ...emptyState, append: undefined, msg: "boo", timestamp }, { ...emptyState, append: true, msg: "boo", timestamp }, @@ -254,12 +256,12 @@ describe("LogEntry", () => { const entry = logger.info("") entry.setSuccess() entry.setState("change text") - expect(entry.getMessageState().status).to.equal("success") + expect(entry.getLatestMessage().status).to.equal("success") }) it("should set symbol to empty if entry has section and spinner disappears (to preserve alignment)", () => { const entry = logger.info({ status: "active", section: "foo" }) entry.setState({ status: "error" }) - expect(entry.getMessageState().symbol).to.equal("empty") + expect(entry.getLatestMessage().symbol).to.equal("empty") const newEntry = logger.info({ status: "active", @@ -267,10 +269,10 @@ describe("LogEntry", () => { symbol: "info", }) newEntry.setState({ status: "error" }) - expect(newEntry.getMessageState().symbol).to.equal("info") + expect(newEntry.getLatestMessage().symbol).to.equal("info") }) it("should update the metadata property", () => { - const timestamp = freezeTime().valueOf() + const timestamp = freezeTime() const taskMetadataA: TaskMetadata = { type: "a", key: "a", @@ -286,11 +288,11 @@ describe("LogEntry", () => { entry.setState({ metadata: { task: taskMetadataA } }) expect(entry.getMetadata()).to.eql({ task: taskMetadataA }) // Message states should not change - expect(entry.getMessageStates()).to.eql([{ ...emptyState, timestamp }]) + expect(entry.getMessages()).to.eql([{ ...emptyState, timestamp }]) entry.setState({ metadata: { task: taskMetadataB } }) expect(entry.getMetadata()).to.eql({ task: taskMetadataB }) - expect(entry.getMessageStates()).to.eql([ + expect(entry.getMessages()).to.eql([ { ...emptyState, timestamp }, { ...emptyState, timestamp }, ]) @@ -300,31 +302,31 @@ describe("LogEntry", () => { it("should update entry state and set status to done", () => { const entry = logger.info("") entry.setDone() - expect(entry.getMessageState().status).to.equal("done") + expect(entry.getLatestMessage().status).to.equal("done") }) }) describe("setSuccess", () => { it("should update entry state and set status and symbol to success", () => { const entry = logger.info("") entry.setSuccess() - expect(entry.getMessageState().status).to.equal("success") - expect(entry.getMessageState().symbol).to.equal("success") + expect(entry.getLatestMessage().status).to.equal("success") + expect(entry.getLatestMessage().symbol).to.equal("success") }) }) describe("setError", () => { it("should update entry state and set status and symbol to error", () => { const entry = logger.info("") entry.setError() - expect(entry.getMessageState().status).to.equal("error") - expect(entry.getMessageState().symbol).to.equal("error") + expect(entry.getLatestMessage().status).to.equal("error") + expect(entry.getLatestMessage().symbol).to.equal("error") }) }) describe("setWarn", () => { it("should update entry state and set status and symbol to warn", () => { const entry = logger.info("") entry.setWarn() - expect(entry.getMessageState().status).to.equal("warn") - expect(entry.getMessageState().symbol).to.equal("warning") + expect(entry.getLatestMessage().status).to.equal("warn") + expect(entry.getLatestMessage().symbol).to.equal("warning") }) }) }) diff --git a/core/test/unit/src/logger/log-node.ts b/core/test/unit/src/logger/log-node.ts index 5787a8436b..7f4cfadeb1 100644 --- a/core/test/unit/src/logger/log-node.ts +++ b/core/test/unit/src/logger/log-node.ts @@ -7,12 +7,13 @@ */ import { expect } from "chai" -import { getLogger } from "../../../../src/logger/logger" +import { getLogger, Logger } from "../../../../src/logger/logger" -const logger: any = getLogger() +const logger: Logger = getLogger() beforeEach(() => { - logger.children = [] + // tslint:disable-next-line: prettier + (logger["children"] as any) = [] }) describe("LogNode", () => { diff --git a/core/test/unit/src/logger/logger.ts b/core/test/unit/src/logger/logger.ts index 573e5dfbb4..2ac66837c7 100644 --- a/core/test/unit/src/logger/logger.ts +++ b/core/test/unit/src/logger/logger.ts @@ -10,19 +10,20 @@ import { expect } from "chai" import { omit } from "lodash" import { LogLevel } from "../../../../src/logger/log-node" -import { getLogger } from "../../../../src/logger/logger" -import { LogEntryEvent, formatLogEntryForEventStream } from "../../../../src/enterprise/buffered-event-stream" +import { getLogger, Logger } from "../../../../src/logger/logger" +import { LogEntryEventPayload, formatLogEntryForEventStream } from "../../../../src/enterprise/buffered-event-stream" -const logger: any = getLogger() +const logger: Logger = getLogger() beforeEach(() => { - logger.children = [] + // tslint:disable-next-line: prettier + (logger["children"] as any) = [] }) describe("Logger", () => { describe("events", () => { - let loggerEvents: LogEntryEvent[] = [] - let listener = (event: LogEntryEvent) => loggerEvents.push(event) + let loggerEvents: LogEntryEventPayload[] = [] + let listener = (event: LogEntryEventPayload) => loggerEvents.push(event) before(() => logger.events.on("logEntry", listener)) after(() => logger.events.off("logEntry", listener)) @@ -56,7 +57,7 @@ describe("Logger", () => { logger.info({ msg: "0" }) logger.info({ msg: "a1", id: "a" }) logger.info({ msg: "a2", id: "a" }) - expect(logger.findById("a")["messageStates"][0]["msg"]).to.eql("a1") + expect(logger.findById("a")["messages"][0]["msg"]).to.eql("a1") expect(logger.findById("z")).to.be.undefined }) }) diff --git a/core/test/unit/src/logger/renderers.ts b/core/test/unit/src/logger/renderers.ts index 1f8bf73ca8..6d5a2c0a04 100644 --- a/core/test/unit/src/logger/renderers.ts +++ b/core/test/unit/src/logger/renderers.ts @@ -8,7 +8,7 @@ import { expect } from "chai" -import { getLogger } from "../../../../src/logger/logger" +import { getLogger, Logger } from "../../../../src/logger/logger" import { renderMsg, msgStyle, @@ -29,10 +29,11 @@ import stripAnsi = require("strip-ansi") import { highlightYaml, safeDumpYaml } from "../../../../src/util/util" import { freezeTime } from "../../../helpers" -const logger: any = getLogger() +const logger: Logger = getLogger() beforeEach(() => { - logger.children = [] + // tslint:disable-next-line: prettier + (logger["children"] as any) = [] }) describe("renderers", () => { @@ -126,8 +127,8 @@ describe("renderers", () => { }) describe("chainMessages", () => { it("should correctly chain log messages", () => { - const timestamp = Date.now() - const messageStateTable = [ + const timestamp = new Date() + const messagesTable = [ [ { msg: "1", append: true }, { msg: "2", append: true }, @@ -155,7 +156,7 @@ describe("renderers", () => { ], ].map((msgStates) => msgStates.map((msgState) => ({ ...msgState, timestamp }))) const expects = [["1", "2", "3"], ["1", "2", "3"], ["2", "3"], ["2", "3"], ["3"]] - messageStateTable.forEach((msgState, index) => { + messagesTable.forEach((msgState, index) => { expect(chainMessages(msgState)).to.eql(expects[index]) }) }) @@ -173,7 +174,7 @@ describe("renderers", () => { const entry = logger.info({}) expect(formatForTerminal(entry, "fancy")).to.equal("") }) - it("should return a string with a new line if any of the members of entry.messageState is not empty", () => { + it("should return a string with a new line if any of the members of entry.messages is not empty", () => { const entryMsg = logger.info({ msg: "msg" }) expect(formatForTerminal(entryMsg, "fancy")).contains("\n") @@ -217,10 +218,11 @@ describe("renderers", () => { expect(formatForTerminal(entry, "basic")).to.equal(`[${now.toISOString()}] ${msgStyle("hello world")}\n`) }) - it("should show the timestamp for the most recent message state", () => { + it("should show the timestamp for the most recent message state", async () => { const entry = logger.info("hello world") + const date = new Date(1600555650583) // Some date that's different from the current one + freezeTime(date) entry.setState("update entry") - entry.messageStates[1].timestamp = 1600555650583 expect(formatForTerminal(entry, "basic")).to.equal(`[2020-09-19T22:47:30.583Z] ${msgStyle("update entry")}\n`) }) diff --git a/core/test/unit/src/logger/writers/basic-terminal-writer.ts b/core/test/unit/src/logger/writers/basic-terminal-writer.ts index a27777a6d2..b104c3d19a 100644 --- a/core/test/unit/src/logger/writers/basic-terminal-writer.ts +++ b/core/test/unit/src/logger/writers/basic-terminal-writer.ts @@ -9,13 +9,14 @@ import { expect } from "chai" import { BasicTerminalWriter } from "../../../../../src/logger/writers/basic-terminal-writer" -import { getLogger } from "../../../../../src/logger/logger" +import { getLogger, Logger } from "../../../../../src/logger/logger" import { formatForTerminal } from "../../../../../src/logger/renderers" -const logger: any = getLogger() +const logger: Logger = getLogger() beforeEach(() => { - logger.children = [] + // tslint:disable-next-line: prettier + (logger["children"] as any) = [] }) describe("BasicTerminalWriter", () => { diff --git a/core/test/unit/src/logger/writers/fancy-terminal-writer.ts b/core/test/unit/src/logger/writers/fancy-terminal-writer.ts index 84b98f2b06..46f44e7b22 100644 --- a/core/test/unit/src/logger/writers/fancy-terminal-writer.ts +++ b/core/test/unit/src/logger/writers/fancy-terminal-writer.ts @@ -9,12 +9,13 @@ import { expect } from "chai" import { FancyTerminalWriter } from "../../../../../src/logger/writers/fancy-terminal-writer" -import { getLogger } from "../../../../../src/logger/logger" +import { getLogger, Logger } from "../../../../../src/logger/logger" -const logger: any = getLogger() +const logger: Logger = getLogger() beforeEach(() => { - logger.children = [] + // tslint:disable-next-line: prettier + (logger["children"] as any) = [] }) describe("FancyTerminalWriter", () => { diff --git a/core/test/unit/src/logger/writers/file-writer.ts b/core/test/unit/src/logger/writers/file-writer.ts index 7465b07a29..c193dcab15 100644 --- a/core/test/unit/src/logger/writers/file-writer.ts +++ b/core/test/unit/src/logger/writers/file-writer.ts @@ -11,14 +11,15 @@ import chalk from "chalk" import stripAnsi from "strip-ansi" import { LogLevel } from "../../../../../src/logger/log-node" -import { getLogger } from "../../../../../src/logger/logger" +import { getLogger, Logger } from "../../../../../src/logger/logger" import { renderError } from "../../../../../src/logger/renderers" import { render } from "../../../../../src/logger/writers/file-writer" -const logger: any = getLogger() +const logger: Logger = getLogger() beforeEach(() => { - logger.children = [] + // tslint:disable-next-line: prettier + (logger["children"] as any) = [] }) describe("FileWriter", () => { diff --git a/core/test/unit/src/logger/writers/json-terminal-writer.ts b/core/test/unit/src/logger/writers/json-terminal-writer.ts index 9a1f4be1f0..a62a6945d9 100644 --- a/core/test/unit/src/logger/writers/json-terminal-writer.ts +++ b/core/test/unit/src/logger/writers/json-terminal-writer.ts @@ -9,13 +9,14 @@ import { expect } from "chai" import { JsonTerminalWriter } from "../../../../../src/logger/writers/json-terminal-writer" -import { getLogger } from "../../../../../src/logger/logger" +import { getLogger, Logger } from "../../../../../src/logger/logger" import { freezeTime } from "../../../../helpers" -const logger: any = getLogger() +const logger: Logger = getLogger() beforeEach(() => { - logger.children = [] + // tslint:disable-next-line: prettier + (logger["children"] as any) = [] }) describe("JsonTerminalWriter", () => { diff --git a/core/test/unit/src/server/server.ts b/core/test/unit/src/server/server.ts index 85cb1d0d23..2a02a8fa79 100644 --- a/core/test/unit/src/server/server.ts +++ b/core/test/unit/src/server/server.ts @@ -41,7 +41,7 @@ describe("GardenServer", () => { it("should show no URL on startup", async () => { const line = gardenServer["statusLog"] - expect(line.getMessageState().msg).to.be.undefined + expect(line.getLatestMessage().msg).to.be.undefined }) it("should update dashboard URL with own if the external dashboard goes down", async () => { @@ -51,7 +51,7 @@ describe("GardenServer", () => { }) const line = gardenServer["statusLog"] await sleep(1) // This is enough to let go of the control loop - const status = stripAnsi(line.getMessageState().msg || "") + const status = stripAnsi(line.getLatestMessage().msg || "") expect(status).to.equal(`Garden dashboard running at ${gardenServer.getUrl()}`) }) @@ -62,7 +62,7 @@ describe("GardenServer", () => { }) const line = gardenServer["statusLog"] await sleep(1) // This is enough to let go of the control loop - const status = stripAnsi(line.getMessageState().msg || "") + const status = stripAnsi(line.getLatestMessage().msg || "") expect(status).to.equal(`Garden dashboard running at http://localhost:9800`) }) diff --git a/core/test/unit/src/util/util.ts b/core/test/unit/src/util/util.ts index 285b31b0e6..6853b97d57 100644 --- a/core/test/unit/src/util/util.ts +++ b/core/test/unit/src/util/util.ts @@ -128,7 +128,7 @@ describe("util", () => { await exec("echo", ["hello"], { stdout: createOutputStream(entry) }) - expect(entry.getMessageState().msg).to.equal(renderOutputStream("hello")) + expect(entry.getLatestMessage().msg).to.equal(renderOutputStream("hello")) }) it("should optionally pipe stderr to an output stream", async () => { @@ -137,7 +137,7 @@ describe("util", () => { await exec("sh", ["-c", "echo hello 1>&2"], { stderr: createOutputStream(entry) }) - expect(entry.getMessageState().msg).to.equal(renderOutputStream("hello")) + expect(entry.getLatestMessage().msg).to.equal(renderOutputStream("hello")) }) it("should throw a standardised error message on error", async () => {