diff --git a/action-src/main.ts b/action-src/main.ts index 01babe640..5c188267c 100755 --- a/action-src/main.ts +++ b/action-src/main.ts @@ -116,6 +116,8 @@ async function run() { const forceRebuild = getInput('forceRebuild'); const ignoreLastBuildOnBranch = getInput('ignoreLastBuildOnBranch'); const logFile = getInput('logFile'); + const logLevel = getInput('logLevel'); + const logPrefix = getInput('logPrefix'); const only = getInput('only'); const onlyChanged = getInput('onlyChanged'); const onlyStoryFiles = getMultilineInput('onlyStoryFiles'); @@ -169,6 +171,8 @@ async function run() { ignoreLastBuildOnBranch: maybe(ignoreLastBuildOnBranch), interactive: false, logFile: maybe(logFile), + logLevel: maybe(logLevel), + logPrefix: maybe(logPrefix), only: maybe(only), onlyChanged: maybe(onlyChanged), onlyStoryFiles: maybe(onlyStoryFiles), diff --git a/action.yml b/action.yml index f882aa1c6..629f84809 100755 --- a/action.yml +++ b/action.yml @@ -59,6 +59,12 @@ inputs: logFile: description: 'Write CLI logs to a file' required: false + logLevel: + description: 'One of: silent, error, warn, info, debug (default: info)' + required: false + logPrefix: + description: 'Custom prefix for log messages (default: current timestamp)' + required: false only: description: 'Deprecated, replaced by onlyStoryNames' required: false diff --git a/node-src/index.ts b/node-src/index.ts index ebaddb8ea..d2c92c9fa 100644 --- a/node-src/index.ts +++ b/node-src/index.ts @@ -105,10 +105,15 @@ export async function run({ flags?: Flags; options?: Partial; }): Promise> { + const config = { + ...parseArguments(argv), + ...(flags && { flags }), + ...(extraOptions && { extraOptions }), + }; const { sessionId = uuid(), env: environment = getEnvironment(), - log = createLogger(), + log = createLogger(config.flags, config.extraOptions), } = extraOptions || {}; const packageInfo = await readPackageUp({ cwd: process.cwd() }); @@ -119,9 +124,7 @@ export async function run({ const { path: packagePath, packageJson } = packageInfo; const ctx: InitialContext = { - ...parseArguments(argv), - ...(flags && { flags }), - ...(extraOptions && { extraOptions }), + ...config, packagePath, packageJson, env: environment, diff --git a/node-src/lib/log.test.ts b/node-src/lib/log.test.ts new file mode 100644 index 000000000..6b01bde8a --- /dev/null +++ b/node-src/lib/log.test.ts @@ -0,0 +1,167 @@ +import { afterEach, beforeEach, describe, expect, it, MockInstance, vi } from 'vitest'; + +import { createLogger } from './log'; + +let consoleError: MockInstance; +let consoleWarn: MockInstance; +let consoleInfo: MockInstance; +let consoleDebug: MockInstance; + +beforeEach(() => { + consoleError = vi.spyOn(console, 'error').mockImplementation(() => undefined); + consoleWarn = vi.spyOn(console, 'warn').mockImplementation(() => undefined); + consoleInfo = vi.spyOn(console, 'info').mockImplementation(() => undefined); + consoleDebug = vi.spyOn(console, 'debug').mockImplementation(() => undefined); + + vi.useFakeTimers(); + vi.setSystemTime(new Date().setTime(0)); +}); + +afterEach(() => { + delete process.env.DISABLE_LOGGING; + delete process.env.LOG_LEVEL; + delete process.env.LOG_PREFIX; + + consoleError.mockReset(); + consoleWarn.mockReset(); + consoleInfo.mockReset(); + consoleDebug.mockReset(); + + vi.useRealTimers(); +}); + +const timestamp = expect.stringMatching(/\d\d:\d\d:\d\d.\d\d\d/); + +describe('log prefix', () => { + it('should use the log prefix from environment variables', () => { + process.env.LOG_PREFIX = 'env-prefix'; + const logger = createLogger({}); + logger.info('message'); + expect(consoleInfo).toHaveBeenCalledWith('env-prefix', 'message'); + }); + + it('should use the log prefix from flags', () => { + process.env.LOG_PREFIX = 'env-prefix'; + const logger = createLogger({ logPrefix: 'flag-prefix' }); + logger.info('message'); + expect(consoleInfo).toHaveBeenCalledWith('flag-prefix', 'message'); + }); + + it('should prefer the log prefix from options', () => { + process.env.LOG_PREFIX = 'env-prefix'; + const logger = createLogger({ logPrefix: 'flag-prefix' }, { logPrefix: 'option-prefix' }); + logger.info('message'); + expect(consoleInfo).toHaveBeenCalledWith('option-prefix', 'message'); + }); + + it('should use a timestamp as prefix by default', () => { + const logger = createLogger({}); + logger.info('message'); + expect(consoleInfo).toHaveBeenCalledWith(timestamp, 'message'); + }); + + it('should not use a prefix if set to an empty string', () => { + process.env.LOG_PREFIX = ''; + const logger = createLogger({}); + logger.info('message'); + expect(consoleInfo).toHaveBeenCalledWith('message'); + }); + + it('should not use a prefix in interactive mode', () => { + process.env.LOG_PREFIX = 'env-prefix'; + const logger = createLogger({ interactive: true, logPrefix: 'flag-prefix' }); + logger.info('message'); + expect(consoleInfo).toHaveBeenCalledWith('message'); + }); +}); + +describe('log levels', () => { + it('should ignore debug messages by default', () => { + const logger = createLogger({}); + + logger.error('error', 1, 2); + expect(consoleError).toHaveBeenCalledWith(timestamp, 'error', '1', '2'); + + logger.warn('warning', 1, 2); + expect(consoleWarn).toHaveBeenCalledWith(timestamp, 'warning', '1', '2'); + + logger.info('message', 1, 2); + expect(consoleInfo).toHaveBeenCalledWith(timestamp, 'message', '1', '2'); + + logger.debug('data', 1, 2); + expect(consoleDebug).not.toHaveBeenCalled(); + }); + + it('should use the log level from environment variables', () => { + process.env.LOG_LEVEL = 'debug'; + const logger = createLogger({}); + + logger.error('error'); + expect(consoleError).toHaveBeenCalledWith(timestamp, 'error'); + + logger.warn('warning'); + expect(consoleWarn).toHaveBeenCalledWith(timestamp, 'warning'); + + logger.info('message'); + expect(consoleInfo).toHaveBeenCalledWith(timestamp, 'message'); + + logger.debug('data'); + expect(consoleDebug).toHaveBeenCalledWith(timestamp, 'data'); + }); + + it('should use the log level from flags', () => { + process.env.LOG_LEVEL = 'debug'; + const logger = createLogger({ logLevel: 'warn' }); + + logger.error('error'); + expect(consoleError).toHaveBeenCalledWith(timestamp, 'error'); + + logger.warn('warning'); + expect(consoleWarn).toHaveBeenCalledWith(timestamp, 'warning'); + + logger.info('message'); + expect(consoleInfo).not.toHaveBeenCalled(); + + logger.debug('data'); + expect(consoleDebug).not.toHaveBeenCalled(); + }); + + it('should prefer the log level from options', () => { + process.env.LOG_LEVEL = 'debug'; + const logger = createLogger({ logLevel: 'warn' }, { logLevel: 'error' }); + + logger.error('error'); + expect(consoleError).toHaveBeenCalledWith(timestamp, 'error'); + + logger.warn('warning'); + expect(consoleWarn).not.toHaveBeenCalled(); + + logger.info('message'); + expect(consoleInfo).not.toHaveBeenCalled(); + + logger.debug('data'); + expect(consoleDebug).not.toHaveBeenCalled(); + }); + + it('should respect DISABLE_LOGGING regardless of logLevel flag or option', () => { + process.env.DISABLE_LOGGING = 'true'; + process.env.LOG_LEVEL = 'debug'; + const logger = createLogger({ logLevel: 'warn' }, { logLevel: 'error' }); + logger.error('error'); + expect(consoleError).not.toHaveBeenCalled(); + }); +}); + +it('stringifies non-primitive values', () => { + const logger = createLogger({}); + logger.info('message', 1, true, null, undefined, { key: 'value' }); + expect(consoleInfo).toHaveBeenCalledWith( + timestamp, + 'message', + '1', + 'true', + 'null', + undefined, + JSON.stringify({ key: 'value' }) + ); +}); diff --git a/node-src/lib/log.ts b/node-src/lib/log.ts index 7ffaabedf..ffa999cab 100644 --- a/node-src/lib/log.ts +++ b/node-src/lib/log.ts @@ -4,6 +4,7 @@ import { createWriteStream, rm } from 'fs'; import stripAnsi from 'strip-ansi'; import { format } from 'util'; +import { Flags, Options } from '../types'; import { errorSerializer } from './logSerializers'; interface QueueMessage { @@ -11,7 +12,6 @@ interface QueueMessage { messages: string[]; } -const { DISABLE_LOGGING, LOG_LEVEL = '' } = process.env; const LOG_LEVELS = { silent: 0, error: 1, warn: 2, info: 3, debug: 4 }; const DEFAULT_LEVEL = 'info'; @@ -19,32 +19,56 @@ const DEFAULT_LEVEL = 'info'; const handleRejection = (reason: string) => console.error('Unhandled promise rejection:', reason); process.on('unhandledRejection', handleRejection); +const isPrintable = (value: any) => { + const type = typeof value; + return type === 'string' || type === 'number' || type === 'boolean'; +}; + // Omits any JSON metadata, returning only the message string const logInteractive = (args: any[]): string[] => args .map((argument) => (argument && argument.message) || argument) - .filter((argument) => typeof argument === 'string'); + .filter((argument) => isPrintable(argument)) + .map(String); -// Strips ANSI codes from messages and stringifies metadata to JSON +// Stringifies metadata to JSON const logVerbose = (type: string, args: any[]) => { const stringify = type === 'error' ? (err: any) => JSON.stringify(errorSerializer(err)) : JSON.stringify; - return args.map((argument) => - typeof argument === 'string' ? stripAnsi(argument) : stringify(argument) - ); + return args.map((argument) => (isPrintable(argument) ? String(argument) : stringify(argument))); }; -const withTime = (messages: string[], color = false) => { - if (messages.every((message) => /^\s*$/.test(message))) return messages; - let time = new Date().toISOString().slice(11, 23); - if (color) time = chalk.dim(time); - return [ - time + ' ', - ...messages.map((message) => - typeof message === 'string' ? message.replaceAll('\n', `\n `) : message - ), - ]; -}; +// Generate a timestamp like "14:30:00.123" in local time +const getTimeString = () => + new Date().toLocaleTimeString('en-US', { + hour: '2-digit', + minute: '2-digit', + second: '2-digit', + fractionalSecondDigits: 3, + hour12: false, + }); + +const createPrefixer = + (color = false, prefix?: string) => + (messages: string[]) => { + // Ignore empty log lines + if (messages.every((message) => /^\s*$/.test(message))) return messages; + + // Use a timestamp as default prefix + const pre = prefix ?? chalk.dim(getTimeString()); + if (pre === '') return color ? messages : messages.map((message) => stripAnsi(message)); + + // Pad lines with spaces to align with the prefix + const padding = ' '.repeat(stripAnsi(pre).length + 1); + return [ + color ? pre : stripAnsi(pre), + ...messages.map((message) => { + if (typeof message !== 'string') return message; + const string = color ? message : stripAnsi(message); + return string.replaceAll('\n', `\n${padding}`); + }), + ]; + }; type LogType = 'error' | 'warn' | 'info' | 'debug'; type LogFunction = (...args: any[]) => void; @@ -93,25 +117,36 @@ const fileLogger = { }, }; -export const createLogger = () => { - let level = (LOG_LEVEL.toLowerCase() as keyof typeof LOG_LEVELS) || DEFAULT_LEVEL; - if (DISABLE_LOGGING === 'true') level = 'silent'; +/* eslint-disable-next-line complexity */ +export const createLogger = (flags: Flags, options?: Partial) => { + const { DISABLE_LOGGING, LOG_LEVEL = '', LOG_PREFIX } = process.env; + + let level = + options?.logLevel || + flags.logLevel || + (LOG_LEVEL.toLowerCase() as Flags['logLevel']) || + DEFAULT_LEVEL; + + if (DISABLE_LOGGING === 'true') { + level = 'silent'; + } - const args = new Set(process.argv.slice(2)); - let interactive = !args.has('--debug') && !args.has('--no-interactive'); + let interactive = (options?.interactive || flags.interactive) && !(options?.debug || flags.debug); let enqueue = false; const queue: QueueMessage[] = []; + const logPrefixer = createPrefixer(true, options?.logPrefix || flags.logPrefix || LOG_PREFIX); + const filePrefixer = createPrefixer(false, options?.logPrefix || flags.logPrefix || LOG_PREFIX); const log = (type: LogType, logFileOnly?: boolean) => (...args: any[]) => { if (LOG_LEVELS[level] < LOG_LEVELS[type]) return; const logs = logVerbose(type, args); - fileLogger.append(...withTime(logs)); + fileLogger.append(...filePrefixer(logs)); if (logFileOnly) return; - const messages = interactive ? logInteractive(args) : withTime(logs, true); + const messages = interactive ? logInteractive(args) : logPrefixer(logs); if (messages.length === 0) return; // Queue up the logs or print them right away diff --git a/node-src/lib/parseArguments.ts b/node-src/lib/parseArguments.ts index 092b4e8da..67289f5bf 100644 --- a/node-src/lib/parseArguments.ts +++ b/node-src/lib/parseArguments.ts @@ -56,6 +56,8 @@ export default function parseArguments(argv: string[]) { --junit-report [filepath] Write build results to a JUnit XML file. {buildNumber} will be replaced with the actual build number. [chromatic-build-{buildNumber}.xml] --list List available stories. This requires running a full build. --log-file [filepath] Write log output to a file. Disable via --no-log-file. [chromatic.log] + --log-level One of "silent", "error", "warn", "info", "debug". Defaults to "info". + --log-prefix Prefix for each log line. Defaults to current timestamp except in interactive mode. Set to "" to disable. --no-file-hashing Disable file hashing. This will cause all files to be uploaded on every build. --no-interactive Don't ask interactive questions about your setup and don't overwrite output. Always true in non-TTY environments. --storybook-log-file [filepath] Write Storybook build output to a file. Disable via --no-storybook-log-file. [storybook-build.log] @@ -113,6 +115,8 @@ export default function parseArguments(argv: string[]) { junitReport: { type: 'string' }, list: { type: 'boolean' }, logFile: { type: 'string' }, + logLevel: { type: 'string', choices: ['silent', 'error', 'warn', 'info', 'debug'] }, + logPrefix: { type: 'string' }, storybookLogFile: { type: 'string' }, traceChanged: { type: 'string' }, uploadMetadata: { type: 'boolean' }, diff --git a/node-src/types.ts b/node-src/types.ts index ce146ba98..ff6ea80d0 100644 --- a/node-src/types.ts +++ b/node-src/types.ts @@ -51,6 +51,8 @@ export interface Flags { junitReport?: string; list?: boolean; logFile?: string; + logLevel?: 'silent' | 'error' | 'warn' | 'info' | 'debug'; + logPrefix?: string; storybookLogFile?: string; traceChanged?: string; uploadMetadata?: boolean; @@ -69,6 +71,8 @@ export interface Options extends Configuration { configFile?: Flags['configFile']; logFile?: Flags['logFile']; + logLevel?: Flags['logLevel']; + logPrefix?: Flags['logPrefix']; onlyChanged: boolean | string; onlyStoryFiles: Flags['onlyStoryFiles']; onlyStoryNames: Flags['onlyStoryNames'];