-
Notifications
You must be signed in to change notification settings - Fork 12k
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
v7.rc.0 serving 2x - 3x slower than stable versions on my projects #12432
Comments
Heya @istiti thanks for trying you the 7.0 RC! I'm going to try and repro this regression and see if I can get similar numbers to yours, then see what's causing it. |
I'm experiencing similar/same behavior. In my case the compiler gets stuck on my sass files for a really long time. Prior to this 7.rc.0 version it went through my sass in few seconds, now it takes up to 2-3 minutes. Eventually, it does work fine though. |
@Enngage do you have a reproduction I can look at? |
@filipesilva its a private project, however I did some more testing that might help. I have It takes 5+ minutes for build to go through this file using this configuration (angular.json):
However, after disabling As an additional test, I tried removing all imports from my main.scss, but it took 5 minutes again. Instead it got stuck on some material design file even though it wasn't referenced in my code. Its like it is doing some processing on files within my assets folder. So, I removed my assets folder along with all my sass files, tried again and it got stuck on some other sass file from my node_modules folder that I referenced in angular.json. Ok, so I removed all references to any and all sass/css files I have and tried again. Now it got stuck with this for about 3 minutes: At this point I'm not sure if this is related to sass or something more generic within aot itself. |
If you have some time, can you try with the Also, can you provide the output of |
@istiti are the build times you showed with AOT? Do you also have a lot of scss/sass files? |
@clydin sure. So the build that takes really long time:
Build that takes around 20 seconds (more than just disabling aot, but I guess thats fine)
What changed is the |
@Enngage Can you try both with AOT enabled? Also it looks like you are using a mix of CLI 7 and 6. The For updating an existing CLI project from 6 to 7, you can use |
@clydin , yeah, I tried the Anyway I just tried it with the |
Ok. If you are using @istiti If you also have some time, can you also try using CLI |
I could reproduce with https://github.com/angular/angular/tree/master/aio. Using With |
@Enngage what OS are you on btw? |
@filipesilva tried this on 2 separate |
@cydin : Also, can you provide the output of ng --version? Before and After? Thank you
@filipesilva : are the build times you showed with AOT?
@filipesilva :Do you also have a lot of scss/sass files?
@cydin For updating an existing CLI project from 6 to 7, you can use ng update @angular/cli --next
@cydin If you also have some time, can you also try using CLI 7.0.0-rc.1 (and @angular-devkit/[email protected]) but with the core Angular packages at 6.1.9?
Please apologize me if structure of this reponse is not easy readable. |
I confirm keep cli v7rc1 glboal&local and backward to |
I've had some questions in the past about how we debug these performance regressions, so thought I could do a write up here for anyone that's curious. The first step is always to reproduce the problem in a side by side comparison, and to get some data on it. Since the projects in this issues were not open source I tried to reproduce using Angular.io (AIO), which you can find inside the I cloned AIO twice. In one the the clones I use the latest v6 CLI ( The reports were in non-AOT builds but AIO has some custom configurations, so I added a new configuration that disabled most things to ensure I was getting data from the simplest case:
I ran With this setup I got v6 at ~300ms rebuilds and v7 at ~6000ms. This confirmed the original report: rebuilds were much slower in v7. Since I didn't really know where to start looking I tried to get a profile of where time was being spent using https://github.com/GoogleChromeLabs/ndb, which is a simplified version of what's described in https://medium.com/@paul_irish/debugging-node-js-nightlies-with-chrome-devtools-7c4a1b95ae27. I tried taking a few profiles of the initial build plus the rebuild but
I shared these profiles with the team, then opened There's 3 processes listed: Main (which is from
Remember that these numbers are for a process while being profiled: individual numbers are not representative of real world apps, but the comparison between two profiled processes is. Couldn't say much here besides that v7 took way longer. But it was interesting to see that even the type checker took way longer. Since the type checker doesn't really use any webpack internals, it was indicative that whatever was slowing things down wasn't related to webpack. At the bottom of the
type checker bottom-Up, v6 left, v7 right What we care about here is the column called "Self Time", which is the time spent on that specific function, but not the functions it calls. We assume the v6 profile as the normal one, and see what's different in the v7 one. We (the team) went over these numbers and drew some conclusions:
We use a lot of Observables and knew RxJs had been updated in our packages, so wondered if there was a performance regression there. To debug this I forced the v7 devkit packages to use the same RxJs as was in v6 by copying it over to Then I started replacing more of the Changing the #12462 and #12461 were tested and together reduced the rebuild times by some 40% (4.5s-> 2.7s). Still too big but it helped. You might notice that the 4.5s rebuild time I just mentioned was different than the 6s one that I reported at the beginning. I don't know the specific reason for the discrepancy. Likely my machine had more resources available, less things in the background, or the process just ended up on a CPU with less load. All of this is common, so comparing numbers from different debugging sessions doesn't mean much. If you want accurate numbers you need to do a before and after that's close together, which is how I got the 4.5s-> 2.7s. I took some more profiles and compared the latest changes (v7-64d1524) with the original v7.
The effect seemed as expected from #12462 and #12461: normalize calls took a lot less time and there was less file system calls in general. Now most of the time was being spent in some kind of file system error. Drilling down showed it ultimately came from TypeScript looking up files: After some time debugging, we say that it was typescript trying to resolve modules, which tries to see if files with various names exist. We discussed this for a while and saw there were some changes to how files were cached. We tried to add a cache to the Typescript module name resolution which further reduced rebuild time, but didn't leave them that close to the original. @clydin discovered that we weren't actually caching the TypeScript He put up #12483, that showed ~254ms (266, 281, 244, 246, 233) rebuilds, while v6 has ~270ms (318, 233, 248, 238, 313) rebuilds. So perhaps slightly faster even, but might also just be some noise in the data. It looks like it re-establishes parity. I'd like to say that we are looking at better automated ways to detect these performance regressions as they are introduced. We have a internal benchmarking tool (#12022) and a new I hope someone finds this write-up useful! |
Thats really great write up! Thanks a lot for sharing this. |
@filipesilva thanks for the update! Just tried it but sadly with same result. I will try to strip our code and provide some public repo where this can be reproduced as I'm not sure I would be able to debug this effectively. |
If you can get me a repro, I can look at it 👍 |
@filipesilva unfortunately with versions :
It is a little bit faster it was 10seconds now it is 6-7seconds : serving with or without sourcemaps. Here is logs' refresh running Here running |
@istiti ok that's still too slow then. Unsure what's causing it now... I think the only way to get some insight is to take a performance profile. Would you be willing to do that? To get a profile of a rebuild you can do this:
Meanwhile I'll also try to find another big project that I can try to run benchmarks on and see if I can see similar results. |
@filipesilva thank you to resume theses easy steps, but apologize me am I doing something wrongly because running |
@istiti do you see the |
@filipesilva update : running 0% |
Hm.... I suppose it could be just taking a long time. Profiling always needs more resources than when you are not profiling. Does it look like it's close to the memory limit you set (8gig)? When something is close to the memory limit it will become very slow. You can also check the "Sources" tab and see if it's stopped at a breakpoint or something. It shouldn't be, but if it is you can click the play button (solid triangle arrow right) to resume execution. |
@filipesilva it seems win10 rights problem installing ndb.. i succeed installing again ndb under admin rights CMD and |
…zing Partially address angular#12432.
@istiti I'm looking over the profile you sent me. Thanks for taking and for being so careful with the timing, it looks like you got a very good isolated sample! It seems like the main process (middle) worked from ~16.5s to ~25s (total ~8.5s seconds), while the type checker process (bottom) ran from ~17s to ~22s (total ~5s). There's also 3 things marked as function calls at 6s, 7s and 9s. I don't know what they are but they don't show up as having any kind of detailed CPU load on the profile so I am ignoring them. This makes me think whatever takes so long is not related to TypeScript, because type checking is the most costly part of the whole type scripting compilation but the type checker process runs a fraction of the total. If TypeScript was taking a very long time, the type checker process would take longer than the main process. For contrast, let's look at the AIO v6 profile from my other comment. You can see here that the type checker (bottom) took a lot longer than the main process (middle). Since the type checker seems like it is fairly normal I won't look much into it now. Going back to the main process, this is how the bottom-up view looks like: These are the functions where time is most spent. A lot of it seems like native functions at the top, so in order to know more we must drilldown by clicking the forward arrow in front of the function name. The first drilldown, for The Looks like a fair bit of time is being spent in sorting chunks. I think this is just another facet of the previous point (lots of lazy chunks). The next one are file open calls: It doesn't overly surprise me that 600ms are spent opening files in a big project but it does surprise me that The fourth enty is a It's curious that a lot of this time is Here we see again that there is a lot of time spent in This looks like more chunk processing by webpack. They seem to be split roughly half and half between Again we can see The tenth and last I will look at is I think this is related to chunk processing overall by webpack. So right now I have two things on my mind: why is The answer to the first question is that we have a bug.
But I checked in our source code and we don't actually add it only in production builds. I have a fix for that in #12546. For now, you can add It's harder to answer the second question. But we can test it. Can you try removing everything in the config @Enngage can I ask you to take a profile as well please? Analysing @istiti's one was very helpful so I wonder what I can get from yours. |
@filipesilva first of all thank you to take time and to your "step by step" answer , I confirm I have theses perfs:
One time I get ps:This is without removing anything in assets config. in contrast: I remove my assets/icons folder which have 1700k file , with extractLicesnes:FALSE I refresh in 2900 - 3200ms with these icons and after removing icons/ folder i get this score above between 2000-3000ms ps2: i can't explain why exportLicences was true in config , to be honest i find angular.json too complicated to understand. after introducing architect Thank you again to your time |
@filipesilva sure, I hope I did it right. This is the profile I got: If I understood your instructions, this rebuild is done just by saving the |
It should be false so that it doesn't affect dev builds. The default production config has it set to true already. Partially address angular#12432.
It should be false so that it doesn't affect dev builds. The default production config has it set to true already. Partially address angular#12432.
@istiti glad to hear the rebuild times are back to what they should be! |
@Enngage sorry I forgot that your problem was somewhat different. You can see the increased build times on initial builds, correct? Then you should be able to do |
It should be false so that it doesn't affect dev builds. The default production config has it set to true already. Partially address #12432.
It should be false so that it doesn't affect dev builds. The default production config has it set to true already. Partially address #12432.
The |
I agree i mark it as closed. Apologize me i didnt follow @Enngage problem, reopen it if needed |
@istiti @Enngage just wanted to say thank you again for taking the time to take the profiles and try to get to the bottom of this with us. It's really hard to find some performance regressions as sometimes they don't manifest in all projects. @Enngage if you get around to making that new profile, can you open a new issue and indicate what types of builds it happens on, and also add the details about the scss please? |
Just hopping in on this. I updated to the latest node.js and turned sourceMap: true to sourceMap: false in both tsconfig.js and angular.json. |
@filipesilva In my project the rebuild time with |
This issue has been automatically locked due to inactivity. Read more about our automatic conversation locking policy. This action has been performed automatically by a bot. |
Bug or Feature ?
Command ?
Versions ?
Angular CLI: 7.0.0-rc.1
Node: 10.9.0
OS: win32 x64
Angular: 7.0.0-rc.0
... common, compiler, compiler-cli, core, forms, http
... language-service, platform-browser, platform-browser-dynamic
... router
Package
@angular-devkit/* 0.9.0-rc.1
@angular-devkit/core 7.0.0-rc.1
@angular-devkit/schematics 7.0.0-rc.1
@angular/cdk 7.0.0-beta.2
@angular/cli 7.0.0-rc.1
@angular/material 7.0.0-beta.2
@ngtools/webpack 7.0.0-rc.1
@schematics/angular 7.0.0-rc.1
@schematics/update 0.9.0-rc.1
rxjs 6.3.3
typescript 3.1.1
webpack 4.19.1
Repro steps ?
Update from 6.2.3 to v7 rc0, it is first time to test cli v7 in my projet.
It is slower even when serving without sourcemaps.
So
ng s
orng s --sourceMap=false
same refresh cli server around 10seconds while it was around 2-3s before.Log ?
https://gist.github.com/istiti/9da2393a26aeb0117932e56bb04edd9a
Useful details ?
I can say project is big relativly to what angular/cli can support without bazel (1000+ files) and can't share project unfortunately
I just come back to stable version of cli v.6.2.4 and angular (see working package.json) and I get this score when serving https://gist.github.com/istiti/fc8b629e0a7f7cab13b41b070cbfb94b
Thanks @clydin
The text was updated successfully, but these errors were encountered: