search

web-infra-dev / rspack

The fast Rust-based web bundler with webpack-compatible API 🦀️
https://rspack.dev
MIT License
9.71k stars 559 forks source link

[Bug]: Regression from rspack v1.0.0-alpha.5 to v1.0.0-beta.0 #7785

Open pushkargupta9807 opened 2 months ago

pushkargupta9807 commented 2 months ago

System Info

System: OS: Linux 6.5 Ubuntu 20.04.6 LTS (Focal Fossa) CPU: (32) x64 Intel(R) Xeon(R) Platinum 8370C CPU @ 2.80GHz Memory: 109.55 GB / 125.78 GB Container: Yes Shell: 5.0.17 - /bin/bash Binaries: Node: 20.11.0 - /usr/local/share/nvm/versions/node/v20.11.0/bin/node Yarn: 1.23.19 - /usr/bin/yarn npm: 10.2.4 - /usr/local/share/nvm/versions/node/v20.11.0/bin/npm Watchman: 20240317.093234.0 - /usr/local/bin/watchman Browsers: Chrome: 125.0.6422.76

Details

Hello, I am observing perf regression up to 50% when going from the rspack v1.0.0-alpha.5 to v1.0.0-beta.0 .

The application start times have gone from 40s to 50 sec and the recompile time for a typical scenario has gone up from 5.5 to 8.0 seconds.

It is surprising because as per the release notes for v1.0.0-beta.0 , there are expected perf improvements but I am observing regression. The only sigificant change I did with the new v1.0.0-beta.0 version was to absorb the breaking change with respect to the webpackDevServer5 .

Any one else experiencing any perf regression in development mode?

I had run into similar issue in the past and the cause was : https://github.com/web-infra-dev/rspack/issues/6743#issuecomment-2159753402

Thanks,

Reproduce link

No response

Reproduce Steps

start an application in serve mode with rspack v1.0.0-beta.0 make a GUI change and observe the regression in recompile times when compared with previous rspack v1.0.0-alpha.5

jerrykingxyz commented 2 months ago

@pushkargupta9807 Could you try v1.0.1? I'm not sure where the performance regression was introduced, if you find the regression still exists on v1.0.1, you could try to generate performance trace on rspack v1.0.0-alpha.5 and v1.0.1 and share it.

https://rspack.dev/contribute/development/profiling#chrome

pushkargupta9807 commented 2 months ago

@jerrykingxyz I see that on v1.0.1 as well. And I traced back the regression to the 1st beta version. Let me collect the trace and share with you tomorrow.

Thanks.

pushkargupta9807 commented 1 month ago

@jerrykingxyz

with rspack v1.0.1

image

with rspack 1.0.0-alpha.5

image

The above is for scenario where the app is serve, followed by a couple of recompiles for a file changes. In the above images you can see the regression as well.

I collected the trace files, but unfortunately these are huge files and exceeding the 25 mb limit . Both the generated files are about 5-10 GB in size. Is there a way I can reduce the file size ? I use the following environment variable to generate the trace:

RSPACK_PROFILE: TRACE=layer=chrome,

jerrykingxyz commented 1 month ago

@pushkargupta9807 You can open the trace file in https://ui.perfetto.dev/ and share the screenshots

pushkargupta9807 commented 1 month ago

@jerrykingxyz here you go, I had to install the native binary to be able to handle the huge size . i have split it to multiple images: 1) with rspack v1.0.1 :

Screenshot 2024-09-04 at 9 36 52 PM Screenshot 2024-09-04 at 9 38 52 PM Screenshot 2024-09-04 at 9 39 12 PM Screenshot 2024-09-04 at 9 39 53 PM
pushkargupta9807 commented 1 month ago

rspack rspack 1.0.0-alpha.5 :

Screenshot 2024-09-04 at 9 48 23 PM Screenshot 2024-09-04 at 9 48 36 PM Screenshot 2024-09-04 at 9 48 56 PM Screenshot 2024-09-04 at 9 49 16 PM
pushkargupta9807 commented 1 month ago

@jerrykingxyz hopefully the above screenshots help.

pushkargupta9807 commented 1 month ago

@jerrykingxyz a gentle follow up . thanks.

jerrykingxyz commented 1 month ago

It seems that SideEffectFlagPlugin takes a lot of time, I will try to optimize it. image

pushkargupta9807 commented 1 month ago

@jerrykingxyz was it a repression from the alpha release? I mean do you know if a related change introduced this ? Thanks

jerrykingxyz commented 1 month ago

@pushkargupta9807 From your trace file, it seems to have happened after the alpha version.

SyMind commented 1 month ago

@pushkargupta9807 Set stats.logging to 'verbose'. For more details, visit: Logging Options.

You can view the span log in stages or plugins as shown below. Please include this in a comment. Let's identify which stages or plugins are slow.

LOG from rspack.Compilation
<t> finish modules: 44 ms
<t> optimize dependencies: 272 ms
<t> create chunks: 241 ms
<t> optimize: 736 ms
<t> module ids: 23 ms
<t> chunk ids: 43 ms
<t> optimize code generation: 44 ms
<t> code generation: 472 ms
<t> runtime requirements.modules: 2 ms
<t> runtime requirements.chunks: 1 ms
<t> runtime requirements.entries: 3 ms
<t> runtime requirements: 11 ms
<t> hashing: hash chunks: 5 ms
<t> hashing: hash runtime chunks: 6 ms
<t> hashing: process full hash chunks: 0 ms
<t> hashing: 12 ms
<t> create module assets: 0 ms
<t> create chunk assets: 15 ms
<t> process assets: 23643 ms
<t> after process assets: 0 ms
<t> after seal: 0 ms

