Skip to content

Commit 845806a

Browse files
RafaelGSSQard
authored and
joyeecheung
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: nodejs#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 fc4b30a commit 845806a

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
@@ -1150,6 +1150,58 @@ Emitted when server receives a request.
11501150

11511151
Emitted when server sends a response.
11521152

1153+
#### Modules
1154+
1155+
`module.require.start`
1156+
1157+
* `event` {Object} containing the following properties
1158+
* `id` - Argument passed to `require()`. Module name.
1159+
* `parentFilename` - Name of the module that attempted to require(id).
1160+
1161+
Emitted when `require()` is executed. See [`start` event][].
1162+
1163+
`module.require.end`
1164+
1165+
* `event` {Object} containing the following properties
1166+
* `id` - Argument passed to `require()`. Module name.
1167+
* `parentFilename` - Name of the module that attempted to require(id).
1168+
1169+
Emitted when a `require()` call returns. See [`end` event][].
1170+
1171+
`module.require.error`
1172+
1173+
* `event` {Object} containing the following properties
1174+
* `id` - Argument passed to `require()`. Module name.
1175+
* `parentFilename` - Name of the module that attempted to require(id).
1176+
* `error` {Error}
1177+
1178+
Emitted when a `require()` throws an error. See [`error` event][].
1179+
1180+
`module.import.asyncStart`
1181+
1182+
* `event` {Object} containing the following properties
1183+
* `id` - Argument passed to `import()`. Module name.
1184+
* `parentURL` - URL object of the module that attempted to import(id).
1185+
1186+
Emitted when `import()` is invoked. See [`asyncStart` event][].
1187+
1188+
`module.import.asyncEnd`
1189+
1190+
* `event` {Object} containing the following properties
1191+
* `id` - Argument passed to `import()`. Module name.
1192+
* `parentURL` - URL object of the module that attempted to import(id).
1193+
1194+
Emitted when `import()` has completed. See [`asyncEnd` event][].
1195+
1196+
`module.import.error`
1197+
1198+
* `event` {Object} containing the following properties
1199+
* `id` - Argument passed to `import()`. Module name.
1200+
* `parentURL` - URL object of the module that attempted to import(id).
1201+
* `error` {Error}
1202+
1203+
Emitted when a `import()` throws an error. See [`error` event][].
1204+
11531205
#### NET
11541206

11551207
`net.client.socket`

‎lib/diagnostics_channel.js

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

277277
class TracingChannel {
278278
constructor(nameOrChannels) {
279-
for (const eventName of traceEvents) {
279+
for (let i = 0; i < traceEvents.length; ++i) {
280+
const eventName = traceEvents[i];
280281
ObjectDefineProperty(this, eventName, {
281282
__proto__: null,
282283
value: tracingChannelFrom(nameOrChannels, eventName),
@@ -285,15 +286,16 @@ class TracingChannel {
285286
}
286287

287288
get hasSubscribers() {
288-
return this.start.hasSubscribers ||
289-
this.end.hasSubscribers ||
290-
this.asyncStart.hasSubscribers ||
291-
this.asyncEnd.hasSubscribers ||
292-
this.error.hasSubscribers;
289+
return this.start?.hasSubscribers ||
290+
this.end?.hasSubscribers ||
291+
this.asyncStart?.hasSubscribers ||
292+
this.asyncEnd?.hasSubscribers ||
293+
this.error?.hasSubscribers;
293294
}
294295

295296
subscribe(handlers) {
296-
for (const name of traceEvents) {
297+
for (let i = 0; i < traceEvents.length; ++i) {
298+
const name = traceEvents[i];
297299
if (!handlers[name]) continue;
298300

299301
this[name]?.subscribe(handlers[name]);
@@ -303,7 +305,8 @@ class TracingChannel {
303305
unsubscribe(handlers) {
304306
let done = true;
305307

306-
for (const name of traceEvents) {
308+
for (let i = 0; i < traceEvents.length; ++i) {
309+
const name = traceEvents[i];
307310
if (!handlers[name]) continue;
308311

309312
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
@@ -198,6 +198,9 @@ let { startTimer, endTimer } = debugWithTimer('module_timer', (start, end) => {
198198
endTimer = end;
199199
});
200200

201+
const { tracingChannel } = require('diagnostics_channel');
202+
const onRequire = getLazy(() => tracingChannel('module.require'));
203+
201204
const isWindows = process.platform === 'win32';
202205

203206
const relativeResolveCache = { __proto__: null };
@@ -237,7 +240,11 @@ function wrapModuleLoad(request, parent, isMain) {
237240
startTimer(logLabel, traceLabel);
238241

239242
try {
240-
return Module._load(request, parent, isMain);
243+
return onRequire().traceSync(Module._load, {
244+
__proto__: null,
245+
parentFilename: parent?.filename,
246+
id: request,
247+
}, Module, request, parent, isMain);
241248
} finally {
242249
endTimer(logLabel, traceLabel);
243250
}

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

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

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

217227
return {
218228
__proto__: null,
@@ -470,9 +480,15 @@ class ModuleLoader {
470480
* @returns {Promise<ModuleExports>}
471481
*/
472482
async import(specifier, parentURL, importAttributes) {
473-
const moduleJob = await this.getModuleJob(specifier, parentURL, importAttributes);
474-
const { module } = await moduleJob.run();
475-
return module.getNamespace();
483+
return onImport.tracePromise(async () => {
484+
const moduleJob = await this.getModuleJob(specifier, parentURL, importAttributes);
485+
const { module } = await moduleJob.run();
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)