NgccProcessor slowing down subsequent builds with AngularCompilerPlugin

[crisbeto]

I'm using the AngularCompilerPlugin for a medium-sized project and I've observed a slowdown in build times after enabling Ivy which appears to come from ngcc. When Ivy is enabled the AngularCompilerPlugin runs the NgccProcessor which is supposed to compile the node_modules for Ivy on the first run, however in my case any subsequent builds are slowed down as well.

I have a hacky way to disable the NgccProcessor which I've used to measure the differences in build times. Here's what it looks like:

class MyAngularCompilerPlugin extends AngularCompilerPlugin {
    public apply(compiler: Compiler): void {
        super.apply(compiler);
        
        compiler.hooks.environment.tap('angular-compiler', () => {
            (this as any)._compilerHost.ngccProcessor = undefined;
        });
    }
}

Here are the timings for 5 production builds on my own machine. Note that these times are after ngcc has been run once over the node_modules in a postinstall script.

// Without ngcc (80737ms on average)
84520ms
72547ms
81733ms
85043ms
79844ms
------------------------
// With ngcc (94208ms on average)
93741ms
93714ms
92922ms
97220ms
93444ms

The 15s slower build time for a production build isn't a big deal locally, however the difference becomes even larger when running it on our CI server. For our production builds we need to run about 30 Webpack builds (10 at a time in parallel), about 20 which go through the AngularCompilerPlugin. Disabling the NgccProcessor on our CI server reduced our build time from around 10 minutes to about 6 minutes. Furthermore keeping the NgccProcessor led to some flakiness in our builds, presumably because 10 different ngcc processes were trying to access file at the same time. Our build script looks something like this:

1. Run npm ci.
2. Run ngcc programmatically as follows:

const ngcc = require('@angular/compiler-cli/ngcc');
ngcc.process({
    basePath: path.join(projectRoot, 'node_modules'),
    compileAllFormats: false,
    propertiesToConsider: ['browser', 'module', 'main'],
    createNewEntryPointFormats: true
});

3. Run webpack --mode=production 30 times by splitting them into chunks of 10 that are run concurrently. We have some logic that tries to make sure that we always run the maximum number of builds, but it stays the same no matter whether ngcc is enabled so it shouldn't have an effect on the times.

I can see a couple of ways to get around this:

1. Short term: add an option to the AngularCompilerPlugin config that allows users that know what they're doing to disable the NgccProcessor.
2. Long term: rework either ngcc or NgccProcessor so that it doesn't have to spend time analyzing the node_modules after it has been run already.

cc @filipesilva

[alan-agius4]

@crisbeto, which version of @angular/compiler-cli are you using?

@petebacondarwin was your PR for improving NGCC performance merged and released?

[crisbeto]

I'm using @ngtools/webpack@^8.0.0 and @angular/compiler-cli@8.2.0-next.0. I can't use next.1, because of the issue that was fixed by angular/angular#31509.

[petebacondarwin]

@crisbeto - thanks for the report. I did a big performance refactoring of ngcc in angular/angular#30525 but I believe that only landed in 8.2.0-next.1.

This fixed a problem where ngcc was parsing the entire node_modules tree every time it was being run from the AngularCompilerPlugin.

I see that angular/angular#31509 has not appeared in any release yet. But it should be released with 8.2.0-next.2. Can you take another look at the performance once that is released. If it is still a problem then we can prioritize work on it.

[alan-agius4]

@crisbeto, would you be able to use the compiler-cli build snapshots and give it a shot and see if the timings improve?

Also, I suggest that you also update the @ngtools/webpack to either the latest or next version. There have been some fixes related to Ivy since 8.0.0 was release.

PS: Thanks @petebacondarwin for your input.

[crisbeto]

@alan-agius4 @petebacondarwin Looks like updating to next.1 brings it pretty much on par. Here are some numbers from this morning:

// Without ngcc (73398ms on average)
72809ms
72956ms
73827ms
72515ms
74883ms
--------------------------------------------
// With ngcc (73501ms on average)
73562ms
73252ms
73706ms
74152ms
72833ms

