Incremental Compile Performance Regression 8.0.3 -> 8.0.11

[berickson1]

Note: This is in a relatively large repo that uses project references + composite projets
~55 typescript composite packages (and slowly growing)
Webpack + ts-loader for compilation (running in watch mode)

Expected Behaviour

Incremental compile is a similar duration after upgrade of ts-loader (~11 seconds)

Actual Behaviour

Incremental compile is 20x longer (~240 seconds)

Steps to Reproduce the Problem

Unfortunately I'm not able to share the repo - but a simple drop-in replacement of ts-loader caused a huge spike in incremental compile times. I'd love to provide any relevant debugging output to help diagnose this.

I think I can work around it by using fork-ts-checker-webpack-plugin, but ideally the root cause in ts-loader could be identified and fixed.

[johnnyreilly]

Could you identify specifically which version of ts-loader the regression occurred in please?

[berickson1]

I grabbed the webpack build times and recorded them below, the clock time on cold builds is actually higher than what webpack reports.
I performed the following test by installing the specified version of ts-loader, executing the webpack build in watch mode, recording first compile time, then modifying 1 file (same file every time) and recording time again

8.0.3 - cold build: 34845ms incremental: 14388ms
8.0.4 - cold build: 32921ms incremental: 13763ms
8.0.5 - cold build: 32908ms incremental: 13753ms
8.0.6 - cold build: 32030ms incremental: 13724ms
8.0.7 - cold build: 135885ms incremental: 176851ms
8.0.8 - cold build: 145522ms incremental: 157949ms
8.0.9 - cold build: 144421ms incremental: 153780ms
8.0.10 - cold build: 143325ms incremental: 154577ms
8.0.11 - cold build: 143119ms incremental: 151772ms

Note: Sample size of 1 build per version, but there's an obvious step function between 8.0.6 and 8.0.7, both for cold and incremental builds

#1202 seems to be the culprit. Incremental builds are effectively the same cost as cold builds, which is pretty much a dealbreaker for upgrading atm. I'd love to help diagnose however possible.

By comparison, executing tsc -b on a fresh repo takes ~262s and a change when running tsc -b -w takes ~7s.

[johnnyreilly]

Thanks for the detail @berickson1! Interestingly, @sheetalkamat's #1202 was designed to improve performance - and I believe (looking at the details) was tested with a fairly big project @sheetalkamat has access to.

So it's intriguing that this would have precisely the opposite effect on your builds.

I appreciate you can't share your build, but is there a way you could come up with a reliable repro repo? That will make it easier for others to help

[berickson1]

I spent some time fiddling and built an (arguably ugly) repro. Currently the example is using ts-loader 8.0.7.

https://github.com/berickson1/project-references-demo/tree/ts-loader-1215

To Test:

