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.

Sign up for GitHub

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

Jump to bottom

lib: add diagnostics_channel events to module loading #44340

Closed
wants to merge 1 commit into from
Closed

lib: add diagnostics_channel events to module loading #44340

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
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
52 changes: 52 additions & 0 deletions doc/api/diagnostics_channel.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1117,6 +1117,58 @@ Emitted when server receives a request.

Emitted when server sends a response.

#### Modules

`module.require.start`

* `event` {Object} containing the following properties
* `id` - Argument passed to `require()`. Module name.
* `parentFilename` - Name of the module that attempted to require(id).

Emitted when `require()` is executed. See [`start` event][].

`module.require.end`

* `event` {Object} containing the following properties
* `id` - Argument passed to `require()`. Module name.
* `parentFilename` - Name of the module that attempted to require(id).

Emitted when a `require()` call returns. See [`end` event][].

`module.require.error`

* `event` {Object} containing the following properties
* `id` - Argument passed to `require()`. Module name.
* `parentFilename` - Name of the module that attempted to require(id).
* `error` {Error}

Emitted when a `require()` throws an error. See [`error` event][].

`module.import.asyncStart`
Flarna marked this conversation as resolved.
Show resolved Hide resolved

* `event` {Object} containing the following properties
* `id` - Argument passed to `import()`. Module name.
* `parentURL` - URL object of the module that attempted to import(id).

Emitted when `import()` is invoked. See [`asyncStart` event][].

`module.import.asyncEnd`

* `event` {Object} containing the following properties
* `id` - Argument passed to `import()`. Module name.
* `parentURL` - URL object of the module that attempted to import(id).

Emitted when `import()` has completed. See [`asyncEnd` event][].

`module.import.error`

* `event` {Object} containing the following properties
* `id` - Argument passed to `import()`. Module name.
* `parentURL` - URL object of the module that attempted to import(id).
* `error` {Error}

Emitted when a `import()` throws an error. See [`error` event][].

#### NET

