Skip to content

Commit e95af74

Browse files
RafaelGSSQard
authored and
targos
committed
lib: add diagnostics_channel events to module loading
This commit adds a tracing channel for module loading through `import()` and `require()`. Co-Authored-By: Stephen Belanger <[email protected]> PR-URL: #44340 Reviewed-By: Geoffrey Booth <[email protected]> Reviewed-By: Santiago Gimeno <[email protected]> Reviewed-By: Rafael Gonzaga <[email protected]> Reviewed-By: James M Snell <[email protected]> Reviewed-By: Gerhard Stöbich <[email protected]>
1 parent 49cfb9d commit e95af74

25 files changed

+398
-37
lines changed

‎doc/api/diagnostics_channel.md

Lines changed: 52 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1117,6 +1117,58 @@ Emitted when server receives a request.
11171117

11181118
Emitted when server sends a response.
11191119

1120+
#### Modules
1121+
1122+
`module.require.start`
1123+
1124+
* `event` {Object} containing the following properties
1125+
* `id` - Argument passed to `require()`. Module name.
1126+
* `parentFilename` - Name of the module that attempted to require(id).
1127+
1128+
Emitted when `require()` is executed. See [`start` event][].
1129+
1130+
`module.require.end`
1131+
1132+
* `event` {Object} containing the following properties
1133+
* `id` - Argument passed to `require()`. Module name.
1134+
* `parentFilename` - Name of the module that attempted to require(id).
1135+
1136+
Emitted when a `require()` call returns. See [`end` event][].
1137+
1138+
`module.require.error`
1139+
1140+
* `event` {Object} containing the following properties
1141+
* `id` - Argument passed to `require()`. Module name.
1142+
* `parentFilename` - Name of the module that attempted to require(id).
1143+
* `error` {Error}
1144+
1145+
Emitted when a `require()` throws an error. See [`error` event][].
1146+
1147+
`module.import.asyncStart`
1148+
1149+
* `event` {Object} containing the following properties
1150+
* `id` - Argument passed to `import()`. Module name.
1151+
* `parentURL` - URL object of the module that attempted to import(id).
1152+
1153+
Emitted when `import()` is invoked. See [`asyncStart` event][].
1154+
1155+
`module.import.asyncEnd`
1156+
1157+
* `event` {Object} containing the following properties
1158+
* `id` - Argument passed to `import()`. Module name.
1159+
* `parentURL` - URL object of the module that attempted to import(id).
1160+
1161+
Emitted when `import()` has completed. See [`asyncEnd` event][].
1162+
1163+
`module.import.error`
1164+
1165+
* `event` {Object} containing the following properties
1166+
* `id` - Argument passed to `import()`. Module name.
1167+
* `parentURL` - URL object of the module that attempted to import(id).
1168+
* `error` {Error}
1169+
1170+
Emitted when a `import()` throws an error. See [`error` event][].
1171+
11201172
#### NET
11211173

11221174
`net.client.socket`

‎lib/diagnostics_channel.js