LOG from rspack.Compiler
<t> make hook: 1 ms
<t> make: 5642 ms
<t> finish make hook: 0 ms
<t> finish compilation: 60 ms
<t> seal compilation: 25636 ms
<t> emitAssets: 66 ms
pushkargupta9807 commented 1 month ago

@SyMind @jerrykingxyz here you go : 1) The initial cold start build when "serve" the app :

`LOG from rspack.Compilation

finish modules: 786 ms optimize dependencies: 1438 ms create chunks: 1800 ms optimize: 465 ms module ids: 96 ms chunk ids: 23 ms optimize code generation: 0 ms module code generation cache: 0.0% (0/65911) code generation: 849 ms runtime requirements.modules: 57 ms runtime requirements.chunks: 43 ms runtime requirements.entries: 22 ms runtime requirements: 129 ms hashing: hash chunks: 55 ms hashing: hash runtime chunks: 38 ms hashing: process full hash chunks: 0 ms hashing: 95 ms create module assets: 0 ms create chunk assets: 365 ms process assets: 5985 ms after process assets: 0 ms after seal: 0 ms LOG from rspack.Compiler make hook: 3 ms make: 18146 ms finish make hook: 0 ms finish compilation: 932 ms seal compilation: 11601 ms emitAssets: 4859 ms ` 2) The subsequent re-compile which also showed regression in time: ` LOG from rspack.Compilation finish modules: 745 ms optimize dependencies: 1562 ms create chunks: 19 ms optimize: 518 ms module ids: 144 ms chunk ids: 31 ms optimize code generation: 0 ms module code generation cache: 86.4% (56916/65911) code generation: 502 ms runtime requirements.modules: 61 ms runtime requirements.chunks: 38 ms runtime requirements.entries: 19 ms runtime requirements: 125 ms hashing: hash chunks: 60 ms hashing: hash runtime chunks: 41 ms hashing: process full hash chunks: 0 ms hashing: 103 ms create module assets: 0 ms create chunk assets: 276 ms process assets: 1726 ms after process assets: 0 ms after seal: 0 ms LOG from rspack.Compiler make hook: 4 ms make: 264 ms finish make hook: 0 ms finish compilation: 886 ms seal compilation: 5440 ms emitAssets: 331 ms `
pushkargupta9807 commented 1 month ago

@SyMind @jerrykingxyz a gentle follow up , thank you.

pushkargupta9807 commented 1 month ago

Hello, just wanted to follow up - hopefully we are able to diagnose the root cause for this perf regression. Its just I am blocked from upgrading in our repo the rspack version from alpha to the latest 1.0.x versions . Thanks.

pushkargupta9807 commented 1 month ago

@SyMind @jerrykingxyz wanted to follow up with you in case you have any update. We are suck at the alpha release and cannot upgrade to latest versions. Are others NOT seeing this perf regression?

markmssd commented 1 month ago

I see it too 🥲

jerrykingxyz commented 1 month ago

This regression was caused by SideEffectsFlagPlugin feature development and bug fix. It is hard to fix it by revert PR.

I have been able to reproduce this bug in a simple demo and try to optimize it, it will be fixed soon.

JSerFeng commented 1 month ago

can you set stats.logging to 'verbose' and disable tracing, and show use the result, I don't know if the result above is with tracing disabled or enabled

Because I find that tracing in SideEffectsFlagPlugin affects performance a lot

pushkargupta9807 commented 1 month ago

@JSerFeng I am sorry, do you need any inputs from me ? I did not touch the tracing setting so whatever the default value is, the above logs are from it.

I understood that @jerrykingxyz was able to repro it with a small repo - Maybe we can get some inputs from @jerrykingxyz

pushkargupta9807 commented 1 month ago

a gentle follow up, @jerrykingxyz @JSerFeng

JSerFeng commented 1 month ago

We are trying to improve the performance of SideEffectPlugin, we will give you a canary version once we've done ^_^

pushkargupta9807 commented 1 month ago

Thank you @JSerFeng !

JSerFeng commented 3 weeks ago

Try this version 1.0.9-canary-7459b2f0-20241009040036,

optimize dependencies: 1562 ms

should improve performance of this phase

markmssd commented 3 weeks ago

@JSerFeng I've tried it and it was indeed a bit faster 🚀 I think it's still slower than before though. Would be nice to have @pushkargupta9807 compare as well!

pushkargupta9807 commented 1 week ago

@JSerFeng @markmssd Unfortunately I am not seeing any significant improvements and the original regression is still observed.

"The application start times have gone from 40s to 50 sec and the recompile time for a typical scenario has gone up from 5.5 to 8.0 seconds."

FYI I am using the @rspack/core-canary@1.0.12-canary-5152cd23-20241016102625 which potentially has the fix for another worker issue which was blocking me to try the newer versions.

https://github.com/web-infra-dev/rspack/issues/8134#issuecomment-2418340786