1.5 AOT by default performance tracking issue

[filipesilva]

Heya all,

When using Angular CLI 1.5 together with Angular 5.0.0, ng serve will default to using --aot=true. We added a new pipeline that should make AOT compilation much faster than it was with older CLI and Angular versions so we felt confident that AOT rebuild speeds should be much better.

Bigger projects can still have slow AOT rebuilds though. You can disable AOT by passing on the --no-aot (or --aot=false) flag, but if you have time I'd also like to ask for your help debugging remaining bottlenecks.

A good way to figure out how time is being spent in a rebuild is via CPU profiles. These show what functions are being called and how much time is being spent in each function.

This is how you can capture a CPU profile and share it here:

• Make sure your project is using the following dependencies:
  • At least @angular/[email protected].
  • At least @angular/[email protected], together with other @angular/* packages.
  • At least [email protected].
  • Exactly [email protected], newer versions might work but this is the latest officially supported by @angular/compiler-cli.
• Open chrome://inspect/#devices in chrome, and then click Open dedicated DevTools for Node. This will give you a window called Developer Tools - Node.js that we'll get back to in a second.
• In your package.json, add the following NPM script:
  • "debug": "node--max_old_space_size=8192 --inspect --debug-brk ./node_modules/@angular/cli/bin/ng serve"
  • This script tells node to start Angular CLI with the node debugger, and also to raise the maximum memory limit.
• Run npm run debug.
• The Open dedicated DevTools for Node window should pop up. It is stopped on the very first line of Angular CLI. Click the Resume button in the upper left corner of that window:
  
• Wait until the initial build is finalized.
• Open your apps main.ts file, add console.log(1); to the end of it and save. Do this 3 times.
  • Saving a file without code changes won't trigger trigger a real rebuild, we have to actually change code like adding a console.log.
  • The first few rebuilds can take longer than others, so we ignore them.
• Now we will capture the CPU profile of a rebuild:
  • Go back to the Open dedicated DevTools for Node window.
  • Click the right-most tab, called Profiler.
  • Click Start.
  • Add another console.log(1); to main.ts and save it.
  • Wait until the rebuild finishes.
  • Click the Stop button in the profiler tab.
  • Wait until Profile 1 shows up on the left, and then click it (opening it can take some time for big projects).
• You should see a chart. Zoom into it until you get all of it in the screen, take a screenshot and post it here.

  • If you don't see a chart, click the dropdown beneath Profiler and select Chart from there.
    

  • This is how it looks like for a new project:
    

• Right click Profile 1, click Save. Upload it somewhere and link it here.
  • I uploaded it to google drive: https://drive.google.com/open?id=0B06an8Bxmi7URXhhRzMxLWpPQmM

Then I can look at the CPU profile and see where time is being spent on your rebuild. Hopefully I can find new bottlenecks and make your builds faster.

Note: Sometimes the debugger doesn't disconnect after you quit the ng serve process. If you have to do this process more than once and get Unable to open devtools socket: address already in use when running npm run debug, open your process manager and kill any existing Node.js processes.

[elvisbegovic]

@filipesilva thanks to this I will do it right now ! cant wait 40 seconds after each changes :(

wait&see

[aitboudad]

@filipesilva it take ~8 seconds see https://drive.google.com/file/d/0B5h6RmZbETX3WUJYR0JwM3RnZnc/view?usp=sharing

[filipesilva]

@aitboudad thanks for posting your profile here! I can get some information out of it but it looks very different from others I've seen.... What node version are you using? Wondering if it's related to that.

[filipesilva]

I took a CPU profile of a rebuild from @karptonite's project in #8216 (with his permission). It looks like this:

It can be found here: https://drive.google.com/file/d/0B06an8Bxmi7UWTBOUHY4SVRWNkE/view?usp=sharing

The interpretation of that CPU profile is that the big chunks on the middle/left (the ones that say AngularCompilerProgram) are part of the AOT compiler. They seem to be taking around 13s total. The two blocks on the left are part of webpack - creating the bundles and emitting them. That is taking about 4s.

I'm going to talk to the compiler team to see if something can be done about the AngularCompilerProgram bits.

[filipesilva]

@istiti thanks for doing this. 40s is really a long time for a rebuild, can you try using ng serve --no-aot for now until we improve/fix the performance of AOT?

[elvisbegovic]

@filipesilva thanks for theses clear/easy steps but just to be more precise without error/question you should edit your message to have :
"debug": "node --max-old-space-size=8192 --inspect --debug-brk ./node_modules/@angular/cli/bin/ng serve"
to avoid JavaScript heap out of memory

and edit step "You should see a chart" because I see :

and neew change view.

And I edit 3 times main.ts writing at end :
console.log(1); -> build
then console.log(2); -> build
then console.log(3); -> build

and last one writing console.log(4);

Here's my config :

// npm v5.5.1 and [email protected]
Angular CLI: 1.5.0-rc.8
Node: 6.11.5
OS: win32 x64
Angular: 5.0.0-rc.9 animations, common, compiler, compiler-cli, core, forms http, language-service, platform-browser platform-browser-dynamic, router
@angular/cli: 1.5.0-rc.8
@angular-devkit/build-optimizer: 0.0.31
@angular-devkit/core: 0.0.20
@angular-devkit/schematics: 0.0.34
@ngtools/json-schema: 1.1.0
@ngtools/webpack: 1.8.0-rc.8
@schematics/angular: 0.0.49
typescript: 2.4.2
webpack: 3.8.1

Here's chart:

And file: https://drive.google.com/open?id=0BzKW4KaSm_QMQXpUWlpmeFh4RVk

please apologizes my ignorance, cant able to read this profile, outside of my skills :)

UPDATE: change npm version was write mistake above

[filipesilva]

@istiti thank you so much for this information, I'll edit my comment to reflect the memory flag and the view selector.

Your CPU profile looks a lot like @karptonite's one. Most of the time is spent in emitting files from AngularCompilerProgram. I'll see what I can do about that.

[elvisbegovic]

@filipesilva what does this mean, it's on angular side?? do you invite me to make some noises here angular/angular#19337

[aitboudad]

What node version are you using?

v8.6.0

[filipesilva]

@istiti not necessarily. The CLI might be using the compiler incorrectly and that results in bigger build times. So I have to investigate what's the root cause of the problem, I do not know yet.

[aitboudad]

@filipesilva downgraded my node version into v6.11.5 here is file: https://drive.google.com/file/d/0B5h6RmZbETX3NzZ2eEpMLTBHRjA/view?usp=sharing

[filipesilva]

@aitboudad ah yes, it seems it was because of the node version... now it looks like the others:

[zeniale]

@filipesilva here is my screenshot:

and my .cpuprofile
https://drive.google.com/open?id=0B5sBny2Y-icKYlBEel9MTmJRejQ

Here is my config:

npm v5.4.2 and [email protected] Angular CLI: 1.5.0-rc.8 Node: 8.6.0 OS: win32 x64 Angular: 5.0.0-rc.9 animations, common, compiler, compiler-cli, core, forms http, platform-browser platform-browser-dynamic, router @angular/cli: 1.5.0-rc.8 @angular-devkit/build-optimizer: 0.0.31 @angular-devkit/core: 0.0.20 @angular-devkit/schematics: 0.0.34 @ngtools/json-schema: 1.1.0 @ngtools/webpack: 1.8.0-rc.8 @schematics/angular: 0.0.49 typescript: 2.4.2 webpack: 3.8.1

[filipesilva]

@zeniale thanks for pitching in. Yours is a bit different from the rest... it seems that half the time is spent on rebundling. Just to confirm, do you remember which rebuild number this was? The first 2 or 3 rebuilds could do this but I wouldn't expect the ones after that.

[zeniale]

@filipesilva I followed your instructions, this is the fourth (4) rebuild

[filipesilva]

Thanks for the confirmation. Then in yours I see around 33s used in AngularCompilerProgram and 20s in webpack rebundling, for a total of a 70s rebuild. Can you tell me how long are your --no-aot rebuilds for comparison?

[intellix]

No AOT: 500-700ms
AOT: 5s

Profile: https://drive.google.com/open?id=0B-z04hg-_QmgTmloU0VNSzBZVkE

Screenshot:

Zoomed into a little bit of the smaller parts:

[karptonite]

Is everyone counting rebuilds the same way? That is, does the first "build" count as a rebuild, or is it a rebuild only when after the first change?

[filipesilva]

@karptonite following the instructions in the original post should yield a CPU profile for the fourth rebuild. Any rebuild after the second or third should be fine however.

[filipesilva]

@intellix thanks for capturing that profile. Yours seems similar to most of the ones before: your rebuild time is composed around 3/4 of AngularCompilerProgram work and 1/4 of bundling. So far the only one to deviate was @zeniale's one, that seemed to be almost half one and half the other.

[zeniale]

@filipesilva If I launch --no-aot build, I get some errors like this:

ERROR in ./node_modules/@myFramework/framework-ng2/src/index.ts
Module build failed: Error: C:\CODE\MyApp\MyApp.ng2\node_modules\@myFramework\framework-ng2\src\index.ts is not part of the compilation output. Please check the other error messages for details.
    at AngularCompilerPlugin.getCompiledFile (C:\CODE\MyApp\MyApp.ng2\node_modules\@ngtools\webpack\src\angular_compiler_plugin.js:629:23)
    at plugin.done.then (C:\CODE\MyApp\MyApp.ng2\node_modules\@ngtools\webpack\src\loader.js:467:39)
    at <anonymous>
    at process._tickCallback (internal/process/next_tick.js:188:7)
 @ ./src/app/core/myApp-shared/myApp-shared.module.ts 24:0-61
 @ ./src/app/conf/entity/entity-grid/entity-grid.module.ts
 @ ./src/$$_lazy_route_resource lazy
 @ ./node_modules/@angular/core/esm5/core.js
 @ ./src/main.ts
 @ multi webpack-dev-server/client?http://0.0.0.0:0 ./src/main.ts

This error in repeated for many modules. This seems to be this BUG (#8263) or this (#8066). This error is also present when launching ng-test

[zeniale]

@filipesilva I get the error after compilation, I generate .cpuprofile file & screenshot for --no-aot build anyway.
Here is the screenshot:

Here is .cpuprofile file:
https://drive.google.com/open?id=0B5sBny2Y-icKWFJhSGlZUTFtR0E

P.S. Can you notify me on previous error solution?

[filipesilva]

@zeniale I think the errors you're seeing are because that library (@myFramework/fromework-ng2) wasn't packaged correctly and contains .ts files. There's more information about that problem here #8263.

[elvisbegovic]

@filipesilva --no-aot is fast rebuilding, really appreciate and correct time BUT on browser loading page is very slow (4-5seconds for my case lazyloadmodules)

I really want help you here and give you more infos from my project, how can I help to investigate? IMHO on more common project angular-cli 1.5.0 can't sell and activate aot by default

[hccampos]

Besides just trying to make AoT compilation faster, which is good, of course, why not try to come up with ways to make the compilation faster by avoiding certain patterns or using certain features in a different way.

For example, in the past it has been mentioned that using barrels could hurt performance. Is that still the case? Always or only when using export * from './awesomepackage'

How about path alises, do they hurt rebuild times?

And inline templates vs separate files? Inline styles vs scss files?

And what about having some output in the console with the number of modules contained in a chunk so we can more easily work towards having chunks with less modules (just looking at file size is tricky).

[hansl]

Hi @istiti, @hccampos,

To answer your questions:

This breaking my heart

It's also breaking ours. We really pushed the limits of both compilers (webpack, ngc and tsc) to be able to set AOT by default, and we fell short on large projects.

Does this mean we need wait ABC for cli v2 to have correct rebuild aot time in big project, or hopely in near future 1.5x ?

Yes and no. We have a plan to remake the build system which will allow us to keep using webpack while also splitting your application in smaller pieces. When that's in, you should see shorter rebuild times (assuming you're following our best practices).

Do you have some advice on structure project in big project we need follow for aot?

Not yet, but this is something we're working on.

For example, in the past it has been mentioned that using barrels could hurt performance. Is that still the case? Always or only when using export * from './awesomepackage'

It is still the case, but we helped webpack improve on this and they're still improving. We now build CommonJS in development which also fixes this issue completely (we want to go back to ES2015 modules but won't until performance improves).

In this case though, the performance itself comes from generating factories. The barrel is not a factor anymore, so times reported in this issue come mostly from ngc itself.

How about path alises, do they hurt rebuild times?

No. Path aliases are done by typescript, and report times of typescript itself (which is used in JIT) is minimal. Path aliases happen in both JIT and AOT.

And inline templates vs separate files? Inline styles vs scss files?

This is where most of the time is being spent in ngc. Big templates are definitely a problem, but it's unclear without actually investigating the issue where exactly the time is spent and if it can be helped.

---

The real fix would be to have smaller applications, which will come in the new build system and ABC (when it's ready).

[bmayen]

"It's also breaking ours. We really pushed the limits of both compilers (webpack, ngc and tsc) to be able to set AOT by default, and we fell short on large projects."
Valiant effort, guys! Thanks for all the hard work, as always.

[theunreal]

Any temporary workaround?

[hansl]

@theunreal You can still use ng serve --aot, which is immensely faster than before (with ng5 and cli1.5).

[danwulff]

@hansl @filipesilva With all this discussion on making aot default, I didn't see any info about running unit tests in aot. Will that be a possibility in the future? Will ng test aot be made default like ng serve aot some day when compile time is better?

[diagramatics]

Here's one from me if it's still required. It's a pretty hefty project with a lot of work poured in it, and the profile is on Node v8.7.0 with the versions of Angular and the CLI noted above on a beefy Macbook Pro.

CPU-20171102T144702.cpuprofile.zip

[hccampos]

Here is an interesting profile from our project, which takes 128 seconds on the 3rd rebuild while debugging. Almost 2 minutes are spent in StyleCompiler._codegenStyles which means something is going very wrong there.

Note that this was using Typescript 2.5.3 instead of the suggested 2.4.x. We are also using https://github.com/mseemann/angular2-mdl which might be introducing some hard to analyze/generate styles. Or maybe we are just doing something else in our codebase which the AoT compiler doesn't like.

CPU-20171102T091339.cpuprofile.zip

[hccampos]

Since most of the time is spent on replace, I am guessing something is triggering this http://www.regular-expressions.info/catastrophic.html I will dig deeper, but maybe someone on the Angular compiler team can figure it out quicker. @hansl @filipesilva should I open an issue on the Angular repo instead?

[filipesilva]

@danwulff there's some discussion about AOT in unit tests on #8007

@diagramatics thanks for taking your CPU profile as well. I had a look at it and it looks very similar to the 'normal' time distribution: 3/4s on AOT, 1/4 on webpack. It's good to get confirmation of these samples 👍

@hccampos I pinged the compiler team about your issue.

[pleerock]

@filipesilva looks like there is a confusion between max-old-space-size and max_old_space_size. I also used max-old-space-size in debugging because I used code from your first post, you need to edit it. I made this found because of @sabeersulaiman post in #5618

[filipesilva]

@pleerock thanks for heads up, will edit it.

[elvirdolic]

Will aot be default on ng serve as promised for v6?

[elvisbegovic]

Where is it promised?! afaik it was for 1.5 but not interesting on large project. I heart for v6.x some things about it will come but still’ not default

You could take a look inside bazel from alexeagle repo or https://www.ng-conf.org/sessions/hands-full-stack-development-nx-bazel/

[elvirdolic]

Not directly promised for this release but mentioned in the angular 5 release: https://blog.angular.io/version-5-0-0-of-angular-now-available-37e414935ced Begović <[email protected]> schrieb am Mo. 16. Apr. 2018 um 21:29:

…

Where is it promised?! afaik it was for 1.5 but not interesting on large project. I heart for v6.x some things about it will come but still’ not default You could take a look inside bazel from alexeagle repo or https://www.ng-conf.org/sessions/hands-full-stack-development-nx-bazel/ — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#8259 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AQ8j8jXBobtMB-SerPJNqHra7caHbLr3ks5tpPD_gaJpZM4QMhfl> .

[elvisbegovic]

Yes, if you read in this thread this comment it was by default one moment but deactivated again because in my project by example it is completly not interesting. check my comment here.

And last news you can read this comment

[elvirdolic]

Thx I was looking for this. Begović <[email protected]> schrieb am Mo. 16. Apr. 2018 um 22:46:

…

Yes, if you read in this thread this comment <#8259 (comment)> it was by default one moment but deactivated again <filipesilva@211bc3a> because in my project by example it is completly not interesting. check my comment here <#8259 (comment)> . And last news you can read this comment <#10304 (comment)> — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#8259 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AQ8j8okegd7ixvsgFJ44A2fj09q5BQ_Pks5tpQM1gaJpZM4QMhfl> .

[angular-automatic-lock-bot]

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.}