`net.client.socket`
Expand Down
19 changes: 11 additions & 8 deletions lib/diagnostics_channel.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -269,7 +269,8 @@ function tracingChannelFrom(nameOrChannels, name) {

class TracingChannel {
constructor(nameOrChannels) {
for (const eventName of traceEvents) {
for (let i = 0; i < traceEvents.length; ++i) {
const eventName = traceEvents[i];
ObjectDefineProperty(this, eventName, {
__proto__: null,
value: tracingChannelFrom(nameOrChannels, eventName),
Expand All @@ -278,15 +279,16 @@ class TracingChannel {
}

get hasSubscribers() {
return this.start.hasSubscribers ||
this.end.hasSubscribers ||
this.asyncStart.hasSubscribers ||
this.asyncEnd.hasSubscribers ||
this.error.hasSubscribers;
return this.start?.hasSubscribers ||
this.end?.hasSubscribers ||
this.asyncStart?.hasSubscribers ||
this.asyncEnd?.hasSubscribers ||
this.error?.hasSubscribers;
}

subscribe(handlers) {
for (const name of traceEvents) {
for (let i = 0; i < traceEvents.length; ++i) {
const name = traceEvents[i];
if (!handlers[name]) continue;

this[name]?.subscribe(handlers[name]);
Expand All @@ -296,7 +298,8 @@ class TracingChannel {
unsubscribe(handlers) {
let done = true;

for (const name of traceEvents) {
for (let i = 0; i < traceEvents.length; ++i) {
const name = traceEvents[i];
if (!handlers[name]) continue;

if (!this[name]?.unsubscribe(handlers[name])) {
Expand Down
9 changes: 8 additions & 1 deletion lib/internal/modules/cjs/loader.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -189,6 +189,9 @@ let { startTimer, endTimer } = debugWithTimer('module_timer', (start, end) => {
endTimer = end;
});

const { tracingChannel } = require('diagnostics_channel');
const onRequire = getLazy(() => tracingChannel('module.require'));
Copy link
Member

Choose a reason for hiding this comment

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

getLazy is required otherwise it will cause segmentation fault on nodejs build. I haven't figured it out in-depth, but I suspect some module required by dc isn't available before Node.js fully startup.

Copy link
Member Author

Choose a reason for hiding this comment

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

My guess would be that WeakReference is not initialized yet.


const isWindows = process.platform === 'win32';

const relativeResolveCache = { __proto__: null };
Expand All @@ -209,7 +212,11 @@ function wrapModuleLoad(request, parent, isMain) {
startTimer(logLabel, traceLabel);

try {
return Module._load(request, parent, isMain);
return onRequire().traceSync(Module._load, {
__proto__: null,
parentFilename: parent?.filename,
id: request,
}, Module, request, parent, isMain);
} finally {
endTimer(logLabel, traceLabel);
}
Expand Down
30 changes: 23 additions & 7 deletions lib/internal/modules/esm/loader.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -43,6 +43,9 @@ const {
} = require('internal/modules/helpers');
let defaultResolve, defaultLoad, defaultLoadSync, importMetaInitializer;

const { tracingChannel } = require('diagnostics_channel');
const onImport = tracingChannel('module.import');

/**
* @typedef {import('url').URL} URL
*/
Expand Down Expand Up @@ -211,10 +214,17 @@ class ModuleLoader {
return compileSourceTextModule(url, source, this);
};
const { ModuleJob } = require('internal/modules/esm/module_job');
const job = new ModuleJob(
this, url, undefined, evalInstance, false, false);
this.loadCache.set(url, undefined, job);
const { module } = await job.run(isEntryPoint);
const module = await onImport.tracePromise(async () => {
const job = new ModuleJob(
this, url, undefined, evalInstance, false, false);
this.loadCache.set(url, undefined, job);
const { module } = await job.run(isEntryPoint);
return module;
}, {
__proto__: null,
parentURL: '<eval>',
url,
});
Copy link
Member

Choose a reason for hiding this comment

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

So this is capturing ESM code that comes from --eval or STDIN? Shouldn’t we do the same for CommonJS string input?

Copy link
Member Author

Choose a reason for hiding this comment

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

Maybe? I'm not sure we actually need this here. I'm still working on this and figuring out testing and some changes that probably need to be made.


return {
__proto__: null,
Expand Down Expand Up @@ -470,9 +480,15 @@ class ModuleLoader {
* @returns {Promise<ModuleExports>}
*/
async import(specifier, parentURL, importAttributes, isEntryPoint = false) {
const moduleJob = await this.getModuleJob(specifier, parentURL, importAttributes);
const { module } = await moduleJob.run(isEntryPoint);
return module.getNamespace();
return onImport.tracePromise(async () => {
const moduleJob = await this.getModuleJob(specifier, parentURL, importAttributes);
Flarna marked this conversation as resolved.
Show resolved Hide resolved
const { module } = await moduleJob.run(isEntryPoint);
return module.getNamespace();
}, {
__proto__: null,
parentURL,
url: specifier,
});
}

/**
Expand Down
1 change: 1 addition & 0 deletions test/fixtures/console/console.snapshot
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -7,3 +7,4 @@ Trace: foo
at *
at *
at *
at *
1 change: 1 addition & 0 deletions test/fixtures/errors/force_colors.snapshot
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -11,5 +11,6 @@ Error: Should include grayed stack trace
 at *
 at *
 at *
 at *

Node.js *
1 change: 1 addition & 0 deletions test/fixtures/errors/promise_unhandled_warn_with_error.snapshot
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -7,5 +7,6 @@
at *
at *
at *
at *
(Use `node --trace-warnings ...` to show where the warning was created)
(node:*) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https:*nodejs.org*api*cli.html#cli_unhandled_rejections_mode). (rejection id: 1)
2 changes: 2 additions & 0 deletions test/fixtures/errors/unhandled_promise_trace_warnings.snapshot
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,7 @@
at *
at *
at *
at *
(node:*) Error: This was rejected
at *
at *
Expand All @@ -20,6 +21,7 @@
at *
at *
at *
at *
(node:*) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 1)
at *
at *
Expand Down
1 change: 1 addition & 0 deletions test/message/assert_throws_stack.out
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@ AssertionError [ERR_ASSERTION]: Expected values to be strictly deep-equal:
at *
at *
at *
at *
at * {
generatedMessage: true,
code: 'ERR_ASSERTION',
Expand Down
1 change: 1 addition & 0 deletions test/message/internal_assert.out
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,7 @@ Please open an issue with this stack trace at https://github.com/nodejs/node/iss
at *
at *
at *
at *
at * {
code: 'ERR_INTERNAL_ASSERTION'
}
Expand Down
1 change: 1 addition & 0 deletions test/message/internal_assert_fail.out
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,7 @@ Please open an issue with this stack trace at https://github.com/nodejs/node/iss
at *
at *
at *
at *
at * {
code: 'ERR_INTERNAL_ASSERTION'
}
Expand Down
30 changes: 20 additions & 10 deletions test/message/util-inspect-error-cause.out
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@ Error: Number error cause
at *
at *
at *
at *
at * {
[cause]: 42
}
Expand All @@ -17,6 +18,7 @@ Error: Object cause
at *
at *
at *
at *
at * {
[cause]: {
message: 'Unique',
Expand All @@ -33,6 +35,7 @@ Error: undefined cause
at *
at *
at *
at *
at * {
[cause]: undefined
}
Expand All @@ -44,6 +47,7 @@ Error: cause that throws
at *
at *
at *
at *
at * {
[cause]: [Getter]
}
Expand All @@ -53,7 +57,7 @@ RangeError: New Stack Frames
[cause]: FoobarError: Individual message
at *
*[90m at *[39m
*[90m ... 5 lines matching cause stack trace ...*[39m
*[90m ... 6 lines matching cause stack trace ...*[39m
*[90m at *[39m {
status: *[32m'Feeling good'*[39m,
extraProperties: *[32m'Yes!'*[39m,
Expand All @@ -66,17 +70,18 @@ RangeError: New Stack Frames
*[90m at *[39m
*[90m at *[39m
*[90m at *[39m
*[90m at *[39m
}
}
Error: Stack causes
at *
*[90m at *[39m
*[90m ... 5 lines matching cause stack trace ...*[39m
*[90m ... 6 lines matching cause stack trace ...*[39m
*[90m at *[39m {
[cause]: FoobarError: Individual message
at *
*[90m at *[39m
*[90m ... 5 lines matching cause stack trace ...*[39m
*[90m ... 6 lines matching cause stack trace ...*[39m
*[90m at *[39m {
status: *[32m'Feeling good'*[39m,
extraProperties: *[32m'Yes!'*[39m,
Expand All @@ -89,6 +94,7 @@ Error: Stack causes
*[90m at *[39m
*[90m at *[39m
*[90m at *[39m
*[90m at *[39m
}
}
RangeError: New Stack Frames
Expand All @@ -97,12 +103,12 @@ RangeError: New Stack Frames
[cause]: Error: Stack causes
at *
*[90m at *[39m
*[90m ... 5 lines matching cause stack trace ...*[39m
*[90m ... 6 lines matching cause stack trace ...*[39m
*[90m at *[39m {
[cause]: FoobarError: Individual message
at *
*[90m at *[39m
*[90m ... 5 lines matching cause stack trace ...*[39m
*[90m ... 6 lines matching cause stack trace ...*[39m
*[90m at *[39m {
status: *[32m'Feeling good'*[39m,
extraProperties: *[32m'Yes!'*[39m,
Expand All @@ -115,6 +121,7 @@ RangeError: New Stack Frames
*[90m at *[39m
*[90m at *[39m
*[90m at *[39m
*[90m at *[39m
}
}
}
Expand All @@ -124,7 +131,7 @@ RangeError: New Stack Frames
[cause]: FoobarError: Individual message
at *
at *
... 5 lines matching cause stack trace ...
... 6 lines matching cause stack trace ...
at * {
status: 'Feeling good',
extraProperties: 'Yes!',
Expand All @@ -137,17 +144,18 @@ RangeError: New Stack Frames
at *
at *
at *
at *
}
}
Error: Stack causes
at *
at *
... 5 lines matching cause stack trace ...
... 6 lines matching cause stack trace ...
at * {
[cause]: FoobarError: Individual message
at *
at *
... 5 lines matching cause stack trace ...
... 6 lines matching cause stack trace ...
at *
status: 'Feeling good',
extraProperties: 'Yes!',
Expand All @@ -160,6 +168,7 @@ Error: Stack causes
at *
at *
at *
at *
}
}
RangeError: New Stack Frames
Expand All @@ -168,12 +177,12 @@ RangeError: New Stack Frames
[cause]: Error: Stack causes
at *
at *
... 5 lines matching cause stack trace ...
... 6 lines matching cause stack trace ...
at * {
[cause]: FoobarError: Individual message
at *
at *
... 5 lines matching cause stack trace ...
... 6 lines matching cause stack trace ...
at * {
status: 'Feeling good',
extraProperties: 'Yes!',
Expand All @@ -186,6 +195,7 @@ RangeError: New Stack Frames
at *
at *
at *
at *
}
}
}
Loading