module: print amount of load time of a module #52213
Merged
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
|
Review requested:
|
|
Could this perhaps get its own label in |
joyeecheung
reviewed
Mar 26, 2024
lemire
reviewed
Mar 26, 2024
H4ad
force-pushed
the
trace-load-module
branch
2 times, most recently
from
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? |
H4ad
force-pushed
the
trace-load-module
branch
2 times, most recently
from
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
reviewed
Mar 27, 2024
richardlau
added
the
semver-minor
|
@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. |
|
If we use the |
|
I fixed the tests and I also changed a little bit the visualization for |
joyeecheung
reviewed
Mar 30, 2024
RafaelGSS
reviewed
Apr 4, 2024
joyeecheung
reviewed
Apr 8, 2024
joyeecheung
reviewed
Apr 8, 2024
github-actions
bot
removed
the
request-ci
H4ad
added
commit-queue
nodejs-github-bot
added
commit-queue-failed
Commit Queue failed- Loading data for nodejs/node/pull/52213 ✔ Done loading data for nodejs/node/pull/52213 ----------------------------------- PR info ------------------------------------ Title module: print amount of load time of a module (#52213) ⚠ Could not retrieve the email or name of the PR author's from user's GitHub profile! Branch H4ad:trace-load-module -> nodejs:main Labels semver-minor, author ready, needs-ci, review wanted, commit-queue-squash Commits 29 - module: print amount of load time of a cjs module - try support both node_debug and trace by introducing a new module - add trace label to better visualization - fix lint issue with max line - lazy load trace_timer - fix lint issues introduce when lazy load - cleanup and added more tests - remove unecessary changes - remove unecessary changes - resolve rebase conflicts - fixing nits - resolve conflicts after rebase - fix lint issues - handle unexpected errors during _load - add wrap module load function - removed unused spaces - fixing tests on last modification - escape backslash when is label - fix references for _load - add test to check against un-escaped backslash - fix issues with test & missing fn - making eslint happy with trailing space - minor changes - fix missing changing the name of the module - try get more info from ci - try get more info from ci & make lint happy - fix import of common and spawnSync - do not cache process.execPath on import - thanks richard, you are amazing Committers 1 - Vinícius Lourenço PR-URL: https://github.com/nodejs/node/pull/52213 Reviewed-By: Joyee Cheung Reviewed-By: James M Snell Reviewed-By: Matteo Collina ------------------------------ Generated metadata ------------------------------ PR-URL: https://github.com/nodejs/node/pull/52213 Reviewed-By: Joyee Cheung Reviewed-By: James M Snell Reviewed-By: Matteo Collina -------------------------------------------------------------------------------- ⚠ Commits were pushed since the last approving review: ⚠ - module: print amount of load time of a cjs module ⚠ - try support both node_debug and trace by introducing a new module ⚠ - add trace label to better visualization ⚠ - fix lint issue with max line ⚠ - lazy load trace_timer ⚠ - fix lint issues introduce when lazy load ⚠ - cleanup and added more tests ⚠ - remove unecessary changes ⚠ - remove unecessary changes ⚠ - resolve rebase conflicts ⚠ - fixing nits ⚠ - resolve conflicts after rebase ⚠ - fix lint issues ⚠ - handle unexpected errors during _load ⚠ - add wrap module load function ⚠ - removed unused spaces ⚠ - fixing tests on last modification ⚠ - escape backslash when is label ⚠ - fix references for _load ⚠ - add test to check against un-escaped backslash ⚠ - fix issues with test & missing fn ⚠ - making eslint happy with trailing space ⚠ - minor changes ⚠ - fix missing changing the name of the module ⚠ - try get more info from ci ⚠ - try get more info from ci & make lint happy ⚠ - fix import of common and spawnSync ⚠ - do not cache process.execPath on import ⚠ - thanks richard, you are amazing ℹ This PR was created on Tue, 26 Mar 2024 01:41:52 GMT ✔ Approvals: 3 ✔ - Joyee Cheung (@joyeecheung) (TSC): https://github.com/nodejs/node/pull/52213#pullrequestreview-1997745510 ✔ - James M Snell (@jasnell) (TSC): https://github.com/nodejs/node/pull/52213#pullrequestreview-2026657587 ✔ - Matteo Collina (@mcollina) (TSC): https://github.com/nodejs/node/pull/52213#pullrequestreview-2035376215 ✔ Last GitHub CI successful ℹ Last Full PR CI on 2024-05-29T21:59:32Z: https://ci.nodejs.org/job/node-test-pull-request/59531/ - Querying data for job/node-test-pull-request/59531/ ✔ Last Jenkins CI successful -------------------------------------------------------------------------------- ✔ Aborted `git node land` session in /home/runner/work/node/node/.ncuhttps://github.com/nodejs/node/actions/runs/9294909258 |
|
@joyeecheung We are closer, just one (re)approval :) |
joyeecheung
added
commit-queue
nodejs-github-bot
removed
the
commit-queue
|
Landed in f883865 |
targos
pushed a commit
that referenced
this pull request
Jun 1, 2024
PR-URL: #52213 Reviewed-By: Joyee Cheung <joyeec9h3@gmail.com> Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Matteo Collina <matteo.collina@gmail.com>
lukins-cz
pushed a commit
to lukins-cz/OS-Aplet-node
that referenced
this pull request
Jun 1, 2024
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>
RafaelGSS
added a commit
that referenced
this pull request
Jun 7, 2024
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 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,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: TODO
RafaelGSS
added a commit
that referenced
this pull request
Jun 7, 2024
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,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
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
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