Skip to content

Slow compilation issues (40-50s) - --skipLibCheck not working #41517

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

Closed
NoPhaseNoKill opened this issue Nov 12, 2020 · 28 comments · Fixed by #41574
Closed

Slow compilation issues (40-50s) - --skipLibCheck not working #41517

NoPhaseNoKill opened this issue Nov 12, 2020 · 28 comments · Fixed by #41574
Assignees
Labels
Fix Available A PR has been opened for this issue Needs Investigation This issue needs a team member to investigate its status.

Comments

@NoPhaseNoKill
Copy link

TypeScript Version: 3.8.3

Search Terms: --skipLibCheck slow compilation tsc

Code

Running tsc --listFiles --generateCpuProfile profile --skipLibCheck from the command line results in having the following output - which appears to be slowing compilation significantly. It appears as though it's including multiple .d.ts files from my @types node_modules in the compilation. What sort of time should I be expecting this amount of files to compile in? Any help reducing the compilation time would also be greatly appreciated.

/home/user1/projects/projectName/node_modules/@types/semantic-ui-form/global.d.ts
/home/user1/projects/projectName/node_modules/@types/jquery/JQueryStatic.d.ts
/home/user1/projects/projectName/node_modules/@types/moment-timezone/moment-timezone.d.ts
.....etc

Extended diagnostics are:
Files:                         3022
Lines:                       410050
Nodes:                      1604064
Identifiers:                 555657
Symbols:                     804555
Types:                       254555
Memory used:               1220647K
Assignability cache size:     95587
Identity cache size:          13620
Subtype cache size:         4718477
Strict subtype cache size:     6378
I/O Read time:                0.10s
Parse time:                   1.78s
Program time:                 3.22s
Bind time:                    1.45s
Check time:                  39.98s
transformTime time:           1.39s
commentTime time:             0.56s
I/O Write time:               0.20s
printTime time:               5.02s
Emit time:                    5.02s
Total time:                  49.68s
 

my tsconfig is as follows:

{
  "compilerOptions": {
    "outDir": "./dist/",
    "extendedDiagnostics": true,
    "baseUrl": "src/",
    "module": "commonjs",
    "target": "es6",
    "jsx": "react",
    "allowJs": true,
    "allowSyntheticDefaultImports": true,
    "moduleResolution": "node",
    "esModuleInterop": true,
    "strict": true,
    "experimentalDecorators": true,
    "skipLibCheck": true,
    "lib": [
      "dom",
      "es2015",
      "scripthost",
      "es6",
      "es2016",
      "es2017"
    ]
  },
  "include": [
    "./src/**/*.ts",
    "./src/**/*.tsx"
  ],
  "exclude": [
    "node_modules",
    ".idea",
    ".storybook",
    ".git",
    "dist"
  ]
}

with my project folder structure being:

├── src
│   ├── folder1/....
│   └── folder2/.....
├── node_modules
│   ├── shouldNotBeCompiled1.d.ts
│   ├── shouldNotBeCompiled2.d.ts
│   └── shouldNotBeCompiled3.d.ts
├── dist

Expected behavior:
Should not type-check any of the files inside node_modules during compilation
Actual behavior:
Appears to be including node_modules/@types during compilation - which is causing a compilation time of ~50s for project.

Related Issues:
#37635
#36103

@NoPhaseNoKill
Copy link
Author

@amcasey tagging you both @RyanCavanaugh in this as I saw you from other threads with similar/slow compilation issues

@MartinJohns
Copy link
Contributor

@NoPhaseNoKill
Copy link
Author

Upgrading to 3.9.7 results in basically the same speed:

Files:                         2698
Lines:                       380456
Nodes:                      1438657
Identifiers:                 499827
Symbols:                     772615
Types:                       237792
Instantiations:              763693
Memory used:               1705486K
Assignability cache size:     85249
Identity cache size:          13293
Subtype cache size:         9399787
Strict subtype cache size:     4043
I/O Read time:                0.12s
Parse time:                   1.58s
ResolveTypeReference time:    0.04s
ResolveModule time:           0.93s
Program time:                 2.96s
Bind time:                    1.83s
Check time:                  35.41s
transformTime time:           1.51s
commentTime time:             0.46s
I/O Write time:               0.14s
printTime time:               4.80s
Emit time:                    4.80s
Total time:                  44.99s