1. Clone
2. yarn install
3. yarn clean
4. yarn webpack
5. Once build is complete, edit a file (mod7\utilities.ts is what I've been using)

Downgrade to 8.0.6 and notice that incremental build times drop substantially.

One interesting tidbit is that the inclusion of an @material-ui/core had a noticeable impact on both cold and incremental builds (even when code relating to imported types was not touched)

[johnnyreilly]

Thanks @berickson1! It's funny you should mention material UI as I half remember something about that being used by TypeScript as an explicit test case against compilation time regressions.

@sheetalkamat / @andrewbranch do you have any thoughts about this?

[sheetalkamat]

#1217 should fix this

[berickson1]

I just pulled the latest ts-loader. Unfortunately this does not resolve the build time regressions in our product, in fact I believe it made things worse :(

Below is the latest build-time test dumps:
8.0.6 - cold build: 39,358ms incremental: 86,713ms
8.0.7 - cold build: 165,511ms incremental: 317,632ms
8.0.11 - cold build: 174,613ms incremental: 338,876ms
8.0.12 - cold build: 403,365ms incremental: 414,037ms (tested this 2 times to validate)

Note: Not sure why my incremental build times are so much worse than cold atm - perhaps something else part of the build, but either way I tested this starting at the latest version, working backwards - cold build -> record times -> change specific file for incremental build -> record fimes

[sheetalkamat]

The repro you created had the issue that was fixed in #1217
If there is anything else thats going not sure. you would need to create a repro.. You would also want to check how is performance for tsc -b and is that reasonable.

[berickson1]

The repro I shared above was the closest I could build to what we have in our closed source repo in a reasonable amount of time.
Here's the stats for tsc -b directly
Clean:

brenterickson$ time tsc -b

real	4m53.259s
user	5m23.414s
sys	0m9.751s

Incremental: (Same change I made in all the above tests)

brenterickson$ time tsc -b

real	0m56.854s
user	1m6.463s
sys	0m3.366s

[johnnyreilly]

Hey @berickson1,

Without a reliable reproduction repo, it won't be easy to help you I'm afraid (as @sheetalkamat suggests)

I appreciate it's a closed source repo and that does not make your life easier. I have definitely been there!

But without that, it's going to be hard for progress to be made.

[berickson1]

I've spent some time digging into this using ndb to profile and identify hot paths. Turns out most of the CPU cycles are going to ServicesHost.ts::getInputFileNameFromOutput (https://github.com/TypeStrong/ts-loader/blob/master/src/servicesHost.ts#L855).

I'm seeing a ton of files from node_modules pass through this function, none of which will ever resolve since they're not included in any of my tsconfig.json's for compilation. It appears that having 50+ projects totaling >2k files makes this 2x Map iteration + 1x Array iteration is non-trivially expensive when there's enough files being sourced from node_modules.

Adding a conditional to skip all node_modules in this function greatly speeds up my build and doens't appear to have any negative side-effects. I will admit that I don't fully understand the implications of this change & would need to dig a bit deeper before I would consider posting a PR (especially if a tsconfig.json happened to include anything from node_modules). Regardless, I wanted to post back here with my findings to see if that sparks any ideas/thoughts.

[johnnyreilly]

Thanks for sharing your findings. The node_modules piece is interesting. Out of curiosity, how does your codebase align with @DanielRosenwasser's perf code advice here: https://github.com/microsoft/TypeScript/wiki/Performance?utm_source=typescript-weekly.com&utm_campaign=typescript_weekly_159&utm_medium=email (does it follow advised good practices etc)

[berickson1]

Generally, we match up quite well. tsc alone doesn't have the same performance issue that ts-loader does.

Things we are doing:
Explicit include/exclude (node_modules is in a base tsconfig.json)
Separation of code using project references
Interfaces over intersections
Type annotations on function returns
Base-over-union types (generally)
strict: true

Things we're not doing:
isolated modules
skipLibCheck (on/off doesn't make a substantial difference)
type inclusion isn't explicit (but in testing it didn't have a large impact either)

[johnnyreilly]

I'm seeing a ton of files from node_modules pass through this function, none of which will ever resolve since they're not included in any of my tsconfig.json's for compilation.

This is very strange... I'm curious as to what the cause of this might be. What sort of things are you seeing included that you are surprised by; and and you see what the thing is that triggers that? And I'm guessing tsc doesn't include these? traceResolution may help here

[berickson1]

They're all .d.ts files from imported libraries (or @types).
I added a log line in servicesHost when this case occurs and here's a couple (scrubbed path) examples:

======== Module name './Zoom' was successfully resolved to 'client/node_modules/@material-ui/core/Zoom/Zoom.d.ts' with Package ID '@material-ui/core/Zoom/Zoom.d.ts@4.11.1'. ========
ts-loader fileName: client/node_modules/@material-ui/core/Zoom/Zoom.d.ts

and

======== Resolving module './RootRef' from 'client/node_modules/@material-ui/core/RootRef/index.d.ts'. ========
Explicitly specified module resolution kind: 'NodeJs'.
Loading module as file / folder, candidate module location 'client/node_modules/@material-ui/core/RootRef/RootRef', target file type 'TypeScript'.
File 'client/node_modules/@material-ui/core/RootRef/RootRef.ts' does not exist.
File 'client/node_modules/@material-ui/core/RootRef/RootRef.tsx' does not exist.
File 'client/node_modules/@material-ui/core/RootRef/RootRef.d.ts' exist - use it as a name resolution result.
Found 'package.json' at 'client/node_modules/@material-ui/core/package.json'.
'package.json' does not have a 'typesVersions' field.
======== Module name './RootRef' was successfully resolved to 'client/node_modules/@material-ui/core/RootRef/RootRef.d.ts' with Package ID '@material-ui/core/RootRef/RootRef.d.ts@4.11.1'. ========
ts-loader fileName: client/node_modules/@material-ui/core/RootRef/RootRef.d.ts

tsconfig has:
exclude **/node_modules
skipLibCheck: true

[berickson1]

As an addition the above - I hope to have some more time next week to dig a little deeper on why this code path is being hit. If all goes well, I hope to be able to contribute a fix back.
If anyone has thoughts or pointers I'm more than willing to listen!

[johnnyreilly]

Awesome - all help gratefully received ❤️🌻

[berickson1]

One quick fix: Enabling the useCaseSensitiveFileNames loader options greatly reduced my compile times. Turns out executing the 2 regexes in createFilePathKeyMapper in a tight loop on files was non-trivially expensive. Falling back to case-sensitive paths helped a ton in build times.

I'm in the process of getting contributions back to ts-loader ok'd by my employer, I hope to have a path forward to share a couple other code-changes by mid next-week.

[andrewbranch]

Adding a conditional to skip all node_modules in this function greatly speeds up my build and doens't appear to have any negative side-effects.

I’m not super familiar with the issue here, but since Sheetal is out for the holidays I wanted to chime in really quick before you get too far down this path to point out that there is a pretty large set of scenarios when you have project files in node_modules, and that’s via lerna or yarn workspaces monorepos, which symlink projects through each other’s node_modules. I’m not sure how common it is to have a monorepo like that run through Webpack, but it’s something to think about. I also noticed that function calls solutionBuilderHost.realpath() on every input if it doesn’t initially find a result—not sure if that’s already cached or not, but in the compiler we have a lot of heuristics and caches that prevent us from calling realpath very often.

[johnnyreilly]

Thanks for chiming in @andrewbranch - always appreciated ❤️🎄

[berickson1]

That's a fair point re: node_modules. ts-loader has a allowTsInNodeModules flag (https://github.com/TypeStrong/ts-loader#allowtsinnodemodules) that I think can be leveraged for this. Our project is a lerna monorepo, but webpack aliases ensure that the the source typescript files are referenced instead of those in node_modules. I suspect this is pretty common for monorepos based on my experiences

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

[stale]

Closing as stale. Please reopen if you'd like to work on this further.