Skip to content
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

Increased memory usage when creating a watch program that includes local JavaScript files in node_modules #58011

Closed
reduckted opened this issue Mar 31, 2024 · 29 comments Β· Fixed by #58398
Assignees
Labels
Needs Investigation This issue needs a team member to investigate its status.

Comments

@reduckted
Copy link

πŸ”Ž Search Terms

Reached heap limit Allocation failed out of memory createWatchCompilerHost createWatchProgram

πŸ•— Version & Regression Information

⏯ Playground Link

https://github.com/reduckted/repro-typescript-memory-usage

πŸ’» Code

This cannot be reproduced with a few lines of code. It needs a large TypeScript project. Use these steps to see the increased memory usage:

  1. Clone the repository git clone https://github.com/reduckted/repro-typescript-memory-usage
  2. Run npm i
  3. Run node run.js and see the memory usage (this will be for TypeScript 5.4.3).
  4. Install TypeScript 5.3.3 npm i typescript@5.3.3 -D
  5. Run node run.js and see the memory usage.

For the linked repository, I am seeing 525 MB used in 5.3.3 and 775 MB used in 5.4.3. The larger the TypeScript project, the worse the memory usage is.

πŸ™ Actual behavior

The memory consumed by TypeScript 5.4 is much larger compared to 5.3. The larger the TypeScript project, the worse the memory usage is. Large projects can cause Node.js to run out of memory.

πŸ™‚ Expected behavior

TypeScript should have equivalent memory usage to v5.3.

Additional information about the issue

What I've been able to determine is that when you have a JavaScript project in the repository and install it as a node module, creating a "watch" program that includes files that require files from that project will consume significantly more memory in 5.4.3 compared to 5.3.3.

I encountered this problem when running ESLint with a config that uses the @typescript-eslint/* plugins. Using TypeScript 5.3.3, ESLint would run fine. After upgrading to 5.4.3, ESLint would crash with an out of memory error:

FATAL ERROR: Reached heap limit Allocation failed - JavaScript heap out of memory

The repository that this was occurring on is an internal, closed-source company project, so I can't share it and signing an NDA will not be possible. However, I have been able to see an increased memory usage with a similar project setup in other projects. The repository I have linked above is a clone of ionic-team/ionic-framework with a few additions to it.

This is roughly the setup in the closed-source repository:

  • All TypeScript code is contained under a source/ directory.
  • We have some JavaScript projects that are for various build tools. One of them is for our Storybook configuration.
  • We install those JavaScript projects as node modules so that we can refer to them using @my/project (for example) rather than use relative paths.
  • We have a .storybook/ folder at the root. The files in that folder require some of the JavaScript projects.
  • We have a TypeScript configuration file that is specifically used by ESLint. It includes all of the TypeScript code as well as the .storybook/ directory, as well as a few other files that aren't relevant to this issue.

I've created a similar setup in the linked repository.

I've created a script called run.js that does a simplified version of what the @typescript-eslint plugin does. It creates a "watch" compiler host, then creates a "watch" program:

let tsconfigPath = path.join(__dirname, "tsconfig.memory.json");

let host = ts.createWatchCompilerHost(
  tsconfigPath,
  {
    noEmit: true,
    noUnusedLocals: true,
    noUnusedParameters: true,
    allowNonTsExtensions: true,
    allowJs: true,
    checkJs: true,
    extendedDiagnostics: true,
  },
  ts.sys,
  ts.createAbstractBuilder,
  () => {},
  () => {}
);

host.onUnRecoverableConfigFileDiagnostic = (diagnostic) => {
  console.log(
    ts.flattenDiagnosticMessageText(diagnostic.messageText, ts.sys.newLine)
  );
};

host.trace = () => {};

console.log("TypeScript v" + ts.version);

console.log(
  `Memory before: ${Math.trunc(process.memoryUsage().heapUsed / 1048576)} MB`
);
let program = ts.createWatchProgram(host);

console.log(
  `Memory after:  ${Math.trunc(process.memoryUsage().heapUsed / 1048576)} MB`
);
program.close();

Using the linked repository, I'm seeing this when using TypeScript 5.3.3:

TypeScript v5.3.3
Memory before: 20 MB
Memory after:  525 MB

And this for TypeScript 5.4.3:

TypeScript v5.4.3
Memory before: 20 MB
Memory after:  775 MB

An extra 250 MB of memory used. If you remove ".storybook/**/*.js" from the TypeScript configuration, the amount of memory used by TypeScript 5.4.3 is about 580 MB, so still a little bit higher that 5.3.3, but significantly less that 5.4.3.