@RyanCavanaugh RyanCavanaugh added the Needs Investigation This issue needs a team member to investigate its status. label Nov 12, 2020
@RyanCavanaugh RyanCavanaugh added this to the TypeScript 4.2.0 milestone Nov 12, 2020
@NoPhaseNoKill
Copy link
Author

As an FYI, if you need more information please let me know and I'll be happy to provide. The only problem is that I cannot post the project, as it's a private/institutional repo. So if there is any way of providing obfuscated data about the project that will help troubleshooting please let me know

@amcasey
Copy link
Member

amcasey commented Nov 13, 2020

@NoPhaseNoKill I wrote up some instructions for how to gather a trace that will identify which parts of your program are taking the longest to compile: https://github.com/microsoft/TypeScript/wiki/Performance-Tracing

Ideally, you'd share the resulting logs, but one of our goals in adding this functionality was to be able to work with users who can't share source. I'm hoping it will be enough for you to identify the problem and either fix it on your end or provide us a reduced repro (e.g. calling the same npm module that's giving you problems). It's still a pretty new tool (and doc), so ping me if you get stuck and I'll do what I can to unblock you (except tomorrow, when I'll be away). Thanks!

@amcasey
Copy link
Member

amcasey commented Nov 13, 2020

Anecdotally, from your huge subtype cache, I'm guessing you have a huge array of object literals somewhere (the trace should give you a file and position). If that's the case, my usual workaround is to add as any as YOUR_ARRAY_ELEMENT_TYPE to the first element.

I suspect the node_modules .d.ts files are a red herring. The short explanation is that the parts consumed by the code you're compiling will be checked (because the compiler needs to know about it to check your code) and the others won't. On their own, .d.ts files rarely contribute to check time - the cost is nearly always at the use-site.

@amcasey
Copy link
Member

amcasey commented Nov 13, 2020

One last point: I didn't see anything in your comment about your findings from generateCpuProfile. If you looked through it, I'd be interested to know what the hotspots were. If you didn't (personally, I find them very difficult to read), you might want to skip that flag because it will just slow down your run.

@NoPhaseNoKill
Copy link
Author

Yeah I didn't end up reading the CPU profile. Just currently running the performance tracing atm - so will get back to you ASAP.

What would an example of this be?

If that's the case, my usual workaround is to add as any as YOUR_ARRAY_ELEMENT_TYPE to the first element.

@NoPhaseNoKill
Copy link
Author

NoPhaseNoKill commented Nov 13, 2020

When trying to open the trace.json file - nothing is displaying (even though it's got the fact it's opened that file). Any ideas?

edit: The trace file is like 1.5GB - got a feeling it's maybe crashing/too big?

@NoPhaseNoKill
Copy link
Author

NoPhaseNoKill commented Nov 13, 2020

I'm more than happy to send the trace.json - as it doesn't include anything specific about the source code. How would you like me to upload this?

edit: I believe I can share these via OneDrive. Standby for links upon uploading

@NoPhaseNoKill
Copy link
Author

There's actually a few pieces of data in here which the company considers 'sensitive'. So I'm going to go through and obfuscate it. This should be done next Monday - so I'll post here with the links when it's good to go :)

@NoPhaseNoKill
Copy link
Author

Do let me know what you meant about the object literals though. We do have a large file which contains maybe 700/800 lines of object literals - so would be interested to see how we tackle this workaround considering we're assigning them to multiple consts etc.

Sorry for the constant posting, just brain dumping as I find out more info. Really appreciate the help :)

@NoPhaseNoKill
Copy link
Author

Ok I was able to trace the bug to the smallest possible repo. Please let me know if you need any further information @amcasey

Please see: https://github.com/NoPhaseNoKill/ts-slow-compilation-example/tree/main/src

When line 21 in the IconButton is commented out we get perf of:

Files:                         405
Lines:                       99782
Nodes:                      350212
Identifiers:                116341
Symbols:                     79696
Types:                        5179
Memory used:               131482K
Assignability cache size:      593
Identity cache size:            31
Subtype cache size:             24
Strict subtype cache size:       0
I/O Read time:               0.02s
Parse time:                  0.62s
Program time:                1.06s
Bind time:                   0.43s
Check time:                  0.18s
Total time:                  1.67s

