Skip to content

Commit

Permalink
chore: change logging to use a single base logging method (#32081)
Browse files Browse the repository at this point in the history 
Closes #32039


Modified the existing logging mechanism to route to a single log function. Adapted the existing structure so that very minimal changes were required for existing logging functions and how they are used today


----

*By submitting this pull request, I confirm that my contribution is made under the terms of the Apache-2.0 license*
  • Loading branch information
@HBobertz
HBobertz authored Nov 27, 2024
1 parent be000a2 commit 069b72c
Show file tree
Hide file tree
Showing 6 changed files with 445 additions and 90 deletions.
9 changes: 4 additions & 5 deletions packages/aws-cdk/lib/api/util/cloudformation/stack-activity-monitor.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,7 @@ import { ArtifactMetadataEntryType, type MetadataEntry } from '@aws-cdk/cloud-as
import type { CloudFormationStackArtifact } from '@aws-cdk/cx-api';
import * as chalk from 'chalk';
import { ResourceEvent, StackEventPoller } from './stack-event-poller';
import { error, logLevel, LogLevel, setLogLevel } from '../../../logging';
import { error, LogLevel, setLogLevel } from '../../../logging';
import type { ICloudFormationClient } from '../../aws-auth';
import { RewritableBlock } from '../display';

Expand Down Expand Up @@ -102,7 +102,7 @@ export class StackActivityMonitor {
};

const isWindows = process.platform === 'win32';
const verbose = options.logLevel ?? logLevel;
const verbose = options.logLevel ?? LogLevel.INFO;
// On some CI systems (such as CircleCI) output still reports as a TTY so we also
// need an individual check for whether we're running on CI.
// see: https://discuss.circleci.com/t/circleci-terminal-is-a-tty-but-term-is-not-set/9965
Expand Down Expand Up @@ -626,7 +626,7 @@ export class CurrentActivityPrinter extends ActivityPrinterBase {
*/
public readonly updateSleep: number = 2_000;

private oldLogLevel: LogLevel = LogLevel.DEFAULT;
private oldLogLevel: LogLevel = LogLevel.INFO;
private block = new RewritableBlock(this.stream);

constructor(props: PrinterProps) {
Expand Down Expand Up @@ -674,8 +674,7 @@ export class CurrentActivityPrinter extends ActivityPrinterBase {
public start() {
// Need to prevent the waiter from printing 'stack not stable' every 5 seconds, it messes
// with the output calculations.
this.oldLogLevel = logLevel;
setLogLevel(LogLevel.DEFAULT);
setLogLevel(LogLevel.INFO);
}

public stop() {
Expand Down
16 changes: 14 additions & 2 deletions packages/aws-cdk/lib/cli.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,7 @@ import { realHandler as docs } from '../lib/commands/docs';
import { realHandler as doctor } from '../lib/commands/doctor';
import { MIGRATE_SUPPORTED_LANGUAGES, getMigrateScanType } from '../lib/commands/migrate';
import { availableInitLanguages, cliInit, printAvailableTemplates } from '../lib/init';
import { data, debug, error, print, setLogLevel, setCI } from '../lib/logging';
import { data, debug, error, print, setCI, setLogLevel, LogLevel } from '../lib/logging';
import { Notices } from '../lib/notices';
import { Command, Configuration, Settings } from '../lib/settings';
import * as version from '../lib/version';
Expand All @@ -48,8 +48,20 @@ export async function exec(args: string[], synthesizer?: Synthesizer): Promise<n

const argv = await parseCommandLineArguments(args, makeBrowserDefault(), await availableInitLanguages(), MIGRATE_SUPPORTED_LANGUAGES as string[], version.DISPLAY_VERSION, yargsNegativeAlias);

// if one -v, log at a DEBUG level
// if 2 -v, log at a TRACE level
if (argv.verbose) {
setLogLevel(argv.verbose);
let logLevel: LogLevel;
switch (argv.verbose) {
case 1:
logLevel = LogLevel.DEBUG;
break;
case 2:
default:
logLevel = LogLevel.TRACE;
break;
}
setLogLevel(logLevel);
}

// Debug should always imply tracing
Expand Down
252 changes: 170 additions & 82 deletions packages/aws-cdk/lib/logging.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -2,114 +2,202 @@ import { Writable } from 'stream';
import * as util from 'util';
import * as chalk from 'chalk';

type StyleFn = (str: string) => string;
const { stdout, stderr } = process;

type WritableFactory = () => Writable;
/**
* Available log levels in order of increasing verbosity.
*/
export enum LogLevel {
ERROR = 'error',
WARN = 'warn',
INFO = 'info',
DEBUG = 'debug',
TRACE = 'trace',
}

export async function withCorkedLogging<A>(block: () => Promise<A>): Promise<A> {
corkLogging();
try {
return await block();
} finally {
uncorkLogging();
}
/**
* Configuration options for a log entry.
*/
export interface LogEntry {
level: LogLevel;
message: string;
timestamp?: boolean;
prefix?: string;
style?: ((str: string) => string);
forceStdout?: boolean;
}

const { stdout, stderr } = process;

// Corking mechanism
let CORK_COUNTER = 0;
const logBuffer: [Writable, string][] = [];

function corked() {
return CORK_COUNTER !== 0;
}
// Style mappings
const styleMap: Record<LogLevel, (str: string) => string> = {
[LogLevel.ERROR]: chalk.red,
[LogLevel.WARN]: chalk.yellow,
[LogLevel.INFO]: chalk.white,
[LogLevel.DEBUG]: chalk.gray,
[LogLevel.TRACE]: chalk.gray,
};

function corkLogging() {
CORK_COUNTER += 1;
}
// Stream selection
let CI = false;

function uncorkLogging() {
CORK_COUNTER -= 1;
if (!corked()) {
logBuffer.forEach(([stream, str]) => stream.write(str + '\n'));
logBuffer.splice(0);
/**
* Determines which output stream to use based on log level and configuration.
* @param level - The log level to determine stream for
* @param forceStdout - Whether to force stdout regardless of level
* @returns The appropriate Writable stream
*/
const getStream = (level: LogLevel, forceStdout?: boolean): Writable => {
// Special case - data() calls should always go to stdout
if (forceStdout) {
return stdout;
}
if (level === LogLevel.ERROR) return stderr;
return CI ? stdout : stderr;
};

const levelPriority: Record<LogLevel, number> = {
[LogLevel.ERROR]: 0,
[LogLevel.WARN]: 1,
[LogLevel.INFO]: 2,
[LogLevel.DEBUG]: 3,
[LogLevel.TRACE]: 4,
};

let currentLogLevel: LogLevel = LogLevel.INFO;

/**
* Sets the current log level. Messages with a lower priority level will be filtered out.
* @param level - The new log level to set
*/
export function setLogLevel(level: LogLevel) {
currentLogLevel = level;
}

const logger = (stream: Writable | WritableFactory, styles?: StyleFn[], timestamp?: boolean) => (fmt: string, ...args: unknown[]) => {
const ts = timestamp ? `[${formatTime(new Date())}] ` : '';
/**
* Sets whether the logger is running in CI mode.
* In CI mode, all non-error output goes to stdout instead of stderr.
* @param newCI - Whether CI mode should be enabled
*/
export function setCI(newCI: boolean) {
CI = newCI;
}

let str = ts + util.format(fmt, ...args);
if (styles && styles.length) {
str = styles.reduce((a, style) => style(a), str);
}
/**
* Formats a date object into a timestamp string (HH:MM:SS).
* @param d - Date object to format
* @returns Formatted time string
*/
function formatTime(d: Date): string {
const pad = (n: number): string => n.toString().padStart(2, '0');
return `${pad(d.getHours())}:${pad(d.getMinutes())}:${pad(d.getSeconds())}`;
}

const realStream = typeof stream === 'function' ? stream() : stream;
/**
* Executes a block of code with corked logging. All log messages during execution
* are buffered and only written after the block completes.
* @param block - Async function to execute with corked logging
* @returns Promise that resolves with the block's return value
*/
export async function withCorkedLogging<T>(block: () => Promise<T>): Promise<T> {
CORK_COUNTER++;
try {
return await block();
} finally {
CORK_COUNTER--;
if (CORK_COUNTER === 0) {
logBuffer.forEach(([stream, str]) => stream.write(str + '\n'));
logBuffer.splice(0);
}
}
}

// Logger is currently corked, so we store the message to be printed
// later when we are uncorked.
if (corked()) {
logBuffer.push([realStream, str]);
/**
* Core logging function that handles all log output.
* @param entry - LogEntry object or log level
* @param fmt - Format string (when using with log level)
* @param args - Format arguments (when using with log level)
*/
export function log(entry: LogEntry): void;
export function log(level: LogLevel, fmt: string, ...args: unknown[]): void;
export function log(levelOrEntry: LogLevel | LogEntry, fmt?: string, ...args: unknown[]): void {
// Normalize input
const entry: LogEntry = typeof levelOrEntry === 'string'
? { level: levelOrEntry as LogLevel, message: util.format(fmt!, ...args) }
: levelOrEntry;

// Check if we should log this level
if (levelPriority[entry.level] > levelPriority[currentLogLevel]) {
return;
}

realStream.write(str + '\n');
};
// Format the message
let finalMessage = entry.message;

function formatTime(d: Date) {
return `${lpad(d.getHours(), 2)}:${lpad(d.getMinutes(), 2)}:${lpad(d.getSeconds(), 2)}`;

function lpad(x: any, w: number) {
const s = `${x}`;
return '0'.repeat(Math.max(w - s.length, 0)) + s;
// Add timestamp first if requested
if (entry.timestamp) {
finalMessage = `[${formatTime(new Date())}] ${finalMessage}`;
}
}

export enum LogLevel {
/** Not verbose at all */
DEFAULT = 0,
/** Pretty verbose */
DEBUG = 1,
/** Extremely verbose */
TRACE = 2,
}
// Add prefix AFTER timestamp
if (entry.prefix) {
finalMessage = `${entry.prefix} ${finalMessage}`;
}

export let logLevel = LogLevel.DEFAULT;
export let CI = false;
// Apply custom style if provided, otherwise use level-based style
const style = entry.style || styleMap[entry.level];
finalMessage = style(finalMessage);

export function setLogLevel(newLogLevel: LogLevel) {
logLevel = newLogLevel;
}
// Get appropriate stream - pass through forceStdout flag
const stream = getStream(entry.level, entry.forceStdout);

export function setCI(newCI: boolean) {
CI = newCI;
}
// Handle corking
if (CORK_COUNTER > 0) {
logBuffer.push([stream, finalMessage]);
return;
}

export function increaseVerbosity() {
logLevel += 1;
// Write to stream
stream.write(finalMessage + '\n');
}

const stream = () => CI ? stdout : stderr;
const _debug = logger(stream, [chalk.gray], true);

export const trace = (fmt: string, ...args: unknown[]) => logLevel >= LogLevel.TRACE && _debug(fmt, ...args);
export const debug = (fmt: string, ...args: unknown[]) => logLevel >= LogLevel.DEBUG && _debug(fmt, ...args);
export const error = logger(stderr, [chalk.red]);
export const warning = logger(stream, [chalk.yellow]);
export const success = logger(stream, [chalk.green]);
export const highlight = logger(stream, [chalk.bold]);
export const print = logger(stream);
export const data = logger(stdout);

export type LoggerFunction = (fmt: string, ...args: unknown[]) => void;
// Convenience logging methods
export const error = (fmt: string, ...args: unknown[]) => log(LogLevel.ERROR, fmt, ...args);
export const warning = (fmt: string, ...args: unknown[]) => log(LogLevel.WARN, fmt, ...args);
export const info = (fmt: string, ...args: unknown[]) => log(LogLevel.INFO, fmt, ...args);
export const print = (fmt: string, ...args: unknown[]) => log(LogLevel.INFO, fmt, ...args);
export const data = (fmt: string, ...args: unknown[]) => log({
level: LogLevel.INFO,
message: util.format(fmt, ...args),
forceStdout: true,
});
export const debug = (fmt: string, ...args: unknown[]) => log(LogLevel.DEBUG, fmt, ...args);
export const trace = (fmt: string, ...args: unknown[]) => log(LogLevel.TRACE, fmt, ...args);

export const success = (fmt: string, ...args: unknown[]) => log({
level: LogLevel.INFO,
message: util.format(fmt, ...args),
style: chalk.green,
});

export const highlight = (fmt: string, ...args: unknown[]) => log({
level: LogLevel.INFO,
message: util.format(fmt, ...args),
style: chalk.bold,
});

/**
* Create a logger output that features a constant prefix string.
*
* @param prefixString the prefix string to be appended before any log entry.
* @param fn the logger function to be used (typically one of the other functions in this module)
*
* @returns a new LoggerFunction.
* Creates a logging function that prepends a prefix to all messages.
* @param prefixString - String to prepend to all messages
* @param level - Log level to use (defaults to INFO)
* @returns Logging function that accepts format string and arguments
*/
export function prefix(prefixString: string, fn: LoggerFunction): LoggerFunction {
return (fmt: string, ...args: any[]) => fn(`%s ${fmt}`, prefixString, ...args);
}
export function prefix(prefixString: string, level: LogLevel = LogLevel.INFO): (fmt: string, ...args: unknown[]) => void {
return (fmt: string, ...args: unknown[]) => log({
level,
message: util.format(fmt, ...args),
prefix: prefixString,
});
}
2 changes: 1 addition & 1 deletion packages/aws-cdk/test/api/exec.test.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -37,7 +37,7 @@ beforeEach(() => {
});

afterEach(() => {
setLogLevel(LogLevel.DEFAULT);
setLogLevel(LogLevel.INFO);

sinon.restore();
bockfs.restore();
Expand Down
Loading

0 comments on commit 069b72c

Please sign in to comment.