- [x] bug report
- [x ] serve --sourceMap=false
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
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
or ng s --sourceMap=false
same refresh cli server around 10seconds while it was around 2-3s before.
https://gist.github.com/istiti/9da2393a26aeb0117932e56bb04edd9a
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
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 main.scss
file which contains about 50 imports. Its really nothing fancy, very basic sass + custom material design theme.
It takes 5+ minutes for build to go through this file using this configuration (angular.json):
"configurations": {
"production": {
"optimization": true,
"sourceMap": false,
"aot": true,
"vendorChunk": false
}
}
However, after disabling aot
it went through in just a couple of seconds.
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 @angular
libraries at 6.1.9 but keep the CLI at 7?
Also, can you provide the output of ng --version
? Before and After? Thank you.
@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:
@angular-devkit/architect 0.8.3
@angular-devkit/build-angular 0.8.3
@angular-devkit/build-optimizer 0.8.3
@angular-devkit/build-webpack 0.8.3
@angular-devkit/core 0.8.3
@angular-devkit/schematics 7.0.0-rc.1 (cli-only)
@angular/cdk 7.0.0-beta.2
@angular/cli 7.0.0-rc.1
@angular/flex-layout 6.0.0-beta.18
@angular/material 7.0.0-beta.2
@angular/material-moment-adapter 7.0.0-beta.2
@ngtools/webpack 6.2.3
@schematics/angular 7.0.0-rc.1 (cli-only)
@schematics/update 0.9.0-rc.1 (cli-only)
rxjs 6.3.3
typescript 3.1.1
webpack 4.19.1
Build that takes around 20 seconds (more than just disabling aot, but I guess thats fine)
@angular-devkit/architect 0.8.3
@angular-devkit/build-angular 0.8.3
@angular-devkit/build-optimizer 0.8.3
@angular-devkit/build-webpack 0.8.3
@angular-devkit/core 0.8.3
@angular-devkit/schematics 7.0.0-rc.1
@angular/cdk 7.0.0-beta.2
@angular/cli 7.0.0-rc.1
@angular/compiler-cli 6.1.9
@angular/flex-layout 6.0.0-beta.16
@angular/material 7.0.0-beta.2
@angular/material-moment-adapter 7.0.0-beta.2
@ngtools/webpack 6.2.3
@schematics/angular 7.0.0-rc.1
@schematics/update 0.9.0-rc.1
rxjs 6.3.3
typescript 2.7.2
webpack 4.19.1
What changed is the @angular/compiler-cli
and typescript
because the compiler requires lower version.
@Enngage Can you try both with AOT enabled?
Also it looks like you are using a mix of CLI 7 and 6. The @angular-devkit/build-angular
package should be at 0.9.0-rc.1
.
For updating an existing CLI project from 6 to 7, you can use ng update @angular/cli --next
/ng update @angular/core --next
.
@clydin , yeah, I tried the 0.9.0-rc.1
, but the build failed due to some 3rd party library not having a proper format so I had to rollback to 0.8.3
.
Anyway I just tried it with the 0.9.0-rc.1
again and experience same result - it takes about 5 minutes to go through sass files, but then it fails due to the 3rd party lib so I don't think its related.
Ok. If you are using 0.8.3
then you are essentially using the build system from CLI 6 which means the only large difference appears to be the AOT compiler itself (@angular/compiler-cli
).
@istiti 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
?
I could reproduce with https://github.com/angular/angular/tree/master/aio.
Using @angular-devkit/[email protected]
I saw non-AOT ng serve
rebuilds of ~300ms.
With @angular-devkit/[email protected]
rebuilds were ~6000ms. Most of the time seemed to be spent at 0% progress.
@Enngage what OS are you on btw?
@filipesilva tried this on 2 separate Win 10
devices
#
@cydin : Also, can you provide the output of ng --version? Before and After? Thank you
Here you can check my package.json and ng --version when everything is okay (cli v6.2.4) before update cli to --next
Angular CLI: 6.2.4
Node: 10.9.0
OS: win32 x64
Angular: 6.1.9
... common, compiler, compiler-cli, core, forms, http
... language-service, platform-browser, platform-browser-dynamic
... router
Package Version
-----------------------------------------------------------
@angular-devkit/architect 0.8.4
@angular-devkit/build-angular 0.8.4
@angular-devkit/build-optimizer 0.8.4
@angular-devkit/build-webpack 0.8.4
@angular-devkit/core 0.8.4
@angular-devkit/schematics 0.8.4
@angular/cdk 6.4.7
@angular/cli 6.2.4
@angular/material 6.4.7
@ngtools/webpack 6.2.4
@schematics/angular 0.8.4
@schematics/update 0.8.4
rxjs 6.3.3
typescript 2.9.2
webpack 4.20.2
@filipesilva : are the build times you showed with AOT?
Thank you to thank me for try cli7rc 😄
No it is JIT.
PS: I dream for a long time to be able to serve my project with aot ^^ if you remember aot was by default in cli1.5 then disable due to big project : see my comment followed by yours before your merge to disable again aot on large project
@filipesilva :Do you also have a lot of scss/sass files?
I don't use scss/sass only css, you can check my angular.json
@cydin For updating an existing CLI project from 6 to 7, you can use ng update @angular/cli --next
Am I missing something or this is normal behavior :
Anyway I updated cli manually by remove cli globally then install @next then install @angular-devkit/[email protected] the
@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?
I install manually cli (remove lock file, uninstall global/local cli, remove nodes_modules, install cli @next and @angular-devkit/[email protected] now my package.json and ng --version is :
So, with all this, I tried againng s --sourceMap=false
and I get again slow refresh check this GIF to real example (consider I edit file adding comment+SAVE then removing comment+SAVE) :
PS: might be useful angular.json
Please apologize me if structure of this reponse is not easy readable.
I confirm keep cli v7rc1 glboal&local and backward to @angular-devkit/[email protected]
(by the way build-webpack&build-optimizer auto moved to 0.8.4) works as expected.
To give you an update, https://github.com/angular/angular-cli/pull/12462, https://github.com/angular/angular-cli/pull/12461 and https://github.com/angular/angular-cli/pull/12483 together should bring the rebuild speeds back to what they were in CLI 6.x. They aren't released yet but should be in the next RC.
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 aio
folder of https://github.com/angular/angular.
I cloned AIO twice. In one the the clones I use the latest v6 CLI (@angular/[email protected]
+ @angular-devkit/[email protected]), and the other clone I use the upcoming v7 RC (
@angular/[email protected]+
@angular-devkit/[email protected]).
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:
"configurations": {
"debug": {
"aot": false,
"optimization": false,
"buildOptimizer": false,
"outputHashing": "none",
"sourceMap": false,
"statsJson": false,
"extractCss": false,
"extractLicenses": false,
"vendorChunk": true
},
I ran ng serve --configuration=debug
, triggered changes by adding console.log(1);
to src/main.ts
, and gathered some numbers. It's important to actually add code when triggering a rebuild because the build system will do a lot less work if the AST of the files does not change. I ignore the numbers from the first few rebuilds as well, since sometimes it's artificially inflated as caches are being populated.
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 ndb
kept crashing. I'd seen this happen in the past when there are a lot of profile events so instead tried to profile a single rebuild. I took a sample of a v6 and a v7 rebuild by following these steps:
ndb node ./node_modules/@angular/cli/bin/ng serve --configuration=debug
console.log(1);
to src/main.ts
, wait for the rebuild to finish, wait 5s to let all processes stop activityndb
, performance tab, clicked record
button on top, waited for recording to startndb
stopped the recording, then saved it to diskI shared these profiles with the team, then opened ndb
twice, side by side, and loaded the profiles I had saved. The initial view is called "Summary" and looked like this:
v6 Summary
v7 Summary
There's 3 processes listed: Main (which is from ndb
I think), the ng serve
, and the forked type checker. We run type checking in a separate process to speed up rebuilds.
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 ndb
window I switched to the "Bottom-Up" view. This tells you how much time is spent on functions. Bear in mind there is one table for each process.
ng serve
bottom-Up, v6 left, v7 right
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:
normalize
looks expensive or called excessivelyWe 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 node_modules/@angular-devkit/node_modules/
. This forced node resolution to use that copy instead of the top level one. I made sure it was being used by deleting a couple of files, which showed a bunch of RxJs errors. No real change in rebuild times, so this didn't seem the culprit.
Then I started replacing more of the @angular-devkit/*
modules src/
folder with their v6 versions to see when the rebuild times changed. The most crucial ones seemed @angular-devkit/core
(where our virtual file system is) and @ngtools/webpack
(where our webpack plugin is). This isn't a great of debugging things but in this case worked because not too much had changed.
Changing the @ngtools/webpack
source back to v6 made rebuilds fast again. The regression was somewhere in the source of this package. We only had some 15 commits to this package that were in v7 but not v6 so started looking at those.
https://github.com/angular/angular-cli/pull/12462 and https://github.com/angular/angular-cli/pull/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.
ng serve
bottom-Up, v7 left, v7-64d1524 right
The effect seemed as expected from https://github.com/angular/angular-cli/pull/12462 and https://github.com/angular/angular-cli/pull/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 SourceFile
s anymore which caused full instead of incremental TypeScript rebuilds.
He put up https://github.com/angular/angular-cli/pull/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 (https://github.com/angular/angular-cli/pull/12022) and a new --profile
flag (https://github.com/angular/angular-cli/pull/11497). But unfortunately neither of these are very useful for rebuilds right now, which is why this is still a lot of manual work.
I hope someone finds this write-up useful!
Thats really great write up! Thanks a lot for sharing this.
@Enngage I tried comparing v6 and v7 with AOT on, optimization off, with and without the AIO global scss. v7 seemed to rebuild faster at some 1.2s vs 1.5s. The initial build took around 17s.
I also tried with optimization on like you mentioned in https://github.com/angular/angular-cli/issues/12432#issuecomment-426310410 but didn't see any super long initial builds like the 5m you reported.
I know you can't share your project per se, but if you have time can you try using your scss in a new project? Maybe trying the global and component scss separately. It might help get down to the problematic files.
Worth noting that there is an older issue about style processing taking a long time: https://github.com/angular/angular/issues/20105
@istiti @Enngage can you try with @angular-devkit/[email protected]
please?
@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 :+1:
@filipesilva unfortunately with versions :
Angular CLI: 7.0.0-rc.2
Node: 10.9.0
OS: win32 x64
Angular: 6.1.9
... common, compiler, compiler-cli, core, forms, http
... language-service, platform-browser, platform-browser-dynamic
... router
Package Version
-----------------------------------------------------------
@angular-devkit/architect 0.9.0-rc.2
@angular-devkit/build-angular 0.9.0-rc.2
@angular-devkit/build-optimizer 0.9.0-rc.2
@angular-devkit/build-webpack 0.9.0-rc.2
@angular-devkit/core 7.0.0-rc.2
@angular-devkit/schematics 7.0.0-rc.2
@angular/cdk 6.4.7
@angular/cli 7.0.0-rc.2
@angular/material 6.4.7
@ngtools/webpack 7.0.0-rc.2
@schematics/angular 7.0.0-rc.2
@schematics/update 0.9.0-rc.2
rxjs 6.3.3
typescript 2.9.2
webpack 4.19.1
It is a little bit faster it was 10seconds now it is 6-7seconds : serving with or without sourcemaps.
PS:Reminder, I was able to refresh in 2-3seconds before v7rc.
Here is logs' refresh running ng serve
ok.log
Here running ng serve --sourceMaps=false
ok2.log
@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:
npm install -g ndb
ndb node ./node_modules/@angular/cli/bin/ng serve
, ignore the ndb
window but don't close itsrc/main.ts
, wait for the rebuild to finish, wait 10s to let all processes stop activityndb
window, performance tab, click record button (circle) on top left, wait for recording to startndb
stop the recording, then save it to disk using the download button (down arrow) to the right of the record buttonndb
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 ndb node ./node_modules/@angular/cli/bin/ng serve
ndb window is opened but initial build never happends
@istiti do you see the ndb
or the ng serve
process working in the task manager?
@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 ndb node ...
command works correctly!
You can check my profile here Profile-20181010T064859.json
@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!
The overview looks like this:
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 set length
, shows this:
The seal
phase in webpack is one of the final ones, when dependencies settle into their final chunks. I've seen other projects with a lot of lazy modules and know it can take a long time in the seal phase. Sometimes it also has performance issues because of that (like https://github.com/webpack/webpack/issues/6248). I know your project has a lot of lazy loaded chunks so this doesn't look very weird to me.
Next up is the from
call:
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 copy-webpack-plugin
is doing most of them. We use it for assets. I think we should look into this.
The fourth enty is a provideSync
call:
It's curious that a lot of this time is license-webpack-plugin
. Maybe it's not a very performant plugin but I don't think it needs to be. Parsing licenses is the kind of thing that only matters for production builds.
Sixth one is normalizeString
:
Here we see again that there is a lot of time spent in license-webpack-plugin
.
Seventh is has
:
This looks like more chunk processing by webpack.
Eight is stat
calls:
They seem to be split roughly half and half between copy-webpack-plugin
and typescript
.
Ninth is an anonymous call:
Again we can see license-webpack-plugin
is doing a lot of work.
The tenth and last I will look at is handler
:
I think this is related to chunk processing overall by webpack.
So right now I have two things on my mind: why is extractLicenses
enabled on your development builds, and is asset copy taking too long?
The answer to the first question is that we have a bug. extractLicenses
defaults to true
and its description reads:
Extract all licenses in a separate file, in the case of production builds only.
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 https://github.com/angular/angular-cli/pull/12546. For now, you can add "extractLicenses": false
to your build config and your rebuilds should get faster.
It's harder to answer the second question. But we can test it. Can you try removing everything in the config assets
array and tell me how that changes your rebuilds please?
@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 "extractLicenses": false
let me again refresh (jit) in 2-3seconds !!!
I have theses perfs:
Date: 2018-10-10T12:59:44.320Z - Hash: 4b194c3a7fd4fba1bf3e - Time: 5016ms
125 unchanged chunks
chunk {runtime} runtime.775c2cc9a812ffec06c3.js (runtime) 12.4 kB [entry] [rendered]
chunk {0} 0.ff20df0af6fa0ef0632e.js () 2.34 MB [rendered]
i ï½¢wdmï½£: Compiled successfully.
i ï½¢wdmï½£: Compiling...
95% emitting CopyPlugini ï½¢wdmï½£: wait until bundle finished: /assets/icons/utility-sprite/svg/symbols.svg
i ï½¢wdmï½£: wait until bundle finished: /assets/icons/standard-sprite/svg/symbols.svg
i ï½¢wdmï½£: wait until bundle finished: /assets/images/avatar2.jpg
i ï½¢wdmï½£: wait until bundle finished: /assets/images/de.png
i ï½¢wdmï½£: wait until bundle finished: /assets/images/fr.png
i ï½¢wdmï½£: wait until bundle finished: /assets/images/logo-noname.svg
Date: 2018-10-10T12:59:49.223Z - Hash: 1eda7e14a3a64f2b7c30 - Time: 2564ms
125 unchanged chunks
chunk {runtime} runtime.d21e2221884579415883.js (runtime) 12.4 kB [entry] [rendered]
chunk {0} 0.34b0c536c27636b3b270.js () 2.34 MB [rendered]
i ï½¢wdmï½£: Compiled successfully.
i ï½¢wdmï½£: Compiling...
95% emitting CopyPlugini ï½¢wdmï½£: wait until bundle finished: /assets/images/avatar2.jpg
i ï½¢wdmï½£: wait until bundle finished: /assets/images/de.png
i ï½¢wdmï½£: wait until bundle finished: /assets/images/fr.png
i ï½¢wdmï½£: wait until bundle finished: /assets/icons/utility-sprite/svg/symbols.svg
i ï½¢wdmï½£: wait until bundle finished: /assets/icons/standard-sprite/svg/symbols.svg
i ï½¢wdmï½£: wait until bundle finished: /assets/images/logo-noname.svg
Date: 2018-10-10T12:59:53.231Z - Hash: 8f34948ea63894ecfb1a - Time: 2557ms
125 unchanged chunks
chunk {runtime} runtime.af58624784e29a1e7ad4.js (runtime) 12.4 kB [entry] [rendered]
chunk {0} 0.8edccef00925130303a5.js () 2.34 MB [rendered]
i ï½¢wdmï½£: Compiled successfully.
i ï½¢wdmï½£: Compiling...
Date: 2018-10-10T12:59:56.984Z - Hash: 8e7feeae5bab62ce1887 - Time: 2607ms
125 unchanged chunks
chunk {runtime} runtime.3556f299e9814e757a00.js (runtime) 12.4 kB [entry] [rendered]
chunk {0} 0.fca2ef332af46b987252.js () 2.34 MB [rendered]
i ï½¢wdmï½£: Compiled successfully.
i ï½¢wdmï½£: Compiling...
Date: 2018-10-10T13:00:00.688Z - Hash: b974899335175da8aa56 - Time: 2007ms
125 unchanged chunks
chunk {runtime} runtime.4fa2e71be332b9c58ca4.js (runtime) 12.4 kB [entry] [rendered]
chunk {0} 0.e0926767e13a8c0cdf2e.js () 2.34 MB [rendered]
i ï½¢wdmï½£: Compiled successfully.
i ï½¢wdmï½£: Compiling...
Date: 2018-10-10T13:00:04.735Z - Hash: 0e3f97ee5ce0a89b6868 - Time: 2447ms
125 unchanged chunks
chunk {runtime} runtime.909eee2f3b0a942faf03.js (runtime) 12.4 kB [entry] [rendered]
chunk {0} 0.f3e0090bb11f4a28b32c.js () 2.34 MB [rendered]
i ï½¢wdmï½£: Compiled successfully.
i ï½¢wdmï½£: Compiling...
Date: 2018-10-10T13:00:09.208Z - Hash: fd3dfdf3cb386fdd5cb9 - Time: 2244ms
125 unchanged chunks
chunk {runtime} runtime.1b9390fc9451c5fa9eb3.js (runtime) 12.4 kB [entry] [rendered]
chunk {0} 0.8a719322c456ddd35696.js () 2.34 MB [rendered]
i ï½¢wdmï½£: Compiled successfully.
i ï½¢wdmï½£: Compiling...
Date: 2018-10-10T13:00:14.059Z - Hash: daa735a7eb497e7db6f9 - Time: 2429ms
125 unchanged chunks
chunk {runtime} runtime.98d6fdc879986afa0a9d.js (runtime) 12.4 kB [entry] [rendered]
chunk {0} 0.e4a092c8cd803f202ddc.js () 2.34 MB [rendered]
i ï½¢wdmï½£: Compiled successfully.
One time I get 2007ms
I can't believe refresh is near 2s on my project... (i dream to get this with aot:currently around 30-40s ^^)
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 main.ts
file, right? I'm asking because this rebuild was actually quite fast and I believe AOT is not used in this serve command.
@istiti glad to hear the rebuild times are back to what they should be! extractLicenses
being on was a bug on our side though, it didn't have anything to do with your configuration. We'll be looking at the assets issue in the future as well.
@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 ng build --prod --profile
with the latest RC (@angular-devkit/[email protected]
). This will create 2 json files at the root of the project. Can you send those over please?
The rc.3
should contain the fix I mentioned about licenses not being extracted by default. I think that was the last bit to restore rebuilds to parity.
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 was getting an error (call_and_retry_last allocation) when I wouldng build --prod
my project, ng serve
and ng build
worked fine.
The ng build --prod
would run forever until it threw this error.
I updated to the latest node.js and turned sourceMap: true to sourceMap: false in both tsconfig.js and angular.json.
I think that was the last bit to restore rebuilds to parity.
@filipesilva In my project the rebuild time with @ngtools/webpack
7.0.7
is 644.6 ms (avg of 5 stable), but with version 7.1.3
it is 1476.6 ms. I would say in this case this is not in parity (2.3x slowdown), do you agree? Shall I provide something to profile or is it known issue? (#13102 maybe?)
@kondi that's another (different) regression, we are looking at it in https://github.com/angular/angular-cli/issues/13102.
This issue has been automatically locked due to inactivity.
Please file a new issue if you are encountering a similar or related problem.
Read more about our automatic conversation locking policy.
_This action has been performed automatically by a bot._
Most helpful comment
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
aio
folder of https://github.com/angular/angular.I cloned AIO twice. In one the the clones I use the latest v6 CLI (
@angular/[email protected]
+@angular-devkit/[email protected]), and the other clone I use the upcoming v7 RC (
@angular/[email protected]+
@angular-devkit/[email protected]).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
ng serve --configuration=debug
, triggered changes by addingconsole.log(1);
tosrc/main.ts
, and gathered some numbers. It's important to actually add code when triggering a rebuild because the build system will do a lot less work if the AST of the files does not change. I ignore the numbers from the first few rebuilds as well, since sometimes it's artificially inflated as caches are being populated.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
ndb
kept crashing. I'd seen this happen in the past when there are a lot of profile events so instead tried to profile a single rebuild. I took a sample of a v6 and a v7 rebuild by following these steps:ndb node ./node_modules/@angular/cli/bin/ng serve --configuration=debug
console.log(1);
tosrc/main.ts
, wait for the rebuild to finish, wait 5s to let all processes stop activityndb
, performance tab, clickedrecord
button on top, waited for recording to startndb
stopped the recording, then saved it to diskI shared these profiles with the team, then opened
ndb
twice, side by side, and loaded the profiles I had saved. The initial view is called "Summary" and looked like this:v6 Summary

v7 Summary

There's 3 processes listed: Main (which is from
ndb
I think), theng serve
, and the forked type checker. We run type checking in a separate process to speed up rebuilds.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
ndb
window I switched to the "Bottom-Up" view. This tells you how much time is spent on functions. Bear in mind there is one table for each process.ng serve
bottom-Up, v6 left, v7 righttype 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:
normalize
looks expensive or called excessivelyWe 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
node_modules/@angular-devkit/node_modules/
. This forced node resolution to use that copy instead of the top level one. I made sure it was being used by deleting a couple of files, which showed a bunch of RxJs errors. No real change in rebuild times, so this didn't seem the culprit.Then I started replacing more of the
@angular-devkit/*
modulessrc/
folder with their v6 versions to see when the rebuild times changed. The most crucial ones seemed@angular-devkit/core
(where our virtual file system is) and@ngtools/webpack
(where our webpack plugin is). This isn't a great of debugging things but in this case worked because not too much had changed.Changing the
@ngtools/webpack
source back to v6 made rebuilds fast again. The regression was somewhere in the source of this package. We only had some 15 commits to this package that were in v7 but not v6 so started looking at those.https://github.com/angular/angular-cli/pull/12462 and https://github.com/angular/angular-cli/pull/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.
ng serve
bottom-Up, v7 left, v7-64d1524 rightThe effect seemed as expected from https://github.com/angular/angular-cli/pull/12462 and https://github.com/angular/angular-cli/pull/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
SourceFile
s anymore which caused full instead of incremental TypeScript rebuilds.He put up https://github.com/angular/angular-cli/pull/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 (https://github.com/angular/angular-cli/pull/12022) and a new
--profile
flag (https://github.com/angular/angular-cli/pull/11497). But unfortunately neither of these are very useful for rebuilds right now, which is why this is still a lot of manual work.I hope someone finds this write-up useful!