Allow verbose to be a function for custom logging

lib/io/contents.js

@@ -64,7 +64,7 @@ const logOutputAsync = async ({stream, onStreamEnd, fdNumber, encoding, allMixed
 		stripFinalNewline: true,
 		allMixed,
 	});
-	await logLines(linesIterable, stream, verboseInfo);
+	await logLines(linesIterable, stream, fdNumber, verboseInfo);
 };
 
 // When using `buffer: false`, users need to read `subprocess.stdout|stderr|all` right away

lib/io/output-sync.js

@@ -51,6 +51,7 @@ const transformOutputResultSync = (
 	logOutputSync({
 		serializedResult,
 		fdNumber,
+		state,
 		verboseInfo,
 		encoding,
 		stdioItems,
@@ -101,7 +102,7 @@ const serializeChunks = ({chunks, objectMode, encoding, lines, stripFinalNewline
 	return {serializedResult};
 };
 
-const logOutputSync = ({serializedResult, fdNumber, verboseInfo, encoding, stdioItems, objectMode}) => {
+const logOutputSync = ({serializedResult, fdNumber, state, verboseInfo, encoding, stdioItems, objectMode}) => {
 	if (!shouldLogOutput({
 		stdioItems,
 		encoding,
@@ -112,7 +113,13 @@ const logOutputSync = ({serializedResult, fdNumber, verboseInfo, encoding, stdio
 	}
 
 	const linesArray = splitLinesSync(serializedResult, false, objectMode);
-	logLinesSync(linesArray, verboseInfo);
+
+	try {
+		logLinesSync(linesArray, fdNumber, verboseInfo);
+	} catch (error) {
+		state.error ??= error;
+		throw error;
+	}
 };
 
 // When the `std*` target is a file path/URL or a file descriptor

lib/verbose/complete.js

@@ -5,7 +5,7 @@ import {isVerbose} from './info.js';
 import {verboseLog} from './log.js';
 import {logError} from './error.js';
 
-// When `verbose` is `short|full`, print each command's completion, duration and error
+// When `verbose` is `short|full|custom`, print each command's completion, duration and error
 export const logFinalResult = ({shortMessage, durationMs, failed}, verboseInfo) => {
 	logResult(shortMessage, durationMs, verboseInfo, failed);
 };

lib/verbose/default.js

@@ -6,7 +6,7 @@ import {
 	yellowBright,
 } from 'yoctocolors';
 
-// Default logger for the `verbose` option
+// Default logger when `verbose` is not a function
 export const defaultLogger = ({type, message, timestamp, failed, piped, commandId, options: {reject = true}}) => {
 	const timestampString = serializeTimestamp(timestamp);
 	const icon = ICONS[type]({failed, reject, piped});

lib/verbose/error.js

@@ -1,6 +1,6 @@
 import {verboseLog} from './log.js';
 
-// When `verbose` is `short|full`, print each command's error when it fails
+// When `verbose` is `short|full|custom`, print each command's error when it fails
 export const logError = (logMessage, verboseInfo, failed) => {
 	if (failed) {
 		verboseLog({

lib/verbose/info.js

@@ -31,9 +31,9 @@ const validateVerbose = verbose => {
 			throw new TypeError('The "verbose: true" option was renamed to "verbose: \'short\'".');
 		}
 
-		if (!VERBOSE_VALUES.has(fdVerbose)) {
+		if (!VERBOSE_VALUES.has(fdVerbose) && !isCustomFdVerbose(fdVerbose)) {
 			const allowedValues = [...VERBOSE_VALUES].map(allowedValue => `'${allowedValue}'`).join(', ');
-			throw new TypeError(`The "verbose" option must not be ${fdVerbose}. Allowed values are: ${allowedValues}.`);
+			throw new TypeError(`The "verbose" option must not be ${fdVerbose}. Allowed values are: ${allowedValues} or a function.`);
 		}
 	}
 };
@@ -44,7 +44,26 @@ const VERBOSE_VALUES = new Set(['none', 'short', 'full']);
 export const isVerbose = ({verbose}) => getFdGenericVerbose(verbose) !== 'none';
 
 // Whether IPC and output and logged
-export const isFullVerbose = ({verbose}, fdNumber) => getFdSpecificValue(verbose, fdNumber) === 'full';
+export const isFullVerbose = ({verbose}, fdNumber) => {
+	const fdVerbose = getFdSpecificValue(verbose, fdNumber);
+	return fdVerbose === 'full' || isCustomFdVerbose(fdVerbose);
+};
+
+// The `verbose` option can be a function to customize logging
+export const getLogger = ({verbose}, fdNumber) => {
+	const fdVerbose = getFdVerbose(verbose, fdNumber);
+	return isCustomFdVerbose(fdVerbose) ? fdVerbose : undefined;
+};
+
+const isCustomFdVerbose = fdVerbose => typeof fdVerbose === 'function';
+
+// When using `verbose: {stdout, stderr, fd3, ipc}`:
+//  - `verbose.stdout|stderr|fd3` is used for 'output'
+//  - `verbose.ipc` is only used for 'ipc'
+//  - first non-'none' `verbose.*` is used for 'command', 'error' and 'duration'
+const getFdVerbose = (verbose, fdNumber) => fdNumber === undefined
+	? getFdGenericVerbose(verbose)
+	: getFdSpecificValue(verbose, fdNumber);
 
 const getFdGenericVerbose = verbose => verbose.every(fdVerbose => fdVerbose === verbose[0])
 	? verbose[0]

lib/verbose/ipc.js

@@ -9,6 +9,7 @@ export const logIpcOutput = (message, verboseInfo) => {
 	verboseLog({
 		type: 'ipc',
 		logMessage,
+		fdNumber: 'ipc',
 		verboseInfo,
 	});
 };

lib/verbose/log.js

@@ -2,37 +2,60 @@ import {writeFileSync} from 'node:fs';
 import {inspect} from 'node:util';
 import {escapeLines} from '../arguments/escape.js';
 import {defaultLogger} from './default.js';
+import {getLogger} from './info.js';
 
 // Write synchronously to ensure lines are properly ordered and not interleaved with `stdout`
-export const verboseLog = ({type, logMessage, verboseInfo, failed, piped}) => {
+export const verboseLog = ({type, logMessage, fdNumber, verboseInfo, failed, piped}) => {
 	const logObject = getLogObject({
 		type,
 		failed,
 		piped,
 		verboseInfo,
 	});
-	const printedLines = getPrintedLines(logMessage, logObject);
-	writeFileSync(STDERR_FD, `${printedLines}\n`);
+	const logger = getLogger(verboseInfo, fdNumber);
+	const printedLines = getPrintedLines(logMessage, logObject, logger);
+	writeFileSync(STDERR_FD, printedLines);
 };
 
 const getLogObject = ({
 	type,
 	failed = false,
 	piped = false,
-	verboseInfo: {commandId, rawOptions},
+	verboseInfo: {escapedCommand, commandId, rawOptions},
 }) => ({
 	type,
 	timestamp: new Date(),
 	failed,
 	piped,
+	escapedCommand,
 	commandId,
 	options: rawOptions,
 });
 
-const getPrintedLines = (logMessage, logObject) => logMessage
+const getPrintedLines = (logMessage, logObject, logger) => logMessage
 	.split('\n')
-	.map(message => defaultLogger({...logObject, message}))
-	.join('\n');
+	.map(message => getPrintedLine(message, logObject, logger))
+	.filter(printedLine => printedLine !== undefined)
+	.map(printedLine => appendNewline(printedLine))
+	.join('');
+
+const getPrintedLine = (message, logObject, logger) => {
+	const lineLogObject = {...logObject, message};
+	const logLine = defaultLogger(lineLogObject);
+
+	if (logger === undefined) {
+		return logLine;
+	}
+
+	const printedLine = logger(logLine, lineLogObject);
+	if (typeof printedLine === 'string') {
+		return printedLine;
+	}
+};
+
+const appendNewline = printedLine => printedLine.endsWith('\n')
+	? printedLine
+	: `${printedLine}\n`;
 
 // Unless a `verbose` function is used, print all logs on `stderr`
 const STDERR_FD = 2;

lib/verbose/output.js

@@ -24,18 +24,18 @@ const fdUsesVerbose = fdNumber => fdNumber === 1 || fdNumber === 2;
 const PIPED_STDIO_VALUES = new Set(['pipe', 'overlapped']);
 
 // `verbose: 'full'` printing logic with async methods
-export const logLines = async (linesIterable, stream, verboseInfo) => {
+export const logLines = async (linesIterable, stream, fdNumber, verboseInfo) => {
 	for await (const line of linesIterable) {
 		if (!isPipingStream(stream)) {
-			logLine(line, verboseInfo);
+			logLine(line, fdNumber, verboseInfo);
 		}
 	}
 };
 
 // `verbose: 'full'` printing logic with sync methods
-export const logLinesSync = (linesArray, verboseInfo) => {
+export const logLinesSync = (linesArray, fdNumber, verboseInfo) => {
 	for (const line of linesArray) {
-		logLine(line, verboseInfo);
+		logLine(line, fdNumber, verboseInfo);
 	}
 };
 
@@ -49,11 +49,12 @@ export const logLinesSync = (linesArray, verboseInfo) => {
 const isPipingStream = stream => stream._readableState.pipes.length > 0;
 
 // When `verbose` is `full`, print stdout|stderr
-const logLine = (line, verboseInfo) => {
+const logLine = (line, fdNumber, verboseInfo) => {
 	const logMessage = serializeLogMessage(line);
 	verboseLog({
 		type: 'output',
 		logMessage,
+		fdNumber,
 		verboseInfo,
 	});
 };

lib/verbose/start.js

@@ -1,7 +1,7 @@
 import {isVerbose} from './info.js';
 import {verboseLog} from './log.js';
 
-// When `verbose` is `short|full`, print each command
+// When `verbose` is `short|full|custom`, print each command
 export const logCommand = (escapedCommand, verboseInfo, piped) => {
 	if (!isVerbose(verboseInfo)) {
 		return;

test/fixtures/nested/custom-event.js

@@ -0,0 +1,3 @@
+export const getOptions = ({type, eventProperty}) => ({
+	verbose: (logLine, logEvent) => logEvent.type === type ? `${logEvent[eventProperty]}` : undefined,
+});

test/fixtures/nested/custom-print-multiple.js

@@ -0,0 +1,8 @@
+export const getOptions = ({fdNumber, secondFdNumber}) => ({
+	verbose: {
+		[fdNumber](logLine) {
+			console.warn(logLine);
+		},
+		[secondFdNumber]() {},
+	},
+});

test/fixtures/nested/custom-print.js

@@ -0,0 +1,9 @@
+const setFdSpecific = (fdNumber, option) => fdNumber === undefined
+	? option
+	: {[fdNumber]: option};
+
+export const getOptions = ({fdNumber}) => ({
+	verbose: setFdSpecific(fdNumber, logLine => {
+		console.warn(logLine);
+	}),
+});

test/fixtures/nested/custom-return.js

@@ -0,0 +1,5 @@
+export const getOptions = ({logOutput}) => ({
+	verbose(logLine, {type}) {
+		return type === 'command' ? logOutput : undefined;
+	},
+});

test/fixtures/nested/custom-throw.js

@@ -0,0 +1,5 @@
+export const getOptions = ({errorMessage}) => ({
+	verbose() {
+		throw new Error(errorMessage);
+	},
+});

test/fixtures/nested/custom-uppercase.js

@@ -0,0 +1,5 @@
+export const getOptions = () => ({
+	verbose(logLine, {type}) {
+		return type === 'command' ? logLine.replace('noop', 'NOOP') : undefined;
+	},
+});

test/helpers/early-error.js

@@ -1,5 +1,7 @@
 import {execa, execaSync} from '../../index.js';
 
+export const validationErrorOptions = {timeout: []};
+
 export const earlyErrorOptions = {detached: 'true'};
 export const getEarlyErrorSubprocess = options => execa('empty.js', {...earlyErrorOptions, ...options});
 export const earlyErrorOptionsSync = {maxBuffer: false};

test/verbose/custom.js

@@ -0,0 +1,33 @@
+import test from 'ava';
+import {setFixtureDirectory} from '../helpers/fixtures-directory.js';
+import {foobarString} from '../helpers/input.js';
+import {nestedSubprocess} from '../helpers/nested.js';
+import {getCommandLine, testTimestamp} from '../helpers/verbose.js';
+
+setFixtureDirectory();
+
+const testCustomReturn = async (t, logOutput, expectedOutput) => {
+	const {stderr} = await nestedSubprocess(
+		'noop.js',
+		['.'],
+		{optionsFixture: 'custom-return.js', optionsInput: {logOutput}},
+		{stripFinalNewline: false},
+	);
+	t.is(stderr, expectedOutput);
+};
+
+test('"verbose" returning a string prints it', testCustomReturn, `${foobarString}\n`, `${foobarString}\n`);
+test('"verbose" returning a string without a newline adds it', testCustomReturn, foobarString, `${foobarString}\n`);
+test('"verbose" returning a string with multiple newlines keeps them', testCustomReturn, `${foobarString}\n\n`, `${foobarString}\n\n`);
+test('"verbose" returning an empty string prints an empty line', testCustomReturn, '', '\n');
+test('"verbose" returning undefined ignores it', testCustomReturn, undefined, '');
+test('"verbose" returning a number ignores it', testCustomReturn, 0, '');
+test('"verbose" returning a bigint ignores it', testCustomReturn, 0n, '');
+test('"verbose" returning a boolean ignores it', testCustomReturn, true, '');
+test('"verbose" returning an object ignores it', testCustomReturn, {}, '');
+test('"verbose" returning an array ignores it', testCustomReturn, [], '');
+
+test('"verbose" receives logLine string as first argument', async t => {
+	const {stderr} = await nestedSubprocess('noop.js', [foobarString], {optionsFixture: 'custom-uppercase.js'});
+	t.is(getCommandLine(stderr), `${testTimestamp} [0] $ NOOP.js ${foobarString}`);
+});