The larger the project, the worse the memory usage is.

In the closed-source repository, if I remove about half the code, I get these results:

Some of the extended diagnostics
--------------------------------
Files:                6726
Lines of Library:     37748
Lines of Definitions: 200580
Lines of TypeScript:  468949
Lines of JavaScript:  0
Lines of JSON:        0
Lines of Other:       0

Memory usage
------------
TypeScript v5.3.3:
Memory before: 20 MB
Memory after:  1313 MB

TypeScript v5.4.3:
Memory before: 20 MB
Memory after:  3532 MB

If I include all of the code and increase the heap size, I get these results:

Some of the extended diagnostics
--------------------------------
Files:                8800
Lines of Library:     37748
Lines of Definitions: 202172
Lines of TypeScript:  1118038
Lines of JavaScript:  0
Lines of JSON:        0
Lines of Other:       0

Memory usage
------------
TypeScript v5.3.3:
Memory before: 20 MB
Memory after:  2254 MB

TypeScript v5.4.3:
Memory before: 20 MB
Memory after:  8180 MB

As you can see, that's an extra 6 GB of memory compared to 5.3.3! 🀯

Here's a summary of the increased memory usage:

Files Memory Usage in v5.3.3 Memory Usage in v5.4.3
1605 525 MB 775 MB
6726 1313 MB 3532 MB
8800 2254 MB 8180 MB
@reduckted
Copy link
Author

@andrewbranch Any ideas why 385db44 might have triggered this issue?

@andrewbranch
Copy link
Member

Because we’re loading more of your own JS files instead of giving you implicit anys while refusing to read them. Is there a reason you need allowJs enabled but don’t want it to apply to monorepo packages installed locally into other packages?

@reduckted
Copy link
Author

reduckted commented Apr 10, 2024

Because we’re loading more of your own JS files

I understand that more files need to be loaded and that will lead to more memory usage, but 6,000 MB more memory? A 300% increase? That seems excessive to say the least.

Is there a reason you need allowJs enabled

We have a mix of TypeScript and JavaScript in the monorepo. The TypeScript is the application code, while the JavaScript is used for tooling (like ESLint rules, Storybook configurations, build scripts, etc). The reason why we use JavaScript for those types of projects is so that we don't need to compile them before we can use them. For example, we can just run ESLint and it uses our custom rules instead of us first having to compile our rules from TypeScript into JavaScript. It just makes life easier.

The TypeScript and JavaScript projects have separate configuration files (tsconfig.json for the TypeScript projects and jsconfig.json for the JavaScript projects), but we also have a combined project that is used by ESLint - see https://typescript-eslint.io/getting-started/typed-linting/monorepos#one-tsconfigjson-per-package-and-an-optional-one-in-the-root

Having this combined configuration ensures that VS Code (via the ESLint plugin) will check any file in the workspace because the files from all projects are in the TypeScript project that ESLint is using.

@andrewbranch
Copy link
Member

Your extendedDiagnostics comparisons show memory usage before and after, but only files/nodes/etc. from before. Look at the full output in each version and you’ll be able to see where that memory usage comes from and whether 400% seems expected.

@reduckted
Copy link
Author

Unfortunately, the extended diagnostics from tsc --extendedDiagnostics are virtually identical because the issue doesn't occur when compiling via tsc. It only occurs when using a "watch compiler host".

