Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Development Mode Performance Regression 14.x vs 19 #10281

Closed
knoobie opened this issue Mar 13, 2021 · 24 comments
Closed

Development Mode Performance Regression 14.x vs 19 #10281

knoobie opened this issue Mar 13, 2021 · 24 comments
Assignees
Labels
hilla Issues related to Hilla performance

Comments

@knoobie
Copy link
Contributor

knoobie commented Mar 13, 2021

Update:

Further investigation #10281 (comment)

Topic Pull Request
Service Worker Generation #10361 (20.x / 7.x) & #10384 (19.x / 6.x)
Use transpileOnly option for ts-loader #10656 (20.x / 7.x) & #10715 (19.x / 6.x)
Shipping precompiled JS #10765 (20.x / 7.x) & #10795 (19.x / 6.x)

Original Ticket:

Description of the bug / feature

Starting an application (v19) with mvn downloaded from start.vaadin.com takes a lot more time than the same application with v14. On my machine 3x slower..

Minimal reproducible example

V14 Example

Example attached: my-app(1).zip

V19 Example

Example attached: my-app(2).zip

Expected behavior

Both application have the same starting time.

Actual behavior

v14 - 7 sec webpack execution

2021-03-13 09:32:19.629  INFO 22488 --- [nio-8080-exec-1] c.v.f.s.DefaultDeploymentConfiguration   : 
Vaadin is running in DEBUG MODE.
When deploying application for production, remember to disable debug features. See more from https://vaadin.com/docs/
2021-03-13 09:32:21.440  INFO 22488 --- [nio-8080-exec-1] c.vaadin.flow.spring.SpringInstantiator  : The number of beans implementing 'I18NProvider' is 0. Cannot use Spring beans for I18N, falling back to the default behavior
2021-03-13 09:32:26.009  INFO 22488 --- [         task-2] dev-webpack                              : Started webpack-dev-server. Time: 6972ms

v19 - 21 sec webpack execution (and a lot of unrelated logging)

2021-03-13 09:33:18.310  INFO 22804 --- [onPool-worker-1] com.vaadin.flow.server.DevModeHandler    : Starting webpack-dev-server

