module: print amount of load time of a module#52213
module: print amount of load time of a module#52213nodejs-github-bot merged 29 commits intonodejs:mainfrom
Conversation
|
Review requested:
|
|
Could this perhaps get its own label in |
82249f3 to
838237a
Compare
|
@GeoffreyBooth I changed to I didn't found any good alternative for this name, so I'm open to change this to another one if needed. |
|
Conceptually this feels more like something for trace_events than NODE_DEBUG? |
b80bab3 to
ac6e394
Compare
|
@richardlau Maybe I'm not familiar with trace_events but from what I see in the source code, I think it won't be as useful as having it as The benefits of emitting these events through |
|
|
|
Actually |
|
@joyeecheung I changed the implementation to match what we discussed, I liked this new way, it will print in the I still have some tests to fix but in general the implementation is good enough to get some reviews. |
|
I fixed the tests and I also changed a little bit the visualization for |
RafaelGSS
left a comment
There was a problem hiding this comment.
Can you update the PR to include only the changes this PR is about? I can see some linting and type changes.
Notable changes: buffer: * (SEMVER-MINOR) add .bytes() method to Blob (Matthew Aitken) #53221 cli: * (SEMVER-MINOR) add `NODE_RUN_PACKAGE_JSON_PATH` env (Yagiz Nizipli) #53058 * (SEMVER-MINOR) add `NODE_RUN_SCRIPT_NAME` env to `node --run` (Yagiz Nizipli) #53032 doc: * (SEMVER-MINOR) add context.assert docs (Colin Ihrig) #53169 * (SEMVER-MINOR) improve explanation about built-in modules (Joyee Cheung) #52762 * add StefanStojanovic to collaborators (StefanStojanovic) #53118 * add Marco Ippolito to TSC (Rafael Gonzaga) #53008 fs: * mark recursive cp methods as stable (Théo LUDWIG) #53127 lib: * (SEMVER-MINOR) add EventSource Client (Aras Abbasi) #51575 * (SEMVER-MINOR) replace MessageEvent with undici's (Matthew Aitken) #52370 module: * (SEMVER-MINOR) print amount of load time of a cjs module (Vinicius Lourenço) #52213 net: * (SEMVER-MINOR) add new net.server.listen tracing channel (Paolo Insogna) #53136 process: * (SEMVER-MINOR) add process.getBuiltinModule(id) (Joyee Cheung) #52762 src: * (SEMVER-MINOR) traverse parent folders while running `--run` (Yagiz Nizipli) #53154 src,permission: * (SEMVER-MINOR) --allow-wasi & prevent WASI exec (Rafael Gonzaga) #53124 test_runner: * (SEMVER-MINOR) add snapshot testing (Colin Ihrig) #53169 * (SEMVER-MINOR) add context.fullName (Colin Ihrig) #53169 * (SEMVER-MINOR) support module mocking (Colin Ihrig) #52848 PR-URL: #53379
Notable changes: buffer: * (SEMVER-MINOR) add .bytes() method to Blob (Matthew Aitken) #53221 cli: * (SEMVER-MINOR) add `NODE_RUN_PACKAGE_JSON_PATH` env (Yagiz Nizipli) #53058 * (SEMVER-MINOR) add `NODE_RUN_SCRIPT_NAME` env to `node --run` (Yagiz Nizipli) #53032 doc: * (SEMVER-MINOR) add context.assert docs (Colin Ihrig) #53169 * (SEMVER-MINOR) improve explanation about built-in modules (Joyee Cheung) #52762 * add StefanStojanovic to collaborators (StefanStojanovic) #53118 * add Marco Ippolito to TSC (Rafael Gonzaga) #53008 fs: * mark recursive cp methods as stable (Théo LUDWIG) #53127 lib: * (SEMVER-MINOR) add EventSource Client (Aras Abbasi) #51575 * (SEMVER-MINOR) replace MessageEvent with undici's (Matthew Aitken) #52370 module: * (SEMVER-MINOR) print amount of load time of a cjs module (Vinicius Lourenço) #52213 net: * (SEMVER-MINOR) add new net.server.listen tracing channel (Paolo Insogna) #53136 process: * (SEMVER-MINOR) add process.getBuiltinModule(id) (Joyee Cheung) #52762 src: * (SEMVER-MINOR) traverse parent folders while running `--run` (Yagiz Nizipli) #53154 src,permission: * (SEMVER-MINOR) --allow-wasi & prevent WASI exec (Rafael Gonzaga) #53124 test_runner: * (SEMVER-MINOR) add snapshot testing (Colin Ihrig) #53169 * (SEMVER-MINOR) add context.fullName (Colin Ihrig) #53169 * (SEMVER-MINOR) support module mocking (Colin Ihrig) #52848 PR-URL: #53379
PR-URL: nodejs#52213 Reviewed-By: Joyee Cheung <joyeec9h3@gmail.com> Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Matteo Collina <matteo.collina@gmail.com>
Notable changes: buffer: * (SEMVER-MINOR) add .bytes() method to Blob (Matthew Aitken) nodejs#53221 cli: * (SEMVER-MINOR) add `NODE_RUN_PACKAGE_JSON_PATH` env (Yagiz Nizipli) nodejs#53058 * (SEMVER-MINOR) add `NODE_RUN_SCRIPT_NAME` env to `node --run` (Yagiz Nizipli) nodejs#53032 doc: * (SEMVER-MINOR) add context.assert docs (Colin Ihrig) nodejs#53169 * (SEMVER-MINOR) improve explanation about built-in modules (Joyee Cheung) nodejs#52762 * add StefanStojanovic to collaborators (StefanStojanovic) nodejs#53118 * add Marco Ippolito to TSC (Rafael Gonzaga) nodejs#53008 fs: * mark recursive cp methods as stable (Théo LUDWIG) nodejs#53127 lib: * (SEMVER-MINOR) add EventSource Client (Aras Abbasi) nodejs#51575 * (SEMVER-MINOR) replace MessageEvent with undici's (Matthew Aitken) nodejs#52370 module: * (SEMVER-MINOR) print amount of load time of a cjs module (Vinicius Lourenço) nodejs#52213 net: * (SEMVER-MINOR) add new net.server.listen tracing channel (Paolo Insogna) nodejs#53136 process: * (SEMVER-MINOR) add process.getBuiltinModule(id) (Joyee Cheung) nodejs#52762 src: * (SEMVER-MINOR) traverse parent folders while running `--run` (Yagiz Nizipli) nodejs#53154 src,permission: * (SEMVER-MINOR) --allow-wasi & prevent WASI exec (Rafael Gonzaga) nodejs#53124 test_runner: * (SEMVER-MINOR) add snapshot testing (Colin Ihrig) nodejs#53169 * (SEMVER-MINOR) add context.fullName (Colin Ihrig) nodejs#53169 * (SEMVER-MINOR) support module mocking (Colin Ihrig) nodejs#52848 PR-URL: nodejs#53379
PR-URL: nodejs#52213 Reviewed-By: Joyee Cheung <joyeec9h3@gmail.com> Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Matteo Collina <matteo.collina@gmail.com>
Notable changes: buffer: * (SEMVER-MINOR) add .bytes() method to Blob (Matthew Aitken) nodejs#53221 cli: * (SEMVER-MINOR) add `NODE_RUN_PACKAGE_JSON_PATH` env (Yagiz Nizipli) nodejs#53058 * (SEMVER-MINOR) add `NODE_RUN_SCRIPT_NAME` env to `node --run` (Yagiz Nizipli) nodejs#53032 doc: * (SEMVER-MINOR) add context.assert docs (Colin Ihrig) nodejs#53169 * (SEMVER-MINOR) improve explanation about built-in modules (Joyee Cheung) nodejs#52762 * add StefanStojanovic to collaborators (StefanStojanovic) nodejs#53118 * add Marco Ippolito to TSC (Rafael Gonzaga) nodejs#53008 fs: * mark recursive cp methods as stable (Théo LUDWIG) nodejs#53127 lib: * (SEMVER-MINOR) add EventSource Client (Aras Abbasi) nodejs#51575 * (SEMVER-MINOR) replace MessageEvent with undici's (Matthew Aitken) nodejs#52370 module: * (SEMVER-MINOR) print amount of load time of a cjs module (Vinicius Lourenço) nodejs#52213 net: * (SEMVER-MINOR) add new net.server.listen tracing channel (Paolo Insogna) nodejs#53136 process: * (SEMVER-MINOR) add process.getBuiltinModule(id) (Joyee Cheung) nodejs#52762 src: * (SEMVER-MINOR) traverse parent folders while running `--run` (Yagiz Nizipli) nodejs#53154 src,permission: * (SEMVER-MINOR) --allow-wasi & prevent WASI exec (Rafael Gonzaga) nodejs#53124 test_runner: * (SEMVER-MINOR) add snapshot testing (Colin Ihrig) nodejs#53169 * (SEMVER-MINOR) add context.fullName (Colin Ihrig) nodejs#53169 * (SEMVER-MINOR) support module mocking (Colin Ihrig) nodejs#52848 PR-URL: nodejs#53379
|
@H4ad Is it possible to backport this to node 20? |
|
I don't know, usually we need someone from the release team to select this PR first to see if there is any conflict, only if we have conflicts we need a manual backport. |
* chore: bump Node.js to v22.9.0 * build: drop base64 dep in GN build nodejs/node#52856 * build,tools: make addons tests work with GN nodejs/node#50737 * fs: add fast api for InternalModuleStat nodejs/node#51344 * src: move package_json_reader cache to c++ nodejs/node#50322 * crypto: disable PKCS#1 padding for privateDecrypt nodejs-private/node-private#525 * src: move more crypto code to ncrypto nodejs/node#54320 * crypto: ensure valid point on elliptic curve in SubtleCrypto.importKey nodejs/node#50234 * src: shift more crypto impl details to ncrypto nodejs/node#54028 * src: switch crypto APIs to use Maybe<void> nodejs/node#54775 * crypto: remove DEFAULT_ENCODING nodejs/node#47182 * deps: update libuv to 1.47.0 nodejs/node#50650 * build: fix conflict gyp configs nodejs/node#53605 * lib,src: drop --experimental-network-imports nodejs/node#53822 * esm: align sync and async load implementations nodejs/node#49152 * esm: remove unnecessary toNamespacedPath calls nodejs/node#53656 * module: detect ESM syntax by trying to recompile as SourceTextModule nodejs/node#52413 * test: adapt debugger tests to V8 11.4 nodejs/node#49639 * lib: update usage of always on Atomics API nodejs/node#49639 * test: adapt test-fs-write to V8 internal changes nodejs/node#49639 * test: adapt to new V8 trusted memory spaces nodejs/node#50115 * deps: update libuv to 1.47.0 nodejs/node#50650 * src: use non-deprecated v8::Uint8Array::kMaxLength nodejs/node#50115 * src: update default V8 platform to override functions with location nodejs/node#51362 * src: add missing TryCatch nodejs/node#51362 * lib,test: handle new Iterator global nodejs/node#51362 * src: use non-deprecated version of CreateSyntheticModule nodejs/node#50115 * src: remove calls to recently deprecated V8 APIs nodejs/node#52996 * src: use new V8 API to define stream accessor nodejs/node#53084 * src: do not use deprecated V8 API nodejs/node#53084 * src: do not use soon-to-be-deprecated V8 API nodejs/node#53174 * src: migrate to new V8 interceptors API nodejs/node#52745 * src: use supported API to get stalled TLA messages nodejs/node#51362 * module: print location of unsettled top-level await in entry points nodejs/node#51999 * test: make snapshot comparison more flexible nodejs/node#54375 * test: do not set concurrency on parallelized runs nodejs/node#52177 * src: move FromNamespacedPath to path.cc nodejs/node#53540 * test: adapt to new V8 trusted memory spaces nodejs/node#50115 * build: add option to enable clang-cl on Windows nodejs/node#52870 * chore: fixup patch indices * chore: add/remove changed files * esm: drop support for import assertions nodejs/node#54890 * build: compile with C++20 support nodejs/node#52838 * deps: update nghttp2 to 1.62.1 nodejs/node#52966 * src: parse inspector profiles with simdjson nodejs/node#51783 * build: add GN build files nodejs/node#47637 * deps,lib,src: add experimental web storage nodejs/node#52435 * build: add missing BoringSSL dep * src: rewrite task runner in c++ nodejs/node#52609 * fixup! build: add GN build files * src: stop using deprecated fields of v8::FastApiCallbackOptions nodejs/node#54077 * fix: shadow variable * build: add back incorrectly removed SetAccessor patch * fixup! fixup! build: add GN build files * crypto: fix integer comparison in crypto for BoringSSL * src,lib: reducing C++ calls of esm legacy main resolve nodejs/node#48325 * src: move more crypto_dh.cc code to ncrypto nodejs/node#54459 * chore: fixup GN files for previous commit * src: move more crypto code to ncrypto nodejs/node#54320 * Fixup Perfetto ifdef guards * fix: missing electron_natives dep * fix: node_use_node_platform = false * fix: include src/node_snapshot_stub.cc in libnode * 5507047: [import-attributes] Remove support for import assertions https://chromium-review.googlesource.com/c/v8/v8/+/5507047 * fix: restore v8-sandbox.h in filenames.json * fix: re-add original-fs generation logic * fix: ngtcp2 openssl dep * test: try removing NAPI_VERSION undef * chore(deps): bump @types/node * src: move more crypto_dh.cc code to ncrypto nodejs/node#54459 * esm: remove unnecessary toNamespacedPath calls nodejs/node#53656 * buffer: fix out of range for toString nodejs/node#54553 * lib: rewrite AsyncLocalStorage without async_hooks nodejs/node#48528 * module: print amount of load time of a cjs module nodejs/node#52213 * test: skip reproducible snapshot test on 32-bit nodejs/node#53592 * fixup! src: move more crypto_dh.cc code to ncrypto * test: adjust emittedUntil return type * chore: remove redundant wpt streams patch * fixup! chore(deps): bump @types/node * fix: gn executable name on Windows * fix: build on Windows * fix: rename conflicting win32 symbols in //third_party/sqlite On Windows otherwise we get: lld-link: error: duplicate symbol: sqlite3_win32_write_debug >>> defined at .\..\..\third_party\electron_node\deps\sqlite\sqlite3.c:47987 >>> obj/third_party/electron_node/deps/sqlite/sqlite/sqlite3.obj >>> defined at obj/third_party/sqlite\chromium_sqlite3/sqlite3_shim.obj lld-link: error: duplicate symbol: sqlite3_win32_sleep >>> defined at .\..\..\third_party\electron_node\deps\sqlite\sqlite3.c:48042 >>> obj/third_party/electron_node/deps/sqlite/sqlite/sqlite3.obj >>> defined at obj/third_party/sqlite\chromium_sqlite3/sqlite3_shim.obj lld-link: error: duplicate symbol: sqlite3_win32_is_nt >>> defined at .\..\..\third_party\electron_node\deps\sqlite\sqlite3.c:48113 >>> obj/third_party/electron_node/deps/sqlite/sqlite/sqlite3.obj >>> defined at obj/third_party/sqlite\chromium_sqlite3/sqlite3_shim.obj lld-link: error: duplicate symbol: sqlite3_win32_utf8_to_unicode >>> defined at .\..\..\third_party\electron_node\deps\sqlite\sqlite3.c:48470 >>> obj/third_party/electron_node/deps/sqlite/sqlite/sqlite3.obj >>> defined at obj/third_party/sqlite\chromium_sqlite3/sqlite3_shim.obj lld-link: error: duplicate symbol: sqlite3_win32_unicode_to_utf8 >>> defined at .\..\..\third_party\electron_node\deps\sqlite\sqlite3.c:48486 >>> obj/third_party/electron_node/deps/sqlite/sqlite/sqlite3.obj >>> defined at obj/third_party/sqlite\chromium_sqlite3/sqlite3_shim.obj lld-link: error: duplicate symbol: sqlite3_win32_mbcs_to_utf8 >>> defined at .\..\..\third_party\electron_node\deps\sqlite\sqlite3.c:48502 >>> obj/third_party/electron_node/deps/sqlite/sqlite/sqlite3.obj >>> defined at obj/third_party/sqlite\chromium_sqlite3/sqlite3_shim.obj lld-link: error: duplicate symbol: sqlite3_win32_mbcs_to_utf8_v2 >>> defined at .\..\..\third_party\electron_node\deps\sqlite\sqlite3.c:48518 >>> obj/third_party/electron_node/deps/sqlite/sqlite/sqlite3.obj >>> defined at obj/third_party/sqlite\chromium_sqlite3/sqlite3_shim.obj lld-link: error: duplicate symbol: sqlite3_win32_utf8_to_mbcs >>> defined at .\..\..\third_party\electron_node\deps\sqlite\sqlite3.c:48534 >>> obj/third_party/electron_node/deps/sqlite/sqlite/sqlite3.obj >>> defined at obj/third_party/sqlite\chromium_sqlite3/sqlite3_shim.obj lld-link: error: duplicate symbol: sqlite3_win32_utf8_to_mbcs_v2 >>> defined at .\..\..\third_party\electron_node\deps\sqlite\sqlite3.c:48550 >>> obj/third_party/electron_node/deps/sqlite/sqlite/sqlite3.obj >>> defined at obj/third_party/sqlite\chromium_sqlite3/sqlite3_shim.obj * docs: remove unnecessary ts-expect-error after types bump * src: move package resolver to c++ nodejs/node#50322 * build: set ASAN detect_container_overflow=0 nodejs/node#55584 * chore: fixup rebase * test: disable failing ASAN test * win: almost fix race detecting ESRCH in uv_kill libuv/libuv#4341
PR-URL: nodejs#52213 Reviewed-By: Joyee Cheung <joyeec9h3@gmail.com> Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Matteo Collina <matteo.collina@gmail.com>
PR-URL: nodejs#52213 Reviewed-By: Joyee Cheung <joyeec9h3@gmail.com> Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Matteo Collina <matteo.collina@gmail.com>
PR-URL: nodejs#52213 Reviewed-By: Joyee Cheung <joyeec9h3@gmail.com> Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Matteo Collina <matteo.collina@gmail.com>
PR-URL: nodejs#52213 Reviewed-By: Joyee Cheung <joyeec9h3@gmail.com> Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Matteo Collina <matteo.collina@gmail.com>
PR-URL: nodejs#52213 Reviewed-By: Joyee Cheung <joyeec9h3@gmail.com> Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Matteo Collina <matteo.collina@gmail.com>
PR-URL: nodejs#52213 Reviewed-By: Joyee Cheung <joyeec9h3@gmail.com> Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Matteo Collina <matteo.collina@gmail.com>
|
Tentatively backported in #56927 - backporting this reduces the conflicts, though it seems associated with some other later commits, some included regressions, so only tentatively backporting it together with the associated commits that I found, which seemed safe enough. |
PR-URL: nodejs#52213 Reviewed-By: Joyee Cheung <joyeec9h3@gmail.com> Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Matteo Collina <matteo.collina@gmail.com>
|
Backing it out from #56927 to avoid introducing surface for regressions. |

I was investigating why
npmis slow and I started to figure out that was caused by it loading a lot of modules/js files, but I didn't know what are those modules or even how much time it took to load them.So, this implementation came to my mind, and I used with the following commands:
The log looks like this:
If we try to clean a little bit:
The output was:
In this way, is very clear what is taking a lot of time to load
npm, and I actually already opened a PR to fix one of the issues that appeared in this log (npm/cli#7314)@joyeecheung suggest to include also the support for
trace_events, so I created thedebugWithTimerto introduce support for both ways extract information, via log or via trace:This will generate a
trace-events.logfile that can be imported onchrome://tracingor Perfetto UI to generate the following graph:To be easier to read, I introduce two labels on the
debugWithTimer, the first one will be for logging viaNODE_DEBUGand the second one will be used at thetrace./cc @nodejs/performance