Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat: emit system log when plugin has failed to load #5679

Merged
merged 3 commits into from
May 28, 2024
Merged
Show file tree
Hide file tree
Changes from 2 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 2 additions & 0 deletions packages/build/src/core/build.ts
Original file line number Diff line number Diff line change
Expand Up @@ -618,6 +618,8 @@ const runBuild = async function ({
debug,
verbose,
netlifyConfig,
featureFlags,
systemLog,
})

const { steps, events } =
Expand Down
1 change: 1 addition & 0 deletions packages/build/src/core/feature_flags.ts
Original file line number Diff line number Diff line change
Expand Up @@ -22,4 +22,5 @@ export const DEFAULT_FEATURE_FLAGS: FeatureFlags = {
edge_functions_system_logger: false,
netlify_build_reduced_output: false,
netlify_build_updated_plugin_compatibility: false,
netlify_build_plugin_system_log: false,
}
54 changes: 51 additions & 3 deletions packages/build/src/plugins/load.js
Original file line number Diff line number Diff line change
@@ -1,9 +1,13 @@
import { promisify } from 'util'

import { addErrorInfo } from '../error/info.js'
import { addPluginLoadErrorStatus } from '../status/load_error.js'
import { measureDuration } from '../time/main.js'

import { callChild } from './ipc.js'

const pSetTimeout = promisify(setTimeout)

// Retrieve all plugins steps
// Can use either a module name or a file path to the plugin.
export const loadPlugins = async function ({
Expand All @@ -15,10 +19,23 @@ export const loadPlugins = async function ({
debug,
verbose,
netlifyConfig,
featureFlags,
systemLog,
}) {
return pluginsOptions.length === 0
? { pluginsSteps: [], timers }
: await loadAllPlugins({ pluginsOptions, childProcesses, packageJson, timers, logs, debug, verbose, netlifyConfig })
: await loadAllPlugins({
pluginsOptions,
childProcesses,
packageJson,
timers,
logs,
debug,
verbose,
netlifyConfig,
featureFlags,
systemLog,
})
}

const tLoadAllPlugins = async function ({
Expand All @@ -29,10 +46,22 @@ const tLoadAllPlugins = async function ({
debug,
verbose,
netlifyConfig,
featureFlags,
systemLog,
}) {
const pluginsSteps = await Promise.all(
pluginsOptions.map((pluginOptions, index) =>
loadPlugin(pluginOptions, { childProcesses, index, packageJson, logs, debug, verbose, netlifyConfig }),
loadPlugin(pluginOptions, {
childProcesses,
index,
packageJson,
logs,
debug,
verbose,
netlifyConfig,
featureFlags,
systemLog,
}),
),
)
const pluginsStepsA = pluginsSteps.flat()
Expand All @@ -46,11 +75,21 @@ const loadAllPlugins = measureDuration(tLoadAllPlugins, 'load_plugins')
// Do it by executing the plugin `load` event handler.
const loadPlugin = async function (
{ packageName, pluginPackageJson, pluginPackageJson: { version } = {}, pluginPath, inputs, loadedFrom, origin },
{ childProcesses, index, packageJson, logs, debug, verbose, netlifyConfig },
{ childProcesses, index, packageJson, logs, debug, verbose, netlifyConfig, featureFlags, systemLog },
) {
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 = []

if (featureFlags.netlify_build_plugin_system_log && childProcess.stderr) {
childProcess.stderr.on('data', (data) => {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

should we unregister this after we're done initialising?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good point. Done in a0b4327.

bufferedStdErr.push(data.toString().trimEnd())
})
}

try {
const { events } = await callChild({
childProcess,
Expand All @@ -69,6 +108,15 @@ const loadPlugin = async function (
}))
return pluginSteps
} catch (error) {
if (featureFlags.netlify_build_plugin_system_log) {
// Wait for stderr to be flushed.
await pSetTimeout(0)

bufferedStdErr.forEach((line) => {
systemLog(line)
})
}

addErrorInfo(error, {
plugin: { packageName, pluginPackageJson },
location: { event: loadEvent, packageName, loadedFrom, origin },
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,2 @@
name: test
inputs: []
Original file line number Diff line number Diff line change
@@ -0,0 +1,2 @@
[[plugins]]
package = "./plugin"
Original file line number Diff line number Diff line change
@@ -0,0 +1,2 @@
console.error("An error message thrown by Node.js")
process.exit(1)
55 changes: 55 additions & 0 deletions packages/build/tests/plugins/snapshots/tests.js.md
Original file line number Diff line number Diff line change
Expand Up @@ -2747,3 +2747,58 @@ Generated by [AVA](https://avajs.dev).
────────────────────────────────────────────────────────────────␊
(Netlify Build completed in 1ms)`

## Plugin errors that occur during the loading phase are piped to system logs

> Snapshot 1

`␊
Netlify Build ␊
────────────────────────────────────────────────────────────────␊
> Version␊
@netlify/build 1.0.0␊
> Flags␊
debug: false␊
> Current directory␊
packages/build/tests/plugins/fixtures/syntax_error␊
> Config file␊
packages/build/tests/plugins/fixtures/syntax_error/netlify.toml␊
> Context␊
production␊
> Loading plugins␊
- ./plugin@1.0.0 from netlify.toml␊
Plugin "./plugin" internal error ␊
────────────────────────────────────────────────────────────────␊
Error message␊
Plugin exited with exit code 1 and signal null.␊
The plugin might have exited due to a bug terminating the process, such as an infinite loop.␊
The plugin might also have explicitly terminated the process, for example with process.exit().␊
Plugin methods should instead:␊
- on success: return␊
- on failure: call utils.build.failPlugin() or utils.build.failBuild()␊
Plugin details␊
Package: ./plugin␊
Version: 1.0.0␊
Repository: git+https://github.com/netlify/build.git␊
Report issues: https://github.com/netlify/build/issues␊
Error location␊
While loading "./plugin" from netlify.toml␊
Resolved config␊
build:␊
publish: packages/build/tests/plugins/fixtures/syntax_error␊
publishOrigin: default␊
plugins:␊
- inputs: {}␊
origin: config␊
package: ./plugin`
Binary file modified packages/build/tests/plugins/snapshots/tests.js.snap
Binary file not shown.
19 changes: 19 additions & 0 deletions packages/build/tests/plugins/tests.js
Original file line number Diff line number Diff line change
Expand Up @@ -347,3 +347,22 @@ test('Plugin events that do not emit to stderr/stdout are hidden from the logs',
.runWithBuild()
t.snapshot(normalizeOutput(output))
})

test('Plugin errors that occur during the loading phase are piped to system logs', async (t) => {
const systemLogFile = await tmp.file()
const output = await new Fixture('./fixtures/syntax_error')
.withFlags({
debug: false,
featureFlags: { netlify_build_reduced_output: true, netlify_build_plugin_system_log: true },
systemLogFile: systemLogFile.fd,
})
.runWithBuild()

if (platform !== 'win32') {
const systemLog = await fs.readFile(systemLogFile.path, { encoding: 'utf8' })

t.is(systemLog.trim(), 'An error message thrown by Node.js')
}

t.snapshot(normalizeOutput(output))
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could we replace the snapshot with a more precise assertion?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The snapshot is just an accessory thing to ensure we're not throwing an unexpected error somewhere else. The main assertion is ensuring the stuff we pushed to stderr is piped to system logs:

t.is(systemLog.trim(), 'An error message thrown by Node.js')

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If it's about asserting there's no error, maybe it's better to check something like build success? We're always complaining about the snapshot tests so much, so I think we shouldn't add them unnecessarily.

})
Loading