However, when we're compiling the code we get nearly a 20x in compile time:

Files:                         405
Lines:                       99782
Nodes:                      350222
Identifiers:                116345
Symbols:                     79800
Types:                       20305
Memory used:               636574K
Assignability cache size:      635
Identity cache size:            31
Subtype cache size:        4698784
Strict subtype cache size:       0
I/O Read time:               0.02s
Parse time:                  0.66s
Program time:                1.11s
Bind time:                   0.47s
Check time:                 18.80s
Total time:                 20.39s

@amcasey
Copy link
Member

amcasey commented Nov 16, 2020

@NoPhaseNoKill Awesome! Thanks for the reduced repro! I'll dig in. Was --generateTrace useful in isolating that or did you have to figure it out yourself? Sorry about the huge log - we're working on ways to reduce that under Chrome's apparent 1GB cap (I usually post-process to drop very fast entries, but we're also looking at sampling approaches).

@amcasey
Copy link
Member

amcasey commented Nov 16, 2020

On pattern I've seen in a number of slow-to-compile projects is something like this:

const widgets: Widget[] = [
    {
        kind: "widget001"
        //  ...
    },
    // ...
    {
        kind: "widget999"
        //  ...
    },
];

The mitigation I usually use is to add a type assertion to the first list element:

    {
        kind: "widget001"
        //  ...
    } as Widget,

(In rare cases, that causes problems too, in which case I use as any as Widget.)

@NoPhaseNoKill
Copy link
Author

NoPhaseNoKill commented Nov 16, 2020

So I managed to fix the issue by doing this:

<Button>
    <Icon name={this.props.icon as any as SemanticICONS}/>
</Button>

The generate trace for this instance was not helpful, as the log file was coming out at at a whopping 1.5GB lol. Chrome basically was like "nope I ain't having that". I profiled it by myself, by deleting directories/files to narrow it down - which lead me to that line of code.

The one specific difference with this bug (maybe as opposed to others of similar nature) - is that the massive object literal is coming from a third party library (semantic-ui-react in this case). Not sure if this makes a difference when fixing the issue, but something to keep in mind when you guys roll out a fix.

edit: formatting

@amcasey
Copy link
Member

amcasey commented Nov 17, 2020

I have to admit I've never seen a trace like that before. Hopefully, I'll have some concrete details for you tomorrow.

@amcasey
Copy link
Member

amcasey commented Nov 17, 2020

@NoPhaseNoKill Is that code correct? Clearly the compiler shouldn't take so long (I think it's missing a complexity check), but I don't really understand how the type of this.props.icon could be both a string (one of ~2000 from SemanticICONS) and the type required by StrictButtonProps (i.e. boolean | SemanticShorthandItem<IconProps>). Am I missing something?

Edit: Ah, JavaScript - of course you can attach whatever properties you want to a string...

@amcasey
Copy link
Member

amcasey commented Nov 17, 2020

Here's a simpler repro:

import { SemanticICONS } from "semantic-ui-react";

type Stuff = { x: number; } | { y: string; } | { z: boolean; };

declare const icon: SemanticICONS & Stuff;
const name: SemanticICONS = icon;

For convenience, let's say SemanticICONS = "icon1" | ... | "icon2000". Basically, the type of icon is going to be ("icon1" & { x: number }) | ("icon1" & { y: string}) | ("icon1" & { z: boolean }) | ... | ("icon2000" & { z: boolean}) - a union with 6000 elements. To do the assignment to name, we have to confirm that each of those 6000 possible types of icon is assignable to one of the 2000 possible types in SemanticICONS, so we do 12E6 type comparisons, just at the outer layer. Add one more element to Stuff and we're at 16E6 comparisons. Of course, all along the way, we're creating temporary objects, which is why a cpu profile shows ~15% of time spent in GC.

So, what next?

  1. The compiler has a bunch of logic to detect these huge matrices of comparisons, but it seems to be missing this one, which seems like a bug.
  2. I'm pretty sure you just want the type of icon to be SemanticICONS from the start, so I'll see if I can figure out a better way to express that.

@amcasey
Copy link
Member

amcasey commented Nov 17, 2020

(My react experience is limited, so this may be a very dumb suggestion.) Maybe you wanted something like this?

