Skip to content

Commit 4f4b9dc

Browse files
AgentEnderclaudenx-cloud[bot]
authored
fix(core): improve plugin worker error messages and lifecycle timeouts (#34251)
## Current Behavior Plugin workers occasionally fall over during the start up steps. ## Expected Behavior Improves some issues with the error handling when loading plugin workers and adds some more logs to help understand what's went wrong here. ## Related Issue(s) <!-- Please link the issue being fixed so it gets closed when this is merged. --> Fixes # --------- Co-authored-by: Claude <noreply@anthropic.com> Co-authored-by: nx-cloud[bot] <71083854+nx-cloud[bot]@users.noreply.github.com> Co-authored-by: AgentEnder <AgentEnder@users.noreply.github.com>
1 parent fdabc14 commit 4f4b9dc

8 files changed

Lines changed: 207 additions & 49 deletions

e2e/release/src/independent-projects.test.ts

Lines changed: 15 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -237,7 +237,11 @@ describe('nx release - independent projects', () => {
237237
const versionWithGitActionsCLIOutput = runCLI(
238238
`release version 999.9.9-version-git-operations-test.2 -p ${pkg1} --git-commit --git-tag --verbose` // add verbose so we get richer output
239239
);
240-
expect(versionWithGitActionsCLIOutput).toMatchInlineSnapshot(`
240+
const filteredOutput = versionWithGitActionsCLIOutput.replace(
241+
/\[plugin-(pool|worker)\].*\n/g,
242+
''
243+
);
244+
expect(filteredOutput).toMatchInlineSnapshot(`
241245
242246
NX Your filter "{project-name}" matched the following projects:
243247
@@ -320,7 +324,11 @@ describe('nx release - independent projects', () => {
320324
const versionWithGitActionsConfigOutput = runCLI(
321325
`release version 999.9.9-version-git-operations-test.3 --verbose --gitTag` // add verbose so we get richer output
322326
);
323-
expect(versionWithGitActionsConfigOutput).toMatchInlineSnapshot(`
327+
const filteredConfigOutput = versionWithGitActionsConfigOutput.replace(
328+
/\[plugin-(pool|worker)\].*\n/g,
329+
''
330+
);
331+
expect(filteredConfigOutput).toMatchInlineSnapshot(`
324332
325333
NX Running release version for project: {project-name}
326334
@@ -516,7 +524,11 @@ describe('nx release - independent projects', () => {
516524
const versionWithGitActionsCLIOutput = runCLI(
517525
`release changelog 999.9.9-changelog-git-operations-test.1 -p ${pkg1} --verbose`
518526
);
519-
expect(versionWithGitActionsCLIOutput).toMatchInlineSnapshot(`
527+
const filteredChangelogOutput = versionWithGitActionsCLIOutput.replace(
528+
/\[plugin-(pool|worker)\].*\n/g,
529+
''
530+
);
531+
expect(filteredChangelogOutput).toMatchInlineSnapshot(`
520532
521533
NX Your filter "{project-name}" matched the following projects:
522534

e2e/release/src/independent-projects.workspaces.test.ts

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -54,6 +54,8 @@ expect.addSnapshotSerializer({
5454
.replaceAll('pnpm install --lockfile-only', '{lock-file-command}')
5555
.replaceAll(getSelectedPackageManager(), '{package-manager}')
5656
.replaceAll(e2eRegistryUrl, '{registryUrl}')
57+
// Filter out plugin worker verbose logs
58+
.replaceAll(/\[plugin-(pool|worker)\].*\n/g, '')
5759
// We trim each line to reduce the chances of snapshot flakiness
5860
.split('\n')
5961
.map((r) => r.trim())

e2e/release/src/preserve-local-dependency-protocols.test.ts

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -47,6 +47,8 @@ expect.addSnapshotSerializer({
4747
/Integrity:\s*.*/g,
4848
'Integrity: XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX'
4949
)
50+
// Filter out plugin worker verbose logs
51+
.replaceAll(/\[plugin-(pool|worker)\].*\n/g, '')
5052

5153
.split('\n')
5254
.map((r) => r.trim())

e2e/release/src/version-plans-check.test.ts

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -32,6 +32,8 @@ expect.addSnapshotSerializer({
3232
.replaceAll(/Test @[\w\d]+/g, 'Test @{COMMIT_AUTHOR}')
3333
// Normalize the version title date.
3434
.replaceAll(/\(\d{4}-\d{2}-\d{2}\)/g, '(YYYY-MM-DD)')
35+
// Filter out plugin worker verbose logs
36+
.replaceAll(/\[plugin-(pool|worker)\].*\n/g, '')
3537
// We trim each line to reduce the chances of snapshot flakiness
3638
.split('\n')
3739
.map((r) => r.trim())

e2e/release/src/version-plans-only-touched.test.ts

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -29,6 +29,8 @@ expect.addSnapshotSerializer({
2929
.replaceAll(/Test @[\w\d]+/g, 'Test @{COMMIT_AUTHOR}')
3030
// Normalize the version title date.
3131
.replaceAll(/\(\d{4}-\d{2}-\d{2}\)/g, '(YYYY-MM-DD)')
32+
// Filter out plugin worker verbose logs
33+
.replaceAll(/\[plugin-(pool|worker)\].*\n/g, '')
3234
// We trim each line to reduce the chances of snapshot flakiness
3335
.split('\n')
3436
.map((r) => r.trim())

packages/nx/src/project-graph/plugins/get-plugins.ts

Lines changed: 108 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -47,14 +47,35 @@ export async function getPlugins(
4747
}
4848

4949
currentPluginsConfigurationHash = pluginsConfigurationHash;
50-
const [defaultPlugins, specifiedPlugins] = await Promise.all([
50+
const results = await Promise.allSettled([
5151
getOnlyDefaultPlugins(root),
5252
(pendingPluginsPromise ??= loadSpecifiedNxPlugins(
5353
pluginsConfiguration,
5454
root
5555
)),
5656
]);
5757

58+
const errors: Error[] = [];
59+
const defaultPlugins: LoadedNxPlugin[] = [];
60+
const specifiedPlugins: LoadedNxPlugin[] = [];
61+
62+
for (let i = 0; i < results.length; i++) {
63+
const result = results[i];
64+
if (result.status === 'fulfilled') {
65+
(i === 0 ? defaultPlugins : specifiedPlugins).push(...result.value);
66+
} else {
67+
errors.push(
68+
result.reason instanceof Error
69+
? result.reason
70+
: new Error(String(result.reason))
71+
);
72+
}
73+
}
74+
75+
if (errors.length > 0) {
76+
throw new AggregateError(errors, errors.map((e) => e.message).join('\n'));
77+
}
78+
5879
loadedPlugins = specifiedPlugins.concat(defaultPlugins);
5980

6081
return loadedPlugins;
@@ -115,28 +136,58 @@ async function loadDefaultNxPlugins(root = workspaceRoot) {
115136
const plugins = getDefaultPlugins(root);
116137

117138
const cleanupFunctions: Array<() => void> = [];
139+
const results = await Promise.allSettled(
140+
plugins.map(async (plugin) => {
141+
performance.mark(`Load Nx Plugin: ${plugin} - start`);
142+
143+
const [loadedPluginPromise, cleanup] = await loadingMethod(plugin, root);
144+
145+
cleanupFunctions.push(cleanup);
146+
const res = await loadedPluginPromise;
147+
performance.mark(`Load Nx Plugin: ${plugin} - end`);
148+
performance.measure(
149+
`Load Nx Plugin: ${plugin}`,
150+
`Load Nx Plugin: ${plugin} - start`,
151+
`Load Nx Plugin: ${plugin} - end`
152+
);
153+
154+
return res;
155+
})
156+
);
157+
158+
const defaultPluginResults: LoadedNxPlugin[] = [];
159+
const errors: Array<{ pluginName: string; error: Error }> = [];
160+
161+
for (let i = 0; i < results.length; i++) {
162+
const result = results[i];
163+
if (result.status === 'fulfilled') {
164+
defaultPluginResults.push(result.value);
165+
} else {
166+
errors.push({
167+
pluginName: plugins[i],
168+
error:
169+
result.reason instanceof Error
170+
? result.reason
171+
: new Error(String(result.reason)),
172+
});
173+
}
174+
}
175+
176+
if (errors.length > 0) {
177+
for (const fn of cleanupFunctions) {
178+
fn();
179+
}
180+
const errorMessage = errors
181+
.map((e) => ` - ${e.pluginName}: ${e.error.message}`)
182+
.join('\n');
183+
throw new AggregateError(
184+
errors.map((e) => e.error),
185+
`Failed to load ${errors.length} default Nx plugin(s):\n${errorMessage}`
186+
);
187+
}
188+
118189
const ret = [
119-
await Promise.all(
120-
plugins.map(async (plugin) => {
121-
performance.mark(`Load Nx Plugin: ${plugin} - start`);
122-
123-
const [loadedPluginPromise, cleanup] = await loadingMethod(
124-
plugin,
125-
root
126-
);
127-
128-
cleanupFunctions.push(cleanup);
129-
const res = await loadedPluginPromise;
130-
performance.mark(`Load Nx Plugin: ${plugin} - end`);
131-
performance.measure(
132-
`Load Nx Plugin: ${plugin}`,
133-
`Load Nx Plugin: ${plugin} - start`,
134-
`Load Nx Plugin: ${plugin} - end`
135-
);
136-
137-
return res;
138-
})
139-
),
190+
defaultPluginResults,
140191
() => {
141192
for (const fn of cleanupFunctions) {
142193
fn();
@@ -170,7 +221,7 @@ async function loadSpecifiedNxPlugins(
170221
pluginsConfigurations ??= [];
171222

172223
const cleanupFunctions: Array<() => void> = [];
173-
const plugins = await Promise.all(
224+
const results = await Promise.allSettled(
174225
pluginsConfigurations.map(async (plugin, index) => {
175226
const pluginPath = typeof plugin === 'string' ? plugin : plugin.plugin;
176227
performance.mark(`Load Nx Plugin: ${pluginPath} - start`);
@@ -201,6 +252,40 @@ async function loadSpecifiedNxPlugins(
201252
'loadSpecifiedNxPlugins:end'
202253
);
203254

255+
const plugins: LoadedNxPlugin[] = [];
256+
const errors: Array<{ pluginName: string; error: Error }> = [];
257+
258+
for (let i = 0; i < results.length; i++) {
259+
const result = results[i];
260+
if (result.status === 'fulfilled') {
261+
plugins.push(result.value);
262+
} else {
263+
const pluginConfig = pluginsConfigurations[i];
264+
const pluginName =
265+
typeof pluginConfig === 'string' ? pluginConfig : pluginConfig.plugin;
266+
errors.push({
267+
pluginName,
268+
error:
269+
result.reason instanceof Error
270+
? result.reason
271+
: new Error(String(result.reason)),
272+
});
273+
}
274+
}
275+
276+
if (errors.length > 0) {
277+
for (const fn of cleanupFunctions) {
278+
fn();
279+
}
280+
const errorMessage = errors
281+
.map((e) => ` - ${e.pluginName}: ${e.error.message}`)
282+
.join('\n');
283+
throw new AggregateError(
284+
errors.map((e) => e.error),
285+
`Failed to load ${errors.length} Nx plugin(s):\n${errorMessage}`
286+
);
287+
}
288+
204289
cleanupSpecifiedPlugins = () => {
205290
for (const fn of cleanupFunctions) {
206291
fn();

packages/nx/src/project-graph/plugins/isolation/plugin-pool.ts

Lines changed: 21 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -4,8 +4,7 @@ import path = require('path');
44

55
import { PluginConfiguration } from '../../../config/nx-json';
66

7-
// TODO (@AgentEnder): After scoped verbose logging is implemented, re-add verbose logs here.
8-
// import { logger } from '../../utils/logger';
7+
import { logger } from '../../../utils/logger';
98

109
import { getPluginOsSocketPath } from '../../../daemon/socket-utils';
1110
import { consumeMessagesFromSocket } from '../../../utils/consume-messages-from-socket';
@@ -189,6 +188,9 @@ function createWorkerHandler(
189188
const { name, createNodesPattern, include, exclude } = result;
190189
pluginName = name;
191190
pluginNames.set(worker, pluginName);
191+
logger.verbose(
192+
`[plugin-pool] loaded plugin "${name}" from worker (pid: ${worker.pid})`
193+
);
192194
onload({
193195
name,
194196
include,
@@ -431,6 +433,7 @@ function registerPendingPromise(
431433
global.nxPluginWorkerCount ??= 0;
432434

433435
async function startPluginWorker(name: string) {
436+
performance.mark(`start-plugin-worker:${name}`);
434437
// this should only really be true when running unit tests within
435438
// the Nx repo. We still need to start the worker in this case,
436439
// but its typescript.
@@ -471,6 +474,10 @@ async function startPluginWorker(name: string) {
471474
}
472475
);
473476

477+
logger.verbose(
478+
`[plugin-pool] spawned worker for "${name}" (pid: ${worker.pid}, socket: ${ipcPath})`
479+
);
480+
474481
// To make debugging easier and allow plugins to communicate things
475482
// like performance metrics, we pipe the stdout/stderr of the worker
476483
// to the main process.
@@ -529,18 +536,29 @@ async function startPluginWorker(name: string) {
529536
if (socket) {
530537
socket.unref();
531538
clearInterval(id);
539+
logger.verbose(
540+
`[plugin-pool] connected to worker for "${name}" (pid: ${worker.pid}) after ${attempts} attempt(s)`
541+
);
532542
resolve({
533543
worker,
534544
socket,
535545
});
536546
} else if (attempts > 10000) {
537547
// daemon fails to start, the process probably exited
538548
// we print the logs and exit the client
539-
reject('Failed to start plugin worker.');
549+
clearInterval(id);
550+
reject(new Error(`Failed to start plugin worker for plugin ${name}`));
540551
} else {
541552
attempts++;
542553
}
543554
}, 10);
555+
}).finally(() => {
556+
performance.mark(`start-plugin-worker-end:${name}`);
557+
performance.measure(
558+
`start-plugin-worker:${name}`,
559+
`start-plugin-worker:${name}`,
560+
`start-plugin-worker-end:${name}`
561+
);
544562
});
545563
}
546564

0 commit comments

Comments
 (0)