From b0f3f2c8001d7e70bc1f65c4c098655c63a157aa Mon Sep 17 00:00:00 2001 From: Eythor Magnusson Date: Thu, 23 Nov 2023 11:22:16 +0100 Subject: [PATCH] improvement(logger): some minor fixes Particularly: - Setting logs for some built-in providers to debug because that's just more fitting - Use the "correct" log context when rendering new lines for graph and provider logs. If we use this.log the newlines are visible in the dev console where they shouldn't be because that's in the context of "internal" commands --- core/src/cli/cli.ts | 11 ++++++++--- core/src/commands/base.ts | 13 ++++++++++--- core/src/commands/login.ts | 4 ++-- core/src/garden.ts | 28 +++++++++++++++++++++------- core/src/graph/actions.ts | 2 +- core/src/monitors/port-forward.ts | 2 +- core/src/mutagen.ts | 2 +- core/src/tasks/base.ts | 22 +++++++++++----------- core/src/tasks/resolve-provider.ts | 11 +++++++---- 9 files changed, 62 insertions(+), 33 deletions(-) diff --git a/core/src/cli/cli.ts b/core/src/cli/cli.ts index c968a578800..6a34dea67e5 100644 --- a/core/src/cli/cli.ts +++ b/core/src/cli/cli.ts @@ -225,8 +225,6 @@ ${renderCommands(commands)} } = parsedOpts const parsedCliVars = parseCliVarFlags(cliVars) - const gardenLog = log.createLog({ name: "garden" }) - // Some commands may set their own logger type so we update the logger config here, // once we've resolved the command. const commandLoggerType = command.getTerminalWriterType({ opts: parsedOpts, args: parsedArgs }) @@ -240,10 +238,16 @@ ${renderCommands(commands)} const sessionId = uuidv4() return withSessionContext({ sessionId }, async () => { + const gardenLog = log.createLog({ name: "garden", showDuration: true }) + // Log context for printing the start and finish of Garden initialization when not using the dev console + const gardenInitLog = command.getFullName() !== "dev" ? log.createLog({ name: "garden", showDuration: true }) : null + // Init Cloud API (if applicable) let cloudApi: CloudApi | undefined - gardenLog.info("Initializing...") + if (gardenInitLog) { + gardenInitLog.info("Initializing...") + } if (!command.noProject) { const config = await this.getProjectConfig(log, workingDir) const cloudDomain = getGardenCloudDomain(config?.domain) @@ -281,6 +285,7 @@ ${renderCommands(commands)} commandInfo, environmentString: environmentName, log, + gardenInitLog: gardenInitLog || undefined, forceRefresh, variableOverrides: parsedCliVars, plugins: this.plugins, diff --git a/core/src/commands/base.ts b/core/src/commands/base.ts index 4dff372b106..a0956f3f263 100644 --- a/core/src/commands/base.ts +++ b/core/src/commands/base.ts @@ -18,7 +18,7 @@ import type { Garden } from "../garden.js" import type { Log } from "../logger/log-entry.js" import type { LoggerType, LoggerBase, LoggerConfigBase, LogLevel } from "../logger/logger.js" import { eventLogLevel } from "../logger/logger.js" -import { printFooter } from "../logger/util.js" +import { printEmoji, printFooter } from "../logger/util.js" import { getCloudDistributionName, getCloudLogSectionName } from "../util/cloud.js" import { getDurationMsec, getPackageVersion, userPrompt } from "../util/util.js" import { renderOptions, renderCommands, renderArguments, cliStyles, optionsWithAliasValues } from "../cli/helpers.js" @@ -284,6 +284,7 @@ export abstract class Command< const log = overrideLogLevel ? garden.log.createLog({ fixLevel: overrideLogLevel }) : garden.log let cloudSession: CloudSession | undefined + let cloudLinkMsg: string | undefined // Session registration for the `dev` and `serve` commands is handled in the `serve` command's `action` method, // so we skip registering here to avoid duplication. @@ -317,8 +318,10 @@ export abstract class Command< shortId: cloudSession.shortId, }).href const cloudLog = log.createLog({ name: getCloudLogSectionName(distroName) }) - - cloudLog.info(`View command results at: ${styles.link(commandResultUrl)}\n`) + cloudLinkMsg = `View command results at: \n\n${printEmoji("👉", log)}${styles.link( + commandResultUrl + )} ${printEmoji("👈", log)} \n` + cloudLog.info(cloudLinkMsg) } let analytics: AnalyticsHandler | undefined @@ -430,6 +433,10 @@ export abstract class Command< // fire, which may be needed to e.g. capture monitors added in event handlers await waitForOutputFlush() + if (cloudLinkMsg) { + log.info("\n" + cloudLinkMsg) + } + return result }) ) diff --git a/core/src/commands/login.ts b/core/src/commands/login.ts index e15acb33bdd..abc6f5c5baa 100644 --- a/core/src/commands/login.ts +++ b/core/src/commands/login.ts @@ -92,7 +92,7 @@ export class LoginCommand extends Command<{}, Opts> { const cloudApi = await CloudApi.factory({ log, cloudDomain, skipLogging: true, globalConfigStore }) if (cloudApi) { - log.info({ msg: `You're already logged in to ${cloudDomain}.` }) + log.success({ msg: `You're already logged in to ${cloudDomain}.` }) cloudApi.close() return {} } @@ -114,7 +114,7 @@ export class LoginCommand extends Command<{}, Opts> { log.info({ msg: `Logging in to ${cloudDomain}...` }) const tokenResponse = await login(log, cloudDomain, garden.events) await CloudApi.saveAuthToken(log, globalConfigStore, tokenResponse, cloudDomain) - log.info({ msg: `Successfully logged in to ${cloudDomain}.` }) + log.success({ msg: `Successfully logged in to ${cloudDomain}.`, showDuration: false }) return {} } diff --git a/core/src/garden.ts b/core/src/garden.ts index 2619af01af5..3fe64a56d2d 100644 --- a/core/src/garden.ts +++ b/core/src/garden.ts @@ -159,6 +159,7 @@ import { configureNoOpExporter } from "./util/open-telemetry/tracing.js" import { detectModuleOverlap, makeOverlapErrors } from "./util/module-overlap.js" import { GotHttpError } from "./util/http.js" import { styles } from "./logger/styles.js" +import { renderDuration } from "./logger/util.js" const defaultLocalAddress = "localhost" @@ -171,6 +172,11 @@ export interface GardenOpts { globalConfigStore?: GlobalConfigStore legacyBuildSync?: boolean log?: Log + /** + * Log context for logging the start and finish of the Garden class + * initialization with duration. + */ + gardenInitLog?: Log monitors?: MonitorManager noEnterprise?: boolean persistent?: boolean @@ -195,6 +201,7 @@ export interface GardenParams { globalConfigStore?: GlobalConfigStore localConfigStore?: LocalConfigStore log: Log + gardenInitLog?: Log moduleIncludePatterns?: string[] moduleExcludePatterns?: string[] monitors?: MonitorManager @@ -226,6 +233,7 @@ interface GardenInstanceState { @Profile() export class Garden { public log: Log + private gardenInitLog?: Log private loadedPlugins?: GardenPluginSpec[] protected actionConfigs: ActionConfigMap protected moduleConfigs: ModuleConfigMap @@ -303,6 +311,7 @@ export class Garden { this.namespace = params.namespace this.gardenDirPath = params.gardenDirPath this.log = params.log + this.gardenInitLog = params.gardenInitLog this.artifactsPath = params.artifactsPath this.vcsInfo = params.vcsInfo this.opts = params.opts @@ -841,7 +850,7 @@ export class Garden { this.resolvedProviders[provider.name] = provider } - providerLog.success("Finished initializing providers") + providerLog.success("Finished resolving providers") if (someCached || allCached) { const msg = allCached ? "All" : "Some" providerLog.info( @@ -850,9 +859,6 @@ export class Garden { } providerLog.silly(() => `Resolved providers: ${providers.map((p) => p.name).join(", ")}`) - - // Print a new line after resolving providers - this.log.info("") }) return keyBy(providers, "name") @@ -1154,9 +1160,16 @@ export class Garden { // This event is internal only, not to be streamed this.events.emit("configGraph", { graph }) - graphLog.success("Done") - // Print a new line after resolving graph - this.log.info("") + graphLog.success("Finished resolving graph") + + // Log Garden class initialization exactly once with duration. This basically assumes that + // Garden is ready after the graph is resolved for the first time. May not be relevant + // for some commands. + if (this.gardenInitLog) { + // We set the duration "manually" instead of using `gardenInitLog.success()` so we can add a new line at the end. + this.gardenInitLog.info(styles.success(`Finished initializing Garden ${renderDuration(this.gardenInitLog.getDuration(1))}\n`)) + this.gardenInitLog = undefined + } return graph.toConfigGraph() } @@ -1964,6 +1977,7 @@ export const resolveGardenParams = profileAsync(async function _resolveGardenPar dotIgnoreFile: config.dotIgnoreFile, proxy, log, + gardenInitLog: opts.gardenInitLog, moduleIncludePatterns: (config.scan || {}).include, username: _username, forceRefresh: opts.forceRefresh, diff --git a/core/src/graph/actions.ts b/core/src/graph/actions.ts index 6a4f2d86f7a..c7fc0463e50 100644 --- a/core/src/graph/actions.ts +++ b/core/src/graph/actions.ts @@ -467,7 +467,7 @@ export async function resolveAction({ const results = await garden.processTasks({ tasks: [task], log, throwOnError: true }) - log.info(`Done!`) + log.success({ msg: `Done`, showDuration: false }) return >(results.results.getResult(task)!.result!.outputs.resolvedAction) } diff --git a/core/src/monitors/port-forward.ts b/core/src/monitors/port-forward.ts index 1891533cd2f..cf609995630 100644 --- a/core/src/monitors/port-forward.ts +++ b/core/src/monitors/port-forward.ts @@ -86,7 +86,7 @@ export class PortForwardMonitor extends Monitor { this.log.info( styles.primary( `Port forward: ` + - styles.underline(proxy.localUrl) + + styles.link(proxy.localUrl) + ` → ${targetHost}:${proxy.spec.targetPort}` + (proxy.spec.name ? ` (${proxy.spec.name})` : "") ) diff --git a/core/src/mutagen.ts b/core/src/mutagen.ts index 6b193905a5d..11655e93a1c 100644 --- a/core/src/mutagen.ts +++ b/core/src/mutagen.ts @@ -388,7 +388,7 @@ export class Mutagen { } const syncCount = session.successfulCycles || 0 - const description = `from ${sourceDescription} to ${targetDescription}` + const description = `from ${styles.highlight(sourceDescription)} to ${styles.highlight(targetDescription)}` const isInitialSync = activeSync.lastSyncCount === 0 // Mutagen resets the sync count to zero after resuming from a sync paused diff --git a/core/src/tasks/base.ts b/core/src/tasks/base.ts index 3ab825be24d..c3a2f2d16f8 100644 --- a/core/src/tasks/base.ts +++ b/core/src/tasks/base.ts @@ -395,26 +395,26 @@ function displayState(state: ActionState): string { const actionLogStrings = { Build: { ready: "built", - notReady: "will be built", - force: "rebuild", + notReady: `will be ${styles.highlight("built")}`, + force: `will ${styles.highlight("force rebuild")}`, running: "Building", }, Deploy: { ready: "deployed", - notReady: "will be deployed", - force: "redeploy", + notReady: `will be ${styles.highlight("deployed")}`, + force: `will ${styles.highlight("force redeploy")}`, running: "Deploying", }, Test: { ready: "run", - notReady: "test will be run", - force: "rerun test", + notReady: `test will be ${styles.highlight("run")}`, + force: `will ${styles.highlight("force rerun test")}`, running: "Testing", }, Run: { ready: "run", - notReady: "will be run", - force: "rerun", + notReady: `will be ${styles.highlight("run")}`, + force: `will ${styles.highlight("force rerun")}`, running: "Running", }, } @@ -480,10 +480,10 @@ export function logAndEmitGetStatusEvents< if (result.state === "ready" && !willRerun) { log.success({ msg: `Already ${logStrings.ready}`, showDuration: false }) } else if (result.state === "ready" && willRerun) { - log.warn(`${styledName} is already ${logStrings.ready}, will force ${logStrings.force}`) + log.info(`${styledName} is already ${styles.highlight(logStrings.ready)}, ${logStrings.force}`) } else { - const stateStr = result.detail?.state || displayState(result.state) - log.warn(`Status is '${stateStr}', ${styledName} ${logStrings.notReady}`) + const stateStr = styles.highlight(result.detail?.state || displayState(result.state)) + log.info(`Status is '${stateStr}', ${styledName} ${logStrings.notReady}`) } // Then an event with the results if the status was successfully retrieved... diff --git a/core/src/tasks/resolve-provider.ts b/core/src/tasks/resolve-provider.ts index 612183ae708..8e1bc2306fc 100644 --- a/core/src/tasks/resolve-provider.ts +++ b/core/src/tasks/resolve-provider.ts @@ -33,6 +33,7 @@ import { stableStringify } from "../util/string.js" import { OtelTraced } from "../util/open-telemetry/decorators.js" import { LogLevel } from "../logger/logger.js" import type { Log } from "../logger/log-entry.js" +import { styles } from "../logger/styles.js" /** * Returns a provider log context with the provider name set. @@ -41,8 +42,8 @@ import type { Log } from "../logger/log-entry.js" * resolved per se. A bit hacky but this is just a cosmetic change. */ function getProviderLog(providerName: string, log: Log) { - const verboseLogProviders = ["templated", "container"] - const fixLevel = verboseLogProviders.includes(providerName) ? LogLevel.verbose : undefined + const debugLogProviders = ["templated", "container"] + const fixLevel = debugLogProviders.includes(providerName) ? LogLevel.debug : undefined return log.createLog({ name: providerName, fixLevel }) } @@ -413,8 +414,10 @@ export class ResolveProviderTask extends BaseTask { let status = await handler!({ ctx, log: providerLog }) if (this.forceInit || !status.ready) { - const statusMsg = status.ready ? "Ready, will force re-init" : "Not ready, will init" - providerLog.warn(statusMsg) + const statusMsg = status.ready + ? `${styles.highlight("Ready")}, will ${styles.highlight("force re-initialize")}` + : `${styles.highlight("Not ready")}, will initialize` + providerLog.info(statusMsg) // TODO: avoid calling the handler manually const prepareHandler = await actions.provider["getPluginHandler"]({ handlerType: "prepareEnvironment",