Property 5.3.3 5.4.3
Files 8809 8810
Lines of Library 37748 38041
Lines of Definitions 202344 202344
Lines of TypeScript 1127689 1127689
Lines of JavaScript 0 0
Lines of JSON 0 0
Lines of Other 0 0
Identifiers 1593168 1593382
Symbols 2079779 2055354
Types 567055 566961
Instantiations 2187276 2201951
Memory used 2159326K 2158843K
Assignability cache size 268493 269038
Identity cache size 16611 16618
Subtype cache size 45843 45813
Strict subtype cache size 87618 87623
I/O Read time 2.58s 2.51s
Parse time 5.26s 5.19s
ResolveModule time 2.85s 2.79s
ResolveLibrary time 0.01s 0.02s
ResolveTypeReference time 0.02s 0.01s
Program time 12.13s 11.87s
Bind time 2.82s 2.54s
Check time 49.14s 50.67s
printTime time 0.00s 0.00s
Emit time 0.00s 0.00s
Total time 64.09s 65.08s

I'll try to work out how to get the same information from the watch host compiler.

@reduckted
Copy link
Author

@andrewbranch Here are the extended diagnostics from the watch host compiler for 5.3.3 and 5.4.5:

Property v5.3.3 v5.4.5 Diff Diff %
Files 8823 9330 +507 5.7%
Lines of Library 37748 38041 +293 0.7%
Lines of Definitions 204088 329819 +125731 61.6%
Lines of TypeScript 1126416 1126416 0 0%
Lines of JavaScript 276 1761 +1485 538.0%
Lines of JSON 0 0 0 0%
Lines of Other 0 0 0 0%
Identifiers 1640769 1771163 +130394 7.9%
Symbols 2081369 2140374 +59005 2.8%
Types 567044 574305 +7261 1.2%
Instantiations 2186559 2229199 +42640 1.9%
Memory used 2338983K 8332631K +5993648 256.2%
Assignability cache size 268459 271481 +3022 1.1%
Identity cache size 16564 16580 +16 0.09%
Subtype cache size 45773 45812 +39 0.08%
Strict subtype cache size 87667 87687 +20 0.02%
I/O Read time 7.63s 6.19s -1.44 -18.8%
Parse time 5.68s 6.08s +0.4 7.0%
ResolveModule time 3.00s 3.37s +0.37 12.3%
ResolveLibrary time 0.03s 0.04s +0.01 33.3%
ResolveTypeReference time 0.03s 0.04s +0.01 33.3%
Program time 25.59s 140.48s +114.89 448.9%
Bind time 2.49s 3.23s +0.74 29.7%
Check time 47.07s 55.12s +8.05 17.1%
printTime time 0.00s 0.00s 0 0%
Emit time 0.00s 0.00s 0 0%
Total time 75.15s 198.84s 123.69 164.4%

@andrewbranch
Copy link
Member

andrewbranch commented Apr 15, 2024

Something is definitely weird. All the correlates of memory usage increased modestly, as expected, while actual memory usage shot up. And all the times increased somewhat within the expected range too, except for program time, which shot up inexplicably. If you look at your smaller repro, the same pattern doesn’t existβ€”program time increased only slightlyβ€”so I’m not sure it’s a good representation of what’s going on here.

Edit: yeah, in the small repro, the time/memory increase can be explained by the newly included JS pulling in all the Storybook type definitions. It looks like those are fairly expensive to process, judging by the type instantiation diff. Something different is happening in the private repo that you haven’t captured in the small version.

@andrewbranch
Copy link
Member

andrewbranch commented Apr 15, 2024

@sheetalkamat can you think of a way that #56946 could be having an unexpected interaction with watch programs specifically that’s creating a huge memory / program construction time increase?

@RyanCavanaugh RyanCavanaugh added the Needs Investigation This issue needs a team member to investigate its status. label Apr 17, 2024
@sheetalkamat
Copy link
Member

