From 45f1f917ecaf54a79431c63564d587c15329efff Mon Sep 17 00:00:00 2001 From: Thorarinn Sigurdsson Date: Tue, 13 Oct 2020 15:49:19 +0200 Subject: [PATCH] fix(cli): less noisy error rendering for workflows Previously, we were logging the details of failed tasks (along with their successfully executed dependencies, if any) when a workflow failed. We've now simplified this to only render the error messages by default, and rendering the details of the failed tasks only (without dependencies) for log levels `debug` and higher. The output logged to `error.log` has been streamlined in the same way, omitting details of successful dependencies of failed tasks. --- core/src/cli/cli.ts | 8 ++----- core/src/commands/base.ts | 11 ++++----- core/src/commands/run/workflow.ts | 33 +++++++++++++++++++------- core/src/logger/util.ts | 16 ++++++------- core/src/task-graph.ts | 2 -- core/test/unit/src/logger/renderers.ts | 2 ++ 6 files changed, 41 insertions(+), 31 deletions(-) diff --git a/core/src/cli/cli.ts b/core/src/cli/cli.ts index 5bd49c79cd..445ee22e1d 100644 --- a/core/src/cli/cli.ts +++ b/core/src/cli/cli.ts @@ -34,12 +34,12 @@ import { ERROR_LOG_FILENAME, DEFAULT_API_VERSION, DEFAULT_GARDEN_DIR_NAME, LOGS_ import { generateBasicDebugInfoReport } from "../commands/get/get-debug-info" import { AnalyticsHandler } from "../analytics/analytics" import { defaultDotIgnoreFiles } from "../util/fs" -import { renderError } from "../logger/renderers" import { BufferedEventStream } from "../enterprise/buffered-event-stream" import { makeEnterpriseContext } from "../enterprise/init" import { GardenProcess } from "../db/entities/garden-process" import { DashboardEventStream } from "../server/dashboard-event-stream" import { GardenPlugin } from "../types/plugin/plugin" +import { formatGardenError } from "../logger/util" export async function makeDummyGarden(root: string, gardenOpts: GardenOpts = {}) { const environments = gardenOpts.environmentName @@ -466,13 +466,9 @@ ${renderCommands(commands)} if (gardenErrors.length > 0) { for (const error of gardenErrors) { - const entry = logger.error({ - msg: error.message, - error, - }) // Output error details to console when log level is silly logger.silly({ - msg: renderError(entry), + msg: formatGardenError(error), }) } diff --git a/core/src/commands/base.ts b/core/src/commands/base.ts index c9c43df652..cf87e9883a 100644 --- a/core/src/commands/base.ts +++ b/core/src/commands/base.ts @@ -11,7 +11,7 @@ import chalk from "chalk" import dedent = require("dedent") import inquirer = require("inquirer") import stripAnsi from "strip-ansi" -import { fromPairs } from "lodash" +import { fromPairs, pickBy, size } from "lodash" import { joi, joiIdentifierMap, joiStringMap } from "../config/common" import { InternalError, RuntimeError, GardenBaseError } from "../exceptions" @@ -431,12 +431,11 @@ export async function handleProcessResults( graphResults, } - const failed = Object.values(results.taskResults).filter((r) => r && r.error).length + const failed = pickBy(results.taskResults, (r) => r && r.error) + const failedCount = size(failed) - if (failed) { - const error = new RuntimeError(`${failed} ${taskType} task(s) failed!`, { - results, - }) + if (failedCount > 0) { + const error = new RuntimeError(`${failedCount} ${taskType} task(s) failed!`, { results: failed }) return { result, errors: [error], restartRequired: false } } diff --git a/core/src/commands/run/workflow.ts b/core/src/commands/run/workflow.ts index e3d86a39ad..926cf8358c 100644 --- a/core/src/commands/run/workflow.ts +++ b/core/src/commands/run/workflow.ts @@ -8,7 +8,7 @@ import chalk from "chalk" import { cloneDeep, merge, repeat } from "lodash" -import { printHeader, getTerminalWidth, formatGardenError } from "../../logger/util" +import { printHeader, getTerminalWidth, formatGardenError, renderMessageWithDivider } from "../../logger/util" import { Command, CommandParams, CommandResult } from "../base" import { dedent, wordWrap, deline } from "../../util/string" import { Garden } from "../../garden" @@ -332,17 +332,26 @@ export function logErrors( ) { const description = formattedStepDescription(stepIndex, stepCount, stepDescription) const errMsg = dedent` - An error occurred while running step ${chalk.white(description)}. - - Aborting all subsequent steps. + An error occurred while running step ${chalk.white(description)}. Aborting all subsequent steps. See the log output below for additional details. ` - log.error("") log.error(chalk.red(errMsg)) + log.debug("") for (const error of errors) { - log.error("") - log.error(formatGardenError(error)) + if (error.type === "workflow-script") { + const scriptErrMsg = renderMessageWithDivider( + `Script exited with code ${error.detail.exitCode}`, + error.detail.stderr, + true + ) + log.error(scriptErrMsg) + } else { + // Error comes from a command step. We only log the detail here (and only for log.debug or higher), since + // the task graph's error logging takes care of the rest. + const taskDetailErrMsg = formatGardenError(error) + log.debug(chalk.red(taskDetailErrMsg)) + } } } @@ -408,11 +417,19 @@ export async function runStepScript({ garden, log, step }: RunStepParams): Promi throw error } - throw new WorkflowScriptError(`Script exited with code ${error.exitCode}`, { + const scriptError = new WorkflowScriptError(`Script exited with code ${error.exitCode}`, { + message: error.stderr, exitCode: error.exitCode, stdout: error.stdout, stderr: error.stderr, }) + + log.error("") + log.error({ msg: `Script failed with the following error:`, error: scriptError }) + log.error("") + log.error(error.stderr) + + throw scriptError } } diff --git a/core/src/logger/util.ts b/core/src/logger/util.ts index 610a153d33..a788972549 100644 --- a/core/src/logger/util.ts +++ b/core/src/logger/util.ts @@ -11,9 +11,8 @@ import chalk from "chalk" import CircularJSON from "circular-json" import { LogNode, LogLevel } from "./log-node" import { LogEntry, LogEntryParams, EmojiName } from "./log-entry" -import { isBuffer, isNumber } from "util" import { deepMap, deepFilter, safeDumpYaml } from "../util/util" -import { padEnd, isEmpty } from "lodash" +import { padEnd, isEmpty, isNumber } from "lodash" import { dedent } from "../util/string" import hasAnsi from "has-ansi" import { GardenError } from "../exceptions" @@ -223,8 +222,8 @@ export function renderMessageWithDivider(prefix: string, msg: string, isError: b } export function formatGardenError(error: GardenError) { - const { detail, message, stack } = error - let out = stack || message + const { detail, message } = error + let out = message || "" // We recursively filter out internal fields (i.e. having names starting with _). const filteredDetail = deepFilter(detail, (_: any, key: string | number) => { @@ -233,11 +232,10 @@ export function formatGardenError(error: GardenError) { if (!isEmpty(filteredDetail)) { try { - const sanitized = sanitizeObject(filteredDetail) - const yamlDetail = safeDumpYaml(sanitized, { noRefs: true }) - out += `\nError Details:\n${yamlDetail}` + const yamlDetail = safeDumpYaml(filteredDetail, { noRefs: true }) + out += `\n\nError Details:\n\n${yamlDetail}` } catch (err) { - out += `\nUnable to render error details:\n${err.message}` + out += `\n\nUnable to render error details:\n${err.message}` } } return out @@ -248,7 +246,7 @@ export function formatGardenError(error: GardenError) { */ export function sanitizeObject(obj: any) { obj = deepMap(obj, (value: any) => { - return isBuffer(value) ? "" : value + return Buffer.isBuffer(value) ? "" : value }) return JSON.parse(CircularJSON.stringify(obj)) } diff --git a/core/src/task-graph.ts b/core/src/task-graph.ts index 2c358662db..5629636d76 100644 --- a/core/src/task-graph.ts +++ b/core/src/task-graph.ts @@ -608,9 +608,7 @@ export class TaskGraph extends EventEmitter2 { private logError(err: Error, errMessagePrefix: string) { const error = toGardenError(err) const errorMessage = error.message.trim() - const msg = renderMessageWithDivider(errMessagePrefix, errorMessage, true) - const entry = this.log.error({ msg, error }) this.log.silly({ msg: renderError(entry) }) } diff --git a/core/test/unit/src/logger/renderers.ts b/core/test/unit/src/logger/renderers.ts index 7c7482bfff..1f8bf73ca8 100644 --- a/core/test/unit/src/logger/renderers.ts +++ b/core/test/unit/src/logger/renderers.ts @@ -86,7 +86,9 @@ describe("renderers", () => { const entry = logger.info({ msg: "foo", error }) expect(renderError(entry)).to.equal(dedent` hello error + Error Details: + foo: bar\n `) })