------------------ Starting Frontend compilation. ------------------
2021-03-13 09:33:18.671  INFO 22804 --- [onPool-worker-1] com.vaadin.flow.server.DevModeHandler    : Running webpack to compile frontend resources. This may take a moment, please stand by...
[....]
[2021-03-13 09:33:39.850  INFO 22804 --- [onPool-worker-1] com.vaadin.flow.server.DevModeHandler    : Started webpack-dev-server. Time: 21539ms

Versions:

- Vaadin / Flow version: 14.x & 19.
- Java version: 8
- OS version: Ubuntu
- IDE (if applicable): Maven
@knoobie
Copy link
Contributor Author

knoobie commented Mar 18, 2021

@pleku well-meaning ping because I think this is a huge regression (300%) and results in a really bad DX

@pleku
Copy link
Contributor

pleku commented Mar 18, 2021

@knoobie this has been discussed internally but there is no conclusion yet. We're tracking the cold/warm build times internally too but this was noticed there only when the final release was done (as apparently it cannot be done reliably with prereleases). One performance test we have for webpack build is still having the same threshold of 11s (or so) since 3.0.

It was sort of ruled out already that the change should not be caused, at least entirely, by switching to use npx nor the theming features. Npx was tested to actually make things faster. And our internal regression test (that also shows build slowdown) doesn't even have the theming features in use. The PWA features were moved from Java runtime to the frontend build, so that might have some impact. But this needs further investigation..

I think it is up for @vlukashov and @mstahv to agree who starts to take a look at this and when. I don't know if this can be "fixed" or if we need to rework the whole build like we've tried to do with investigating webpack 5 module federation (didn't work for web component / polymer reasons) or Snowpack. Personally I would like to get rid off compiling things that are not changed as those are slowing down every single build we have but that might be pointless if there is a better alternative. Personally I also feel we would benefit from having dedicated team for the frontend build, but that is still just a personal opinion for now.

It has been already known that since 3.0+ the fusion introduced changes (like TS compilation that occurs with Flow Lit templates too) makes things slower vaadin/hilla#331 and the issue has some pointers what to look at, but the impact there was from 5s -> 10s.

@knoobie
Copy link
Contributor Author

knoobie commented Mar 18, 2021

@pleku thanks for your valuable feedback and insights! I try to make some more tests the next days with other versions / less features and see if I can narrow down the issue a bit.

Personally I would like to get rid off compiling things that are not changed as those are slowing down every single build we have but that might be pointless if there is a better alternative.

That would probably help a lot with recurring builds! Sadly webpack is a total Blackbox for me so I can't really help on this part..

@Artur-
Copy link
Member

Artur- commented Mar 18, 2021

I tested this using the production build as follows

for run in `seq 1 3`; do rm -rf v14 && npx @vaadin/cli init v14 && cd v14 && mvn install -Pproduction > ../v14-run-$run && cd .. ; done
for run in `seq 1 3`; do rm -rf v19 && npx @vaadin/cli init --latest v19 && cd v19 && mvn install -Pproduction > ../v19-run-$run && cd .. ; done

The result is

$ grep "Total time" v14-run-*
v14-run-1:[INFO] Total time:  01:05 min
v14-run-2:[INFO] Total time:  01:10 min
v14-run-3:[INFO] Total time:  01:05 min
$ grep "Total time" v19-run-*
v19-run-1:[INFO] Total time:  01:01 min
v19-run-2:[INFO] Total time:  59.422 s
v19-run-3:[INFO] Total time:  57.877 s

So is this related to my machine vs your machine or production vs development mode?

@knoobie
Copy link
Contributor Author

knoobie commented Mar 18, 2021

@Artur- I haven't checked the production build time because it runs on our CI server. I tested the development mode because that's what a developer is running locally most of the time.

@mstahv
Copy link
Member

mstahv commented Mar 18, 2021

Both matter, but the development mode build time is much more important.

@knoobie
Copy link
Contributor Author

knoobie commented Mar 18, 2021

@Artur- I run the production build with the following result:

v14: 16 seconds
v19: 32 seconds

Environment: Lenovo T470s with Ubuntu LTS (3 year old business laptop)

@Artur-
Copy link
Member

Artur- commented Mar 18, 2021

Tried the same on a Windows desktop Intel(R) Core(TM) i7-2600 CPU @ 3.40GHz, 3401 Mhz, 4 Core(s), 8 Logical Processor(s)

When run on an old HDD

v14-run-1:[INFO] Total time:  03:45 min
v14-run-2:[INFO] Total time:  02:54 min
v14-run-3:[INFO] Total time:  02:20 min
v19-run-1:[INFO] Total time:  01:56 min
v19-run-2:[INFO] Total time:  01:08 min
v19-run-3:[INFO] Total time:  01:08 min

when run on an SSD

v14-run-1:[INFO] Total time:  01:53 min
v14-run-2:[INFO] Total time:  01:48 min
v14-run-3:[INFO] Total time:  01:48 min
v19-run-1:[INFO] Total time:  01:46 min
v19-run-2:[INFO] Total time:  01:03 min
v19-run-3:[INFO] Total time:  01:02 min

@knoobie
Copy link
Contributor Author

knoobie commented Mar 18, 2021

@Artur- did you run production mode or development mode?

@Artur-
Copy link
Member

Artur- commented Mar 19, 2021

This was the same mvn install -Pproduction

If I run only webpack in the generated projects, then I see a difference (this time on a Mac):

for a in `seq 1 3`; do time node_modules/.bin/webpack > /dev/null ; done` 
V14
real	0m7.396s
V19
real	0m10.760s

@knoobie
Copy link
Contributor Author

knoobie commented Mar 19, 2021

Created two screen casts of my runs - both builds happened with no mvn clean before and a proper node_modules.

V14:
https://drive.google.com/file/d/149phuBeqjGyscn9w05snwlV6fSuX0vUR/view?usp=sharing

v19:
https://drive.google.com/file/d/1vJtj68IlCmxafQ2kkPhuQHzbr9sbRjcn/view?usp=sharing

@vlukashov
Copy link

vlukashov commented Mar 19, 2021

I was able to reproduce and can confirm the issue. The frontend build time in v19 has increased 3.5x - 4x compared to that in v14.5.

webpack-dev-server startup time when running a default Flow project generated from https://start.vaadin.com:

Vaadin version Win 10 Pro WSL2 MacOS 10.14
14.4.9 3.0 sec (100%) 2.5 sec (100%) 3.1 sec (100%)
16.0.4 9.4 sec (316%) 5.7 sec (228%) 7.0 sec (228%)
17.0.11 7.8 sec (265%) 5.7 sec (227%) 6.9 sec (226%)
18.0.7 8.5 sec (288%) 6.1 sec (245%) 7.5 sec (243%)
19.0.0 12.3 sec (416%) 8.5 sec (340%) 11.3 sec (369%)

Projects: v14.zip, v16.zip, v17.zip, v18.zip, v19.zip.

Why it was not detected by an automatic regression test nor noticed by one of Vaadin developers is another question, but let's focus at fixing the build time regression here. I could speculate, without having done a proper research, that the time increase could be due to (i) adding TypeScript compilation in V15 and (ii) adding Service Worker generation in V19. These are assumptions which need validation.

In Flow apps both TypeScript and Service Worker support bring little value, and the build time increase would be hard to justify if it is indeed due to adding these 2 features.

@vlukashov vlukashov added the hilla Issues related to Hilla label Mar 22, 2021
@haijian-vaadin
Copy link
Contributor

Did some preliminary experiments, found that the client-side bootstrapping and service worker has a significant impact on the performance, the impact of theme is not that significant.

On my Mac Laptop:

  • The attached v19 app takes 9.1s to build the frontend
  • The time drops to 6.6s by removing the service worker plugin alone
  • The time drops to 4.2s by removing the client-side bootstrapping (setting useClientSideIndexFileForBootstrapping to false in webpack.generated.js file)
  • The time drops only about 0.5s by removing theme related code in the webpack.generated.js file

@haijian-vaadin
Copy link
Contributor

Next step is make a 2 day time-boxed research to identify the root causes and possible solutions.

@platosha platosha self-assigned this Mar 31, 2021
@platosha
Copy link
Contributor

platosha commented Apr 6, 2021

I researched for the performance improvement ideas using the https://github.com/stephencookdev/speed-measure-webpack-plugin when running node node_modules/webpack/bin/webpack.js --mode=development.

The starting numbers

 SMP  ⏱  
General output time took 8.43 secs

 SMP  ⏱  Plugins
InjectManifest took 6.38 secs
CompressionPlugin took 0.384 secs
StatsPlugin took 0.136 secs
WebpackManifestPlugin took 0.134 secs
HtmlWebpackPlugin took 0.006 secs
ApplicationThemePlugin took 0.005 secs

 SMP  ⏱  Loaders
ts-loader took 4.9 secs
  module count = 7
modules with no loaders took 3.4 secs
  module count = 694
lit-css-loader, and 
extract-loader, and 
css-loader, and 
@vaadin/theme-loader took 0.451 secs
  module count = 4
html-webpack-plugin took 0.015 secs
  module count = 1

Improvements

Recommend: using {transpileOnly: true} option for ts-loader

Gives the best gain by far from the rest. In combination with fork-ts-checker-webpack-plugin for error checking:

Before:

InjectManifest took 6.38 secs
...
ts-loader took 4.9 secs
  module count = 7

After:

InjectManifest took 2.29 secs
ForkTsCheckerWebpackPlugin took 0.004 secs
...
ts-loader took 0.601 secs
  module count = 7

Note: InjectManifest plugin time also decreases.

Recommend: removing flow-frontend/**.ts from TypeScript compilation

We currently ship both source + compiled .js + .d.ts files in target/flow-frontend modules, and the *.ts sources are actually picked up for compilation because we have resolve: { extensions: ['.ts', '.js'] } set in the generated webpack config. I tried simply swapping for ['.js', '.ts']. This brings TypeScript module count down and improves ts-loader time even more.

Before:

ts-loader took 0.601 secs
  module count = 7

After:

ts-loader took 0.183 secs
  module count = 3

The .ts-first extensions configuration is the one recommended in webpack docs, however. We should consider removing the source .ts files from the target/flow-frontend as a way of doing this optimisation.

Maybe: removing resolve.modules entries

Webpack docs recommend keeping those at minimum. We currently have

  resolve: {
    modules: [
      'node_modules',
      flowFrontendFolder,
      ...projectStaticAssetsFolders,
    ],
   }

Removing the latter two was relatively easy in V20 Flow project from the starter for me. The flowFrontendFolder entry was only necessary for the generated theme files, where we could replace it with the existing Frontend/ directory alias, and the ...projectStaticAssetsFolders was never used.

The impact of this is harder to measure with together other improvements applied, does not yield much to my eye. However, with default ts-loader setup, this seems to reduce total time for ~10%:

Before:

General output time took 8.43 secs

After:

General output time took 7.61 secs

Maybe: skipping InjectManifest plugin

In V20, the frontend build generates the service worker, whereas in V14 the service worker is served from Java runtime. Let us see how much it costs for frontend build time, and try skipping InjectManifest plugin:

Before:

General output time took 8.43 secs
...
ts-loader took 4.9 secs
  module count = 7
modules with no loaders took 3.4 secs
  module count = 694

After:

General output time took 6.36 secs
...
ts-loader took 3.3 secs
  module count = 6
modules with no loaders took 3.21 secs
  module count = 602

Again these numbers are taken without ts-loader improvements applied. With transpileOnly: true option for ts-loader, the impact was hardly noticeable for me.

@knoobie
Copy link
Contributor Author

knoobie commented Apr 7, 2021

Some findings from my testing after the chore: skip service worker plugin for non PWAs. (#10384)

Version Time
v19.0.0 21539ms
v19.0.3 17526ms (- ~20%)

After adding <vaadin.useDeprecatedV14Bootstrapping>true</vaadin.useDeprecatedV14Bootstrapping> it drops to 9853ms (- ~60%) but the styling isn't properly applied anymore.

deprecatedV14Bootstrapping:
image
normal starting:
image

@Haprog
Copy link
Contributor

Haprog commented Apr 26, 2021

The webpack dev build performance was improved by these two PRs:

@mstahv
Copy link
Member

mstahv commented Apr 26, 2021

@Haprog Do did you run the tests like @vlukashov did above? Would be nice to see what level of improvements we got and how the situation is now compared to V14.

@Haprog
Copy link
Contributor

Haprog commented Apr 26, 2021

@mstahv I ran tests similar to @platosha above basically running a development mode build of webpack only (trying to simulate what webpack does when you run the app with mvn, though it's not exactly the same as maven runs webpack dev server).

Here's a spreadsheet (with some interesting bits highlighted) where I recorded some of the numbers when I was testing these changes on my work laptop running on Linux.

For V14 tests I had to do some minor manual fix in webpack config to prevent it from doing transpilation that doesn't normally happen in development mode (since giving dev mode flag to webpack wasn't enough for that).

When manually running mvn I had similar results as @vlukashov on WSL2 (before the fixes) though on my Linux it was slightly faster iirc. I think around 8s to start the app before fixes, around 5.5s after #10656 and around 5.2s after both #10656 and #10765). These times are from console line like i 「wdm」: Compiling.2021-04-26 12:02:14.952 INFO 1189587 --- [nPool-worker-19] com.vaadin.flow.server.DevModeHandler : Started webpack-dev-server. Time: 5186ms

All tests ran several times and ignored 1 or 2 first runs which where slower (so assuming populated node_modules etc).

@Haprog
Copy link
Contributor

Haprog commented Apr 26, 2021

Webpack dev mode build on master still takes around 74% more time (on my laptop) compared to what it takes on V14.6 (it was 277% more before the fixes). Webpack part of the build probably can't be optimized much more (without removing features) unless we move away from webpack and implement the same features using some other frontend tooling (e.g. esbuild) if possible (and probably requiring a large effort).

Frontend build time increase alone doesn't explain all of the build time perf regression though. I just did some builds with V14.6 beta and V19 (using local Flow 6 snapshot with the fixes) and noticed that even ignoring the time that webpack dev build takes, the rest of the project startup has also slowed (from 1.1s to 2.5s):

  • V14.6
    • project startup 2.6s ("Started webpack-dev-server. Time: {}ms")
    • webpack dev build 1.5s
    • everything outside webpack 1.1s
  • V19 (using custom Flow 6 snapshot with the above fixes)
    • project startup 5.3s ("Started webpack-dev-server. Time: {}ms")
    • webpack dev build 2.8s
    • everything outside webpack 2.5s

I'm not sure if somebody has tried to look into what other parts in the maven build have become slower. I've been mainly looking at the frontend build.

EDIT: I just realized that the "Started webpack-dev-server. Time: {}ms" actually only measures time from the start of webpack-dev-server (which makes sense) so the difference here is probably just due to method of benchmarking/timing because running webpack dev build is not exactly the same as running webpack-dev-server. So it's probably still just the frontend build that has become slower but explicitly running webpack dev build is faster compared to running the actual webpack-dev-server. Might make sense to try to investigate is there some way to better debug how long webpack-dev-server is doing specific tasks (if possible) and compare that between V14 and V19+.

@Haprog
Copy link
Contributor

Haprog commented Apr 26, 2021

Also did some comparison using vaadin.enableDevServer=false looking at the console line

2021-04-26 13:43:24.875  INFO 1218018 --- [  restartedMain] com.example.application.Application      :
   Started Application in 1.047 seconds (JVM running for 1.326)

comparing between V14.6 and V19 this time seems to be only about 0.1s slower on V19 so it indeed seems that the dev server (probably just webpack-dev-server?) startup time is the main cause of performance regression. I wonder if webpack-dev-server configuration (part of webpack config) has some options that might help the performance more.

@haijian-vaadin
Copy link
Contributor

@knoobie there was another fix for this performance ticket which I updated the description of the ticket. That one actually has a more significant impact on the frontend build time.
Wonder if you can help to verify if (how much) the frontend build time has been reduced for you with Vaadin 19.0.6?

@knoobie
Copy link
Contributor Author

knoobie commented Apr 26, 2021

@haijian-vaadin Thanks! Haven't noticed the other PR. Looks like my laptop got a little bit faster (20 vs 13 sec) with nothing else open, but still way behind v14 for me.

Same applications as last time, just changed the pom version to 14.5.3 and 19.0.6:

V14.4.9
2021-04-26 14:19:04.746 INFO 13669 --- [ task-2] dev-webpack : Started webpack-dev-server. Time: 5934ms
2021-04-26 14:19:33.087 INFO 13880 --- [ task-2] dev-webpack : Started webpack-dev-server. Time: 4865ms
2021-04-26 14:19:58.715 INFO 14089 --- [ task-2] dev-webpack : Started webpack-dev-server. Time: 4958ms

V14.5.3
2021-04-26 14:26:49.007 INFO 14755 --- [ task-2] dev-webpack : Started webpack-dev-server. Time: 5386ms
2021-04-26 14:27:15.730 INFO 14972 --- [ task-2] dev-webpack : Started webpack-dev-server. Time: 5252ms
2021-04-26 14:27:38.519 INFO 15180 --- [ task-2] dev-webpack : Started webpack-dev-server. Time: 5085ms

v19.0.3
2021-04-26 14:12:21.345 INFO 11717 --- [onPool-worker-5] com.vaadin.flow.server.DevModeHandler : Started webpack-dev-server. Time: 14928ms
2021-04-26 14:13:00.762 INFO 11988 --- [onPool-worker-3] com.vaadin.flow.server.DevModeHandler : Started webpack-dev-server. Time: 13966ms
2021-04-26 14:13:47.400 INFO 12217 --- [onPool-worker-3] com.vaadin.flow.server.DevModeHandler : Started webpack-dev-server. Time: 13799ms

v19.0.6
2021-04-26 14:16:30.634 INFO 12882 --- [onPool-worker-3] com.vaadin.flow.server.DevModeHandler : Started webpack-dev-server. Time: 11803ms
2021-04-26 14:17:24.555 INFO 13169 --- [onPool-worker-3] com.vaadin.flow.server.DevModeHandler : Started webpack-dev-server. Time: 10705ms
2021-04-26 14:18:01.193 INFO 13390 --- [onPool-worker-3] com.vaadin.flow.server.DevModeHandler : Started webpack-dev-server. Time: 11021ms

@haijian-vaadin
Copy link
Contributor

@knoobie thanks for sharing, good to see that it helps with the performance, we may need to do another round of performance tuning since the difference is still significant compare with v14.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
hilla Issues related to Hilla performance
Projects
None yet
Development

No branches or pull requests

9 participants