I am not sure whats going on.
Can you check tsc --watch --extendedDiagnostics this should use watch compiler host in tsc. do you see similar to tsc --extendedDiagnsotics i am assuming it to be.
Once done that i would then get logs from --traceResolutions and --explainFiles on both (programatic watch host that you are running and tsc --watch ) and compare and see where things are going off rail and including more files.

@reduckted
Copy link
Author

Apologies for the slow response.

I've discovered an important piece of information. This only happens on Windows. I was able to set up a WSL environment with the same projects and test script. I tried copying the TypeScript code into ~/ and installing node modules there so it's unaffected by whatever npm did on Windows, and the memory usage was more or less the same as TypeScript v5.3.

I also tried running the test script against the projects and node_modules directory on Windows via /mnt and had the same result - the memory usage is equivalent to TypeScript v5.3.

Back on Windows, here's the extended diagnostics from tsc and tsc --watch. Pretty much the same.

Property tsc tsc --watch
Files 8813 8813
Lines of Library 38041 38041
Lines of Definitions 202437 202437
Lines of TypeScript 1127001 1127001
Lines of JavaScript 0 0
Lines of JSON 0 0
Lines of Other 0 0
Identifiers 1592629 1592629
Symbols 2058568 2058568
Types 567416 567416
Instantiations 2205378 2205378
Memory used 2175471K 2262510K
Assignability cache size 269264 269264
Identity cache size 16617 16617
Subtype cache size 45742 45742
Strict subtype cache size 87559 87559
I/O Read time 2.50s 3.34s
Parse time 5.16s 6.99s
ResolveModule time 2.81s 4.73s
ResolveLibrary time 0.02s 0.05s
ResolveTypeReference time 0.01s 0.03s
Program time 11.85s 37.08s
Bind time 2.42s 2.42s
Check time 48.01s 47.57s
printTime time 0.00s 0.00s
Emit time 0.00s 0.01s
Total time 62.28s 87.07s

I'll work on getting the --traceResolutions and --explainFiles output as soon as I can.

@jakebailey
Copy link
Member

Hm, it's a long shot, but if this happens on Windows but not on Linux, can you disable forceConsistentCasingInFileNames and try your test again?

@reduckted
Copy link
Author

Hm, it's a long shot, but if this happens on Windows but not on Linux, can you disable forceConsistentCasingInFileNames and try your test again?

That does indeed seem to be causing the problem.

With forceConsistentCasingInFileNames set to false:

Files:                         9392
Lines of Library:             38041
Lines of Definitions:        331893
Lines of TypeScript:        1127001
Lines of JavaScript:           1768
Lines of JSON:                    0
Lines of Other:                   0
Identifiers:                1774641
Symbols:                    2145904
Types:                       575068
Instantiations:             2233494
Memory used:               2302867K
Assignability cache size:    271829
Identity cache size:          16626
Subtype cache size:           45811
Strict subtype cache size:    87658
I/O Read time:                3.28s
Parse time:                   7.01s
ResolveModule time:           3.71s
ResolveLibrary time:          0.04s
ResolveTypeReference time:    0.04s
Program time:                24.76s
Bind time:                    3.25s
Check time:                  60.84s
printTime time:               0.01s
Emit time:                    0.01s
Total time:                  88.86s

@jakebailey
Copy link
Member

Hm, that time is still 88 seconds, no? Aren't you expecting 62s?

@reduckted
Copy link
Author

reduckted commented Apr 23, 2024

88 seconds is about on par with a regular tsc --watch. The 62 seconds was just from tsc. I ran it again and the total time was about 78 seconds, so the fluctuations are probably just down to other stuff that's happening on my machine.

@jakebailey
Copy link
Member

But, the key is that memory usage is lower? Not totally seeing the change or memory increase from the above, now that I look.

@reduckted
Copy link
Author

Yeah, when forceConsistentCasingInFileNames is set to false, the memory usage is equivalent to a regular tsc or tsc --watch. With forceConsistentCasingInFileNames set to true, it's ~8300000K compared to ~2300000K.

@jakebailey
Copy link
Member

jakebailey commented Apr 23, 2024