Lines changed: 11 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -269,7 +269,8 @@ function tracingChannelFrom(nameOrChannels, name) {
269269

270270
class TracingChannel {
271271
constructor(nameOrChannels) {
272-
for (const eventName of traceEvents) {
272+
for (let i = 0; i < traceEvents.length; ++i) {
273+
const eventName = traceEvents[i];
273274
ObjectDefineProperty(this, eventName, {
274275
__proto__: null,
275276
value: tracingChannelFrom(nameOrChannels, eventName),
@@ -278,15 +279,16 @@ class TracingChannel {
278279
}
279280

280281
get hasSubscribers() {
281-
return this.start.hasSubscribers ||
282-
this.end.hasSubscribers ||
283-
this.asyncStart.hasSubscribers ||
284-
this.asyncEnd.hasSubscribers ||
285-
this.error.hasSubscribers;
282+
return this.start?.hasSubscribers ||
283+
this.end?.hasSubscribers ||
284+
this.asyncStart?.hasSubscribers ||
285+
this.asyncEnd?.hasSubscribers ||
286+
this.error?.hasSubscribers;
286287
}
287288

288289
subscribe(handlers) {
289-
for (const name of traceEvents) {
290+
for (let i = 0; i < traceEvents.length; ++i) {
291+
const name = traceEvents[i];
290292
if (!handlers[name]) continue;
291293

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

299-
for (const name of traceEvents) {
301+
for (let i = 0; i < traceEvents.length; ++i) {
302+
const name = traceEvents[i];
300303
if (!handlers[name]) continue;
301304

302305
if (!this[name]?.unsubscribe(handlers[name])) {

‎lib/internal/modules/cjs/loader.js

Lines changed: 8 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -189,6 +189,9 @@ let { startTimer, endTimer } = debugWithTimer('module_timer', (start, end) => {
189189
endTimer = end;
190190
});
191191

192+
const { tracingChannel } = require('diagnostics_channel');
193+
const onRequire = getLazy(() => tracingChannel('module.require'));
194+
192195
const isWindows = process.platform === 'win32';
193196

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

211214
try {
212-
return Module._load(request, parent, isMain);
215+
return onRequire().traceSync(Module._load, {
216+
__proto__: null,
217+
parentFilename: parent?.filename,
218+
id: request,
219+
}, Module, request, parent, isMain);
213220
} finally {
214221
endTimer(logLabel, traceLabel);
215222
}

‎lib/internal/modules/esm/loader.js

Lines changed: 23 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -42,6 +42,9 @@ const {
4242
} = require('internal/modules/helpers');
4343
let defaultResolve, defaultLoad, defaultLoadSync, importMetaInitializer;
4444

45+
const { tracingChannel } = require('diagnostics_channel');
46+
const onImport = tracingChannel('module.import');
47+
4548
/**
4649
* @typedef {import('url').URL} URL
4750
*/
@@ -210,10 +213,17 @@ class ModuleLoader {
210213
return compileSourceTextModule(url, source, this);
211214
};
212215
const { ModuleJob } = require('internal/modules/esm/module_job');
213-
const job = new ModuleJob(
214-
this, url, undefined, evalInstance, false, false);
215-
this.loadCache.set(url, undefined, job);
216-
const { module } = await job.run(isEntryPoint);
216+
const module = await onImport.tracePromise(async () => {
217+
const job = new ModuleJob(
218+
this, url, undefined, evalInstance, false, false);
219+
this.loadCache.set(url, undefined, job);
220+
const { module } = await job.run(isEntryPoint);
221+
return module;
222+
}, {
223+
__proto__: null,
224+
parentURL: '<eval>',
225+
url,
226+
});
217227

218228
return {
219229
__proto__: null,
@@ -470,9 +480,15 @@ class ModuleLoader {
470480
* @returns {Promise<ModuleExports>}
471481
*/
472482
async import(specifier, parentURL, importAttributes, isEntryPoint = false) {
473-
const moduleJob = await this.getModuleJob(specifier, parentURL, importAttributes);
474-
const { module } = await moduleJob.run(isEntryPoint);
475-
return module.getNamespace();
483+
return onImport.tracePromise(async () => {
484+
const moduleJob = await this.getModuleJob(specifier, parentURL, importAttributes);
485+
const { module } = await moduleJob.run(isEntryPoint);
486+
return module.getNamespace();
487+
}, {
488+
__proto__: null,
489+
parentURL,
490+
url: specifier,
491+
});
476492
}
477493

478494
/**

‎test/fixtures/console/console.snapshot

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -7,3 +7,4 @@ Trace: foo
77
at *
88
at *
99
at *
10+
at *

‎test/fixtures/errors/force_colors.snapshot

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -11,5 +11,6 @@ Error: Should include grayed stack trace
1111
 at *
1212
 at *
1313
 at *
14+
 at *
1415

1516
Node.js *

‎test/fixtures/errors/promise_unhandled_warn_with_error.snapshot

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -7,5 +7,6 @@
77
at *
88
at *
99
at *
10+
at *
1011
(Use `node --trace-warnings ...` to show where the warning was created)
1112
(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)

‎test/fixtures/errors/unhandled_promise_trace_warnings.snapshot

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,7 @@
1111
at *
1212
at *
1313
at *
14+
at *
1415
(node:*) Error: This was rejected
1516
at *
1617
at *
@@ -20,6 +21,7 @@
2021
at *
2122
at *
2223
at *
24+
at *
2325
(node:*) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 1)
2426
at *
2527
at *

‎test/message/assert_throws_stack.out

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -16,6 +16,7 @@ AssertionError [ERR_ASSERTION]: Expected values to be strictly deep-equal:
1616
at *
1717
at *
1818
at *
19+
at *
1920
at * {
2021
generatedMessage: true,
2122
code: 'ERR_ASSERTION',

‎test/message/internal_assert.out

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,7 @@ Please open an issue with this stack trace at https://github.com/nodejs/node/iss
1313
at *
1414
at *
1515
at *
16+
at *
1617
at * {
1718
code: 'ERR_INTERNAL_ASSERTION'
1819
}

‎test/message/internal_assert_fail.out

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -14,6 +14,7 @@ Please open an issue with this stack trace at https://github.com/nodejs/node/iss
1414
at *
1515
at *
1616
at *
17+
at *
1718
at * {
1819
code: 'ERR_INTERNAL_ASSERTION'
1920
}

‎test/message/util-inspect-error-cause.out

Lines changed: 20 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -6,6 +6,7 @@ Error: Number error cause
66
at *
77
at *
88
at *
9+
at *
910
at * {
1011
[cause]: 42
1112
}
@@ -17,6 +18,7 @@ Error: Object cause
1718
at *
1819
at *
1920
at *
21+
at *
2022
at * {
2123
[cause]: {
2224
message: 'Unique',
@@ -33,6 +35,7 @@ Error: undefined cause
3335
at *
3436
at *
3537
at *
38+
at *
3639
at * {
3740
[cause]: undefined
3841
}
@@ -44,6 +47,7 @@ Error: cause that throws
4447
at *
4548
at *
4649
at *
50+
at *
4751
at * {
4852
[cause]: [Getter]
4953
}
@@ -53,7 +57,7 @@ RangeError: New Stack Frames
5357
[cause]: FoobarError: Individual message
5458
at *
5559
*[90m at *[39m
56-
*[90m ... 5 lines matching cause stack trace ...*[39m
60+
*[90m ... 6 lines matching cause stack trace ...*[39m
5761
*[90m at *[39m {
5862
status: *[32m'Feeling good'*[39m,
5963
extraProperties: *[32m'Yes!'*[39m,
@@ -66,17 +70,18 @@ RangeError: New Stack Frames
6670
*[90m at *[39m
6771
*[90m at *[39m
6872
*[90m at *[39m
73+
*[90m at *[39m
6974
}
7075
}
7176
Error: Stack causes
7277
at *
7378
*[90m at *[39m
74-
*[90m ... 5 lines matching cause stack trace ...*[39m
79+
*[90m ... 6 lines matching cause stack trace ...*[39m
7580
*[90m at *[39m {
7681
[cause]: FoobarError: Individual message
7782
at *
7883
*[90m at *[39m
79-
*[90m ... 5 lines matching cause stack trace ...*[39m
84+
*[90m ... 6 lines matching cause stack trace ...*[39m
8085
*[90m at *[39m {
8186
status: *[32m'Feeling good'*[39m,
8287
extraProperties: *[32m'Yes!'*[39m,
@@ -89,6 +94,7 @@ Error: Stack causes
8994
*[90m at *[39m
9095
*[90m at *[39m
9196
*[90m at *[39m
97+
*[90m at *[39m
9298
}
9399
}
94100
RangeError: New Stack Frames
@@ -97,12 +103,12 @@ RangeError: New Stack Frames
97103
[cause]: Error: Stack causes
98104
at *
99105
*[90m at *[39m
100-
*[90m ... 5 lines matching cause stack trace ...*[39m
106+
*[90m ... 6 lines matching cause stack trace ...*[39m
101107
*[90m at *[39m {
102108
[cause]: FoobarError: Individual message
103109
at *
104110
*[90m at *[39m
105-
*[90m ... 5 lines matching cause stack trace ...*[39m
111+
*[90m ... 6 lines matching cause stack trace ...*[39m
106112
*[90m at *[39m {
107113
status: *[32m'Feeling good'*[39m,
108114
extraProperties: *[32m'Yes!'*[39m,
@@ -115,6 +121,7 @@ RangeError: New Stack Frames
115121
*[90m at *[39m
116122
*[90m at *[39m
117123
*[90m at *[39m
124+
*[90m at *[39m
118125
}
119126
}
120127
}
@@ -124,7 +131,7 @@ RangeError: New Stack Frames
124131
[cause]: FoobarError: Individual message
125132
at *
126133
at *
127-
... 5 lines matching cause stack trace ...
134+
... 6 lines matching cause stack trace ...
128135
at * {
129136
status: 'Feeling good',
130137
extraProperties: 'Yes!',
@@ -137,17 +144,18 @@ RangeError: New Stack Frames
137144
at *
138145
at *
139146
at *
147+
at *
140148
}
141149
}
142150
Error: Stack causes
143151
at *
144152
at *
145-
... 5 lines matching cause stack trace ...
153+
... 6 lines matching cause stack trace ...
146154
at * {
147155
[cause]: FoobarError: Individual message
148156
at *
149157
at *
150-
... 5 lines matching cause stack trace ...
158+
... 6 lines matching cause stack trace ...
151159
at *
152160
status: 'Feeling good',
153161
extraProperties: 'Yes!',
@@ -160,6 +168,7 @@ Error: Stack causes
160168
at *
161169
at *
162170
at *
171+
at *
163172
}
164173
}
165174
RangeError: New Stack Frames
@@ -168,12 +177,12 @@ RangeError: New Stack Frames
168177
[cause]: Error: Stack causes
169178
at *
170179
at *
171-
... 5 lines matching cause stack trace ...
180+
... 6 lines matching cause stack trace ...
172181
at * {
173182
[cause]: FoobarError: Individual message
174183
at *
175184
at *
176-
... 5 lines matching cause stack trace ...
185+
... 6 lines matching cause stack trace ...
177186
at * {
178187
status: 'Feeling good',
179188
extraProperties: 'Yes!',
@@ -186,6 +195,7 @@ RangeError: New Stack Frames
186195
at *
187196
at *
188197
at *
198+
at *
189199
}
190200
}
191201
}

0 commit comments

Comments
 (0)