These numbers are from my local machine since I can't test it on our CI until next.2 comes out.

@petebacondarwin do you know whether your refactor would help with some CI flakiness that was being caused by ngcc as well? What I was seeing before is that very randomly (about once every 15 builds) ngcc would throw Unexpected end of JSON input without a stack trace. I traced it back to ngcc by monkey patching JSON.parse and logging out a stack trace when it throws an error so it's possible that the log below isn't totally accurate, however our flakes stopped (hasn't flaked in 4 days) once I disabled ngcc. Here's what the logs look like:

JSON.parse (/ci/project/app/build/config/build-config.ts:35:17)
loadEntryPointPackage (/ci/packages/compiler-cli/ngcc/src/packages/entry_point.ts:159:17)
Object.getEntryPointInfo (/ci/packages/compiler-cli/ngcc/src/packages/entry_point.ts:86:7)
EntryPointFinder.getEntryPointsForPackage (/ci/packages/compiler-cli/ngcc/src/packages/entry_point_finder.ts:116:9)
EntryPointFinder.walkDirectoryForEntryPoints (/ci/packages/compiler-cli/ngcc/src/packages/entry_point_finder.ts:74:30)
/ci/packages/compiler-cli/ngcc/src/packages/entry_point_finder.ts:95:36
Array.forEach (<anonymous>)
EntryPointFinder.walkDirectoryForEntryPoints (/ci/packages/compiler-cli/ngcc/src/packages/entry_point_finder.ts:91:10)
/ci/packages/compiler-cli/ngcc/src/packages/entry_point_finder.ts:95:36
Array.forEach (<anonymous>)
EntryPointFinder.walkDirectoryForEntryPoints (/ci/packages/compiler-cli/ngcc/src/packages/entry_point_finder.ts:91:10)
/ci/packages/compiler-cli/ngcc/src/packages/entry_point_finder.ts:28:60
Array.reduce (<anonymous>)
EntryPointFinder.findEntryPoints (/ci/packages/compiler-cli/ngcc/src/packages/entry_point_finder.ts:27:43)
Object.mainNgcc [as process] (/ci/packages/compiler-cli/ngcc/src/main.ts:110:9)
NgccProcessor.processModule (/ci/project/node_modules/@ngtools/webpack/src/ngcc_processor.js:54:16)
moduleNames.map.moduleName (/ci/project/node_modules/@ngtools/webpack/src/compiler_host.js:318:36)
Array.map (<anonymous>)
WebpackCompilerHost.resolveModuleNames (/ci/project/node_modules/@ngtools/webpack/src/compiler_host.js:315:28)
resolveModuleNamesWorker (/ci/project/node_modules/typescript/lib/typescript.js:88318:127)
resolveModuleNamesReusingOldState (/ci/project/node_modules/typescript/lib/typescript.js:88560:24)
processImportedModules (/ci/project/node_modules/typescript/lib/typescript.js:89890:35)
findSourceFile (/ci/project/node_modules/typescript/lib/typescript.js:89694:17)
processImportedModules (/ci/project/node_modules/typescript/lib/typescript.js:89926:25)
findSourceFile (/ci/project/node_modules/typescript/lib/typescript.js:89694:17)
processImportedModules (/ci/project/node_modules/typescript/lib/typescript.js:89926:25)
findSourceFile (/ci/project/node_modules/typescript/lib/typescript.js:89694:17)
/ci/project/node_modules/typescript/lib/typescript.js:89548:85
getSourceFileFromReferenceWorker (/ci/project/node_modules/typescript/lib/typescript.js:89515:34)
processSourceFile (/ci/project/node_modules/typescript/lib/typescript.js:89548:13)
processRootFile (/ci/project/node_modules/typescript/lib/typescript.js:89378:13)
/ci/project/node_modules/typescript/lib/typescript.js:88393:60
Object.forEach (/ci/project/node_modules/typescript/lib/typescript.js:280:30)
Object.createProgram (/ci/project/node_modules/typescript/lib/typescript.js:88393:16)

What I think was going on is that when I was running 10 builds in parallel 10 different instances of ngcc were trying to access the same files in the node_modules.

[petebacondarwin]

Thanks for the update @crisbeto - hopefully that means that we are not in a dire situation regarding performance :-)