This looks very similar to typescript-eslint/typescript-eslint#1192 then. But that's utterly confusing because this issue is new, while the eslint one is not... Probably not technically similar given the ESLint thing seems to be a diagnostic leak of some sort, but maybe something there...

@jakebailey
Copy link
Member

@reduckted When you get a chance, can you try using "typescript": "npm:@typescript-deploys/pr-build@5.5.0-pr-58299-2" (from #58299 (comment)) and see what happens?

@reduckted
Copy link
Author

Unfortunately, I think that made it worse. 😬

Extended Diagnostics from @typescript-deploys/pr-build@5.5.0-pr-58299-2

Files:                         9333
Lines of Library:             38310
Lines of Definitions:        330028
Lines of TypeScript:        1125933
Lines of JavaScript:           1874
Lines of JSON:                    0
Lines of Other:                   0
Identifiers:                1771154
Symbols:                    2146594
Types:                       575457
Instantiations:             2264849
Memory used:               9018150K
Assignability cache size:    271633
Identity cache size:          15752
Subtype cache size:           45778
Strict subtype cache size:    87964
I/O Read time:                2.83s
Parse time:                   7.16s
ResolveModule time:           3.45s
ResolveLibrary time:          0.06s
ResolveTypeReference time:    0.05s
Program time:               162.39s
Bind time:                    3.36s
Check time:                  62.71s
printTime time:               0.00s
Emit time:                    0.00s
Total time:                 228.47s

@jakebailey
Copy link
Member

That's even more confusing. It's a shame this repo is closed, as heap snapshots would be pretty helpful to know what's leaking...

@sheetalkamat
Copy link
Member

sheetalkamat commented Apr 24, 2024

@jakebailey i dont think that fix is right. The issue doesnt repro with tsc --watch only with programatic usage of API.
Please share a repro as otherwise its hard to identify the issue based on speculation. The only way to debug this is to see where the programatic usage and tsc --watch differ. traceResolution and explainFiles might help you spot those differences or you would need to debug it further if you cant share the repro

Update: Also another option to try is to use createProgram to create the program and see if the memory usage issue persists. I am thinking it might but thats just speculation without any concrete repro.

@jakebailey
Copy link
Member

Ah, I forgot that this was about the public API; too many examples that mention tsc and tsc --watch for my brain to handle πŸ˜…. Though if it's always programmatic stuff which fails, then that is even more like typescript-eslint/typescript-eslint#1192 (which I'm almost thinking is related just because eslint has to open loads of files that would not normally be loaded by a regular tsc run).

But forceConsistentCasingInFileNames sure seems like the key here.

@jakebailey
Copy link
Member

Can you try this build? #58352 (comment)

@sheetalkamat
Copy link
Member

So i looked into the repro you shared a little bit and initially i was suprised as to why there is extra memory compared to just using plain program API and then I realised that you have not set host.afterProgramCreate as undefined which means its doing error reporting and hence type checking.
When i set that undefined the results were comparable to bare program creation with extra usage for data about state for watching etc.

What i noticed in your said example is that Symbols, Types, instantiations have significantly increased along with number of files included. So that increase in memory makes sense to me.

5.3.3 v5.5.0-dev.20240430
Files: 1829 1908
Lines of Library: 37748 38310
Lines of Definitions: 188635 218606
Lines of TypeScript: 82545 82545
Lines of JavaScript: 48 95
Lines of JSON: 0 0
Lines of Other: 0 0
Identifiers: 345442 372494
Symbols: 376435 703767
Types: 164829 292256
Instantiations: 246424 840805
Memory used: 538763K 806180K
Assignability cache size: 233655 251302
Identity cache size: 555 2555
Subtype cache size: 1597 1612
Strict subtype cache size: 16531 17068
I/O Read time: 0.98s 0.34s
Parse time: 1.53s 1.43s
ResolveModule time: 0.59s 0.58s
ResolveLibrary time: 0.02s 0.03s
ResolveTypeReference time: 0.08s 0.08s
Program time: 4.57s 3.73s
Bind time: 0.62s 0.61s
Check time: 7.60s 9.96s
printTime time: 0.00s 0.00s
Emit time: 0.00s 0.00s
Total time: 12.79s 14.30s