import React from "react";
import {
  Button,
  ButtonProps,
  Icon,
  IconProps,
} from "semantic-ui-react";

interface Props {
  icon: IconProps;
};

//doesn't even need to be used

class IconButton extends React.Component<ButtonProps & Props> {
  render() {
    return (
      <Button>
        {/*comment out line 21 to see difference in performance*/}
        <Icon name={this.props.icon.name} />
      </Button>
    );
  }
}

export default IconButton;

It seems like ButtonProps already has a way to specify an icon as a name and you just want to say you expect that variant to be used?

@NoPhaseNoKill
Copy link
Author

NoPhaseNoKill commented Nov 17, 2020

Yeah the code I posted was just a demonstration of what caused the bug. The typing (as you've mentioned) was absolutely a little odd - and needed to be fixed. I didn't post this due to it being a private repo.

  1. Sounds good. Let me know if you need anything else from me.
  2. You're correct :)

edit: Really appreciate the help with debugging this/the time you've put in btw.
edi2: On taking a quick look through the ctrl + click inferred types, your explanation makes complete sense - and I can see how this particular case wouldn't have come up before haha. Hooray for bug fixing!

amcasey added a commit to amcasey/TypeScript that referenced this issue Nov 18, 2020
If their multiplied size is greater than 1E7 (chosen based on the repro
in microsoft#41517), then we'll expend a large amount of time and memory
comparing them, so alert the user instead.

Fixes microsoft#41517
@typescript-bot typescript-bot added the Fix Available A PR has been opened for this issue label Nov 18, 2020
@lafritay
Copy link

lafritay commented Dec 9, 2020

@amcasey @NoPhaseNoKill I'm experiencing the same issue and am also using semantic-ui-react. My trace file is also 1.5GB. Do either of you have any tricks to reduce the size of the file? @amcasey mentioned post-processing to remove fast entries - any tips or tools for doing that?

@NoPhaseNoKill
Copy link
Author

Performance tool in its current state didn't help me at all unfortunately. The best way to debug this (albeit tedious) - was to remove 50% of your repo at a time (ie delete) - recompile, and see whether there was a noticeable difference. Once you figure out which side of the repo is causing the issue, do a 50% delete on that and so forth.

This resulted in it narrowing down to a singular file, and you should then be able to apply the above fix (from previous posts) to solve your issue

@amcasey
Copy link
Member

amcasey commented Dec 9, 2020

@lafritay I have a local script that I've cleaned up and just have to post somewhere. Before we try that though, if you're using the same library, it seems likely that you're hitting a similar issue, which the compiler should now detect.

Edit: I just noticed that the PR isn't merged, so installing nightly won't help. Instead, you can grab a temp build from here. I'll work on getting it merged for real.

@lafritay
Copy link

lafritay commented Dec 9, 2020

@amcasey I was able to find the issue using the process @NoPhaseNoKill described so I think we're good here. Thanks for the work on the diagnostics though - it's really helpful.

@amcasey
Copy link
Member

amcasey commented Dec 9, 2020

@lafritay Did you narrow it down to something that was incorrect or just something that was too slow? #41903 should make it faster, but that's not much help if it just does the wrong thing more quickly. 😉

amcasey added a commit to amcasey/TypeScript that referenced this issue Dec 10, 2020
If their multiplied size is greater than 1E7 (chosen based on the repro
in microsoft#41517), then we'll expend a large amount of time and memory
comparing them, so alert the user instead.

Fixes microsoft#41517
@lafritay
Copy link

@amcasey Something that was slow. Removing this intersection got us 20 seconds of build time back:

image

@amcasey
Copy link
Member

amcasey commented Dec 10, 2020

@lafritay Thanks for the update! If you use this build of TS, I think you should be able to keep that code without losing build time. Please let me know if you have a chance to confirm.

amcasey added a commit that referenced this issue Dec 10, 2020
* Detect comparisons between large unions or intersections

If their multiplied size is greater than 1E6 (chosen based on the repro
in #41517), then we'll expend a large amount of time and memory
comparing them, so record a trace event.

Related to #41517

* Make an exception for primitive union comparisons

* Address PR feedback

* Pick up baseline change from master

* Eliminate diagnostic and only trace

* Don't check reportErrors
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Fix Available A PR has been opened for this issue Needs Investigation This issue needs a team member to investigate its status.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

6 participants