diff --git a/packages/build/src/core/build.ts b/packages/build/src/core/build.ts index c82213bfe0..d699e8de31 100644 --- a/packages/build/src/core/build.ts +++ b/packages/build/src/core/build.ts @@ -481,6 +481,7 @@ const initAndRunBuild = async function ({ timers: timersA, featureFlags, quiet, + systemLog, systemLogFile, }) diff --git a/packages/build/src/plugins/load.js b/packages/build/src/plugins/load.js index e9cb700785..37cddd628d 100644 --- a/packages/build/src/plugins/load.js +++ b/packages/build/src/plugins/load.js @@ -5,6 +5,7 @@ import { addPluginLoadErrorStatus } from '../status/load_error.js' import { measureDuration } from '../time/main.js' import { callChild } from './ipc.js' +import { captureStandardError } from './system_log.js' const pSetTimeout = promisify(setTimeout) @@ -79,20 +80,7 @@ const loadPlugin = async function ( ) { const { childProcess } = childProcesses[index] const loadEvent = 'load' - - // A buffer for any data piped into the child process' stderr. We'll pipe - // this to system logs if we fail to load the plugin. - const bufferedStdErr = [] - - let bufferedStdListener - - if (featureFlags.netlify_build_plugin_system_log && childProcess.stderr) { - bufferedStdListener = (data) => { - bufferedStdErr.push(data.toString().trimEnd()) - } - - childProcess.stderr.on('data', bufferedStdListener) - } + const cleanup = captureStandardError(childProcess, systemLog, loadEvent, featureFlags) try { const { events } = await callChild({ @@ -115,10 +103,6 @@ const loadPlugin = async function ( if (featureFlags.netlify_build_plugin_system_log) { // Wait for stderr to be flushed. await pSetTimeout(0) - - bufferedStdErr.forEach((line) => { - systemLog(line) - }) } addErrorInfo(error, { @@ -128,8 +112,6 @@ const loadPlugin = async function ( addPluginLoadErrorStatus({ error, packageName, version, debug }) throw error } finally { - if (bufferedStdListener) { - childProcess.stderr.removeListener('data', bufferedStdListener) - } + cleanup() } } diff --git a/packages/build/src/plugins/spawn.ts b/packages/build/src/plugins/spawn.ts index 6512fb8d6c..75073ad482 100644 --- a/packages/build/src/plugins/spawn.ts +++ b/packages/build/src/plugins/spawn.ts @@ -1,10 +1,12 @@ import { createRequire } from 'module' import { fileURLToPath, pathToFileURL } from 'url' +import { promisify } from 'util' import { trace } from '@opentelemetry/api' import { ExecaChildProcess, execaNode } from 'execa' import { gte } from 'semver' +import { FeatureFlags } from '../core/feature_flags.js' import { addErrorInfo } from '../error/info.js' import { NetlifyConfig } from '../index.js' import { BufferedLogs } from '../log/logger.js' @@ -15,17 +17,19 @@ import { logOutdatedPlugins, logRuntime, } from '../log/messages/compatibility.js' +import { SystemLogger } from '../plugins_core/types.js' import { isTrustedPlugin } from '../steps/plugin.js' import { measureDuration } from '../time/main.js' import { callChild, getEventFromChild } from './ipc.js' import { PluginsOptions } from './node_version.js' import { getSpawnInfo } from './options.js' +import { captureStandardError } from './system_log.js' export type ChildProcess = ExecaChildProcess const CHILD_MAIN_FILE = fileURLToPath(new URL('child/main.js', import.meta.url)) - +const pSetTimeout = promisify(setTimeout) const require = createRequire(import.meta.url) // Start child processes used by all plugins @@ -34,7 +38,17 @@ const require = createRequire(import.meta.url) // (for both security and safety reasons) // - logs can be buffered which allows manipulating them for log shipping, // transforming and parallel plugins -const tStartPlugins = async function ({ pluginsOptions, buildDir, childEnv, logs, debug, quiet, systemLogFile }) { +const tStartPlugins = async function ({ + pluginsOptions, + buildDir, + childEnv, + logs, + debug, + quiet, + systemLog, + systemLogFile, + featureFlags, +}) { if (!quiet) { logRuntime(logs, pluginsOptions) logLoadingPlugins(logs, pluginsOptions, debug) @@ -46,7 +60,17 @@ const tStartPlugins = async function ({ pluginsOptions, buildDir, childEnv, logs const childProcesses = await Promise.all( pluginsOptions.map(({ pluginDir, nodePath, nodeVersion, pluginPackageJson }) => - startPlugin({ pluginDir, nodePath, nodeVersion, buildDir, childEnv, systemLogFile, pluginPackageJson }), + startPlugin({ + pluginDir, + nodePath, + nodeVersion, + buildDir, + childEnv, + systemLog, + systemLogFile, + pluginPackageJson, + featureFlags, + }), ), ) return { childProcesses } @@ -60,8 +84,10 @@ const startPlugin = async function ({ nodePath, buildDir, childEnv, + systemLog, systemLogFile, pluginPackageJson, + featureFlags, }: { nodeVersion: string nodePath: string @@ -70,7 +96,9 @@ const startPlugin = async function ({ buildDir: string childEnv: Record pluginPackageJson: Record + systemLog: SystemLogger systemLogFile: number + featureFlags: FeatureFlags }) { const ctx = trace.getActiveSpan()?.spanContext() @@ -117,14 +145,23 @@ const startPlugin = async function ({ ? ['pipe', 'pipe', 'pipe', 'ipc', systemLogFile] : undefined, }) + const readyEvent = 'ready' + const cleanup = captureStandardError(childProcess, systemLog, readyEvent, featureFlags) try { - await getEventFromChild(childProcess, 'ready') + await getEventFromChild(childProcess, readyEvent) return { childProcess } } catch (error) { + if (featureFlags.netlify_build_plugin_system_log) { + // Wait for stderr to be flushed. + await pSetTimeout(0) + } + const spawnInfo = getSpawnInfo() addErrorInfo(error, spawnInfo) throw error + } finally { + cleanup() } } diff --git a/packages/build/src/plugins/system_log.ts b/packages/build/src/plugins/system_log.ts new file mode 100644 index 0000000000..fa90a81f74 --- /dev/null +++ b/packages/build/src/plugins/system_log.ts @@ -0,0 +1,37 @@ +import type { FeatureFlags } from '../core/feature_flags.js' +import type { SystemLogger } from '../plugins_core/types.js' + +import type { ChildProcess } from './spawn.js' + +export const captureStandardError = ( + childProcess: ChildProcess, + systemLog: SystemLogger, + eventName: string, + featureFlags: FeatureFlags, +) => { + if (!featureFlags.netlify_build_plugin_system_log) { + return () => { + // no-op + } + } + + let receivedChunks = false + + const listener = (chunk: Buffer) => { + if (!receivedChunks) { + receivedChunks = true + + systemLog(`Plugin failed to initialize during the "${eventName}" phase`) + } + + systemLog(chunk.toString().trimEnd()) + } + + childProcess.stderr?.on('data', listener) + + const cleanup = () => { + childProcess.stderr?.removeListener('data', listener) + } + + return cleanup +} diff --git a/packages/build/tests/plugins/snapshots/tests.js.snap b/packages/build/tests/plugins/snapshots/tests.js.snap index d3bb62fc0d..a0e706ac7d 100644 Binary files a/packages/build/tests/plugins/snapshots/tests.js.snap and b/packages/build/tests/plugins/snapshots/tests.js.snap differ diff --git a/packages/build/tests/plugins/tests.js b/packages/build/tests/plugins/tests.js index 50d804d042..630b1f6d6f 100644 --- a/packages/build/tests/plugins/tests.js +++ b/packages/build/tests/plugins/tests.js @@ -360,8 +360,10 @@ test('Plugin errors that occur during the loading phase are piped to system logs if (platform !== 'win32') { const systemLog = await fs.readFile(systemLogFile.path, { encoding: 'utf8' }) + const lines = systemLog.split('\n') - t.is(systemLog.trim(), 'An error message thrown by Node.js') + t.is(lines[0].trim(), 'Plugin failed to initialize during the "load" phase') + t.is(lines[1].trim(), 'An error message thrown by Node.js') } t.snapshot(normalizeOutput(output))