Later on you have also reported that the issue repros only if you set forceConsistentFileNames to true and I wasnt able to see that with the given repro. So something is missing in the repro you have created. Having said that, it would be great if you can either create a repro or share your code so we can investigate this further. We have lots of reports as @jakebailey mentioned about es-lint issues but no repro.

Also i have a theory that i am going to work out and create a PR but having a concrete repro really helps speedup investigation rather than us trying things based on some theories.

@reduckted
Copy link
Author

reduckted commented May 1, 2024

Can you try this build? #58352 (comment)

No improvement with that one either.

Having said that, it would be great if you can either create a repro or share your code so we can investigate this further

I've actually managed to anonymize the repository, so I will be able to share it soon. I just need to verify that everything has been anonymized. It's a large repo, so it's taking some time to review. Thanks for the patience with this. πŸ™

@sheetalkamat
Copy link
Member

Really appreciate the efforts for repro .. it will help with the right fix . Thanks

@sheetalkamat
Copy link
Member

Can you please try #58398 (comment) to see if this fixes your issue.

@reduckted
Copy link
Author

I've finally been able to get the reproduction in a state where I can share it.

https://github.com/reduckted/repro-typescript-memory-usage-anonymized

All of the TypeScript files just contain imports and exports - there's no other code, so the overall memory usage is quite a bit lower than what the private repository has, but you can still see a very significant increase in memory.

What I've discovered while putting this reproduction together is that the memory usage is low if the path of the TypeScript configuration file exactly matches the path on disk. However, if you specify a path that is a different case (which is what @typescript-eslint does for some reason), then you get a huge increase in memory usage.

I've included the reproduction steps in the repository, but I'll post them here as well. Just a reminder that this only occurs on Windows.

cd Workspace
npm install
npm start

This will convert the full path of the TypeScript configuration file to lowercase - note that the Workspace/ folder has a capital "W", so the path is not an exact match.

To run the same code using the real file path without changing the case, run:

npm run real-path

This is what I am seeing as the results:

Extended Diagnostics npm start npm run real-path
Files 4843 4843
Lines of Library 38041 38041
Lines of Definitions 174189 174189
Lines of TypeScript 32561 32561
Lines of JavaScript 30 30
Lines of JSON 0 0
Lines of Other 0 0
Identifiers 201753 201753
Symbols 140060 140060
Types 2272 2272
Instantiations 168 168
Memory used 1448950K 335819K
Assignability cache size 24 24
Identity cache size 0 0
Subtype cache size 0 0
Strict subtype cache size 0 0
I/O Read time 0.57s 0.69s
Parse time 1.62s 1.76s
ResolveModule time 1.12s 1.56s
ResolveTypeReference time 0.02s 0.02s
ResolveLibrary time 0.07s 0.07s
Program time 26.18s 8.88s
Bind time 0.59s 0.62s
Check time 0.80s 1.09s
printTime time 0.00s 0.00s
Emit time 0.00s 0.00s
Total time 27.57s 10.60s

@reduckted
Copy link
Author

Can you please try #58398 (comment) to see if this fixes your issue.

That has made a huge improvement! There's still a slight increase in memory between using an exact file path and a lowercase file path, but it's much, much closer than it was.

TypeScript Config:    d:\code\repro-typescript-memory-usage-anonymized\workspace\tsconfig.eslint.json
TypeScript Version:   5.5.0-insiders.20240502
Memory used:          332 MB

vs

TypeScript Config:    D:\Code\repro-typescript-memory-usage-anonymized\Workspace\tsconfig.eslint.json
TypeScript Version:   5.5.0-insiders.20240502
Memory used:          299 MB

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Needs Investigation This issue needs a team member to investigate its status.
Projects
None yet
5 participants