Regarding the flakes, I am not surprised that this is happening. ngcc was never designed to be run multiple times in parallel, which is basically what is happening when running multiple builds on the same project at the same time, since the CLI+ngcc integration will trigger ngcc whenever it comes across a new import.

I could imagine that at some point build A is writing to a package.json file just as build B is trying to read from it. Normally it is safe to do this kind of thing in TS builds as they only ever write to their own exclusive files but ngcc writes directly into the shared node_modules folders. For us to be able to support this scenario we would need to add some resource locking mechanism, which in turn would require ngcc to become asynchronous internally I think...

So the natural solution, which you already mentioned, is to do a full ngcc compilation of the whole of the node_modules folders first (post-install?) before running any builds and then disable the CLI+ngcc integration. We should implement such a flag in CLI and have a story around this parallel builds scenario.

(By the way, this could become even more common if using Bazel to build projects since that naturally will try to parallelize compilations...)

[gkalpak]

FYI, we've run into the same issue with the docs examples (which essentially share the same node_modules/ directory via symlinks). See angular/angular#30593 for details on the problem and the solution.

[petebacondarwin]

Actually I think that we don't need the flag... if the node_modules have already been compiled by ngcc then the CLI+ngcc should not need to write any files, so there should be no flakes........

[gkalpak]

Yeah, exactly, that's how we solved it in angular/angular#30593 for angular.io docs examples 😉
No flakes (of that particular kind 😞) since 💪

[alan-agius4]

@crisbeto, seeing all the comments above. I don’t think there is anything to action.

Feel free to ping me on slack if you feel otherwise.

[crisbeto]

@petebacondarwin @alan-agius4 I'm still seeing the flaky behavior where ngcc throws Unexpected end of JSON input after I updated to 8.2.0-next.2.

[gkalpak]

@crisbeto, are you explicitly running ivy-ngcc upfront or implicitly via the cli?

[crisbeto]

I'm running it once up-front like this after I npm install:

const ngcc = require('@angular/compiler-cli/ngcc');
ngcc.process({
    basePath: path.join(projectRoot, 'node_modules'),
    compileAllFormats: false,
    propertiesToConsider: ['browser', 'module', 'main'],
    createNewEntryPointFormats: true
});

Afterwards it gets run implicitly by the NgccProcessor in the AngularCompilerPlugin.

[gkalpak]

Could it be that those properties do not correspond to the es2015 format (which the cli wants to compile)?

[crisbeto]

That call goes through fine. What I'm running into is that when I'm running 10 different Webpack builds in parallel, once every 10 or 15 times it flakes with Unexpected end of JSON input. My best guess is that it's due to multiple ngcc instances trying to read the same files at the same time.

[gkalpak]

I am not implying the call doesn't go through fine 😄 Here is what I mean:

The Unexpected end of JSON input can happen when a package.json gets corrupted. This in turn can happen if multiple ngcc instances try to update a package.json simultaneously. Ngcc updates package.jsons to add info about which formats have been processed.

Based on the above, the trick to avoid the error is to ensure that ngcc will not need to update any package.json during the concurrent cli builds. The way to achieve this is to ensure that all necessary formats will have been compiled in the initial standalone ngcc run.

So, you need to ensure that ngcc will have processed all formats that the cli will request afterwards.

[crisbeto]

That makes sense, although from looking at the logs it doesn't seem like it's doing any more compilation, because I'm not seeing any more of those Compiling something as ... messages.

[petebacondarwin]

It is worth taking a look at the package.json after the original ngcc run and then after the CLI compilation?

We should note that multiple properties in package.json map to the same code format. E.g. module and fesm5 and esm5 are the same "format".

So although you have built the esm5 format in the first run of ngcc (via the module property), there might be a case where the CLI attempts to build an additional entry point, which happens to map to a format that has already been built. In that case you would not see a "Compiling..." message but ngcc might still write to the package.json to say that an entry-point has been processed.

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