Repository navigation
Compilation time significantly slower in 3.7.1-RC vs 3.5.2, essentially the "check time" part. #34920
Description
TypeScript Version: 3.7.1-RC
Search Terms: Compilation time Check time 3.7.1-RC
Code
// takes 25-30 minutes
node --max-old-space-size=8092 "C:\Program Files (x86)\Microsoft SDKs\TypeScript\3.7\tsc.js"
// takes 2-3 minutes
node --max-old-space-size=8092 "C:\Program Files (x86)\Microsoft SDKs\TypeScript\3.5\tsc.js"Expected behavior: Compilation should take a reasonable amount of time
Actual behavior: Compilation is 10 times slower than 3.5.2 version.
Related Issues: maybe related: #24435
Hi, we give a try at typescript 3.7.1-RC today (upgrading from 3.5.2) and we are facing a significant increase of build time.
I've launched the compilation with extendedDiagnostics flag and this is the "check time" which is a lot slower.
In 3.7.1-rc:
Files: 532
Lines: 402274
Nodes: 1927658
Identifiers: 684045
Symbols: 1844544
Types: 528324
Memory used: 1857090K
Assignability cache size: 337352
Identity cache size: 10477
Subtype cache size: 88675
I/O Read time: 0.15s
Parse time: 3.89s
Program time: 4.72s
Bind time: 2.84s
Check time: 1480.74s
transformTime time: 9.18s
commentTime time: 0.28s
I/O Write time: 0.41s
printTime time: 22.17s
Emit time: 22.25s
Total time: 1510.55s
In 3.5.2:
Files: 532
Lines: 400795
Nodes: 2122066
Identifiers: 672829
Symbols: 1707809
Types: 518149
Memory used: 1781530K
Assignability cache size: 333702
Identity cache size: 1968
Subtype cache size: 88497
I/O Read time: 0.14s
Parse time: 3.51s
Program time: 4.22s
Bind time: 2.50s
Check time: 85.37s
transformTime time: 11.09s
commentTime time: 0.13s
I/O Write time: 0.56s
printTime time: 33.09s
Emit time: 33.16s
Total time: 125.24s
Do you have any clue of what is going on ? I've saw nothing in breaking change that could cause that.
Thanks in advance.
the tsconfig.json used:
{
"compileOnSave": true,
"compilerOptions": {
"incremental": false,
"outDir": "./dist/js",
"noImplicitAny": false,
"allowJs": false,
"checkJs": false,
"noEmitOnError": true,
"removeComments": true,
"sourceMap": false,
"target": "es5",
"lib": [
"dom",
"es5",
"scripthost",
"es2015.promise",
"es2015.collection",
"es2015.core",
"es2015.generator",
"es2015.iterable",
"es2015.proxy",
"es2015.reflect",
"es2015.symbol",
"es2015.symbol.wellknown"
],
"rootDir": "./src/js",
"noResolve": true,
"module": "amd",
"moduleResolution": "node",
"experimentalDecorators": false,
"jsx": "react"
},
"include": [
"./src/**/*.js",
"./src/**/*.ts",
"./src/**/*.tsx",
"./Scripts/typings/**/*.ts"
],
"exclude": [
"./Scripts/excludedtypings/**/*.ts",
"node_modules",
"node_modules/@types",
"wwwroot"
]
}
Activity
[-]Compilation time significantly slower in 3.7.1-RC vs 3.5.2 "essentially "check time" part.[/-][+]Compilation time significantly slower in 3.7.1-RC vs 3.5.2, essentially the "check time" part.[/+]temeass commentedon Nov 5, 2019
Shinigami92 commentedon Nov 6, 2019
yarn buildtriggersvue-cli-service buildMedium sized SPA
... cant see any problem in our project 👍
amcasey commentedon Nov 8, 2019
Ikaer thanks for the detailed feedback! Any chance your build is something we can set up locally? If not (no worries, it's pretty common), could you possibly try with 3.6.4 and let us know what you see? That will help us narrow down the span of possible changes.
Ikaer commentedon Nov 12, 2019
Andrew Casey (@amcasey) We try to compile with 3.6.2 (we don't have the 3.6.4 installed on this server). It takes the same amount of time than the 3.7. So It is probably a change made between the 3.5.2 and the 3.6.2.
I cannot provide the source code for this specific solution, sorry :(
Ikaer commentedon Nov 12, 2019
Maybe this can help you to find where the problem is: I've done a node profiling of the compilation with 3.7, and below is a summary (the complete file is attached).
profiling.txt
For comparison this is the profiling with 3.5.2: Profiling352.txt
amcasey commentedon Nov 12, 2019
Ikaer Wow, thanks for the profile! Any chance you'd be willing to share the underlying isolate logs? They should only point into our source, not yours. Better still, if you wanted to do a run with
--trace-maps --trace-ic --prof, we could visualize which parts of our code are contributing to the slowdown.Edit: that's overkill. In 3.7, you should be able to pass
--generateCpuProfile filename.cpuprofiletotscand get a clean CPU trace (i.e. we attempt to scrub any user data).amcasey commentedon Nov 12, 2019
I think the trace shows a huge increase in the amount of GC going on in the newer compiler and the extended diagnostics above seem to indicate that there are 5X as many identity cache entries. That's pretty suspicious.
amcasey commentedon Nov 12, 2019
Ikaer are you using a lot of intersection types? There was some work done in 3.6 to eliminate duplicate signatures that requires a bunch of new identity checks: #32049
If that seems promising, I can try to make you a private build without that change to confirm that it's the culprit. If it is, we can refine the check.
amcasey commentedon Nov 13, 2019
Ikaer you should be able to get a build of 3.6 without the potentially problematic check from #35073 when the bot finishes.
Ikaer commentedon Nov 13, 2019
I will get a run with this version and will let you know how it goes.
For the intersections, yep, we use them a lot, we have a transpilation engine which convert C# code (from server side) into declaration file with enums converted to string literal intersection type.
Ikaer commentedon Nov 13, 2019
Andrew Casey (@amcasey) this build does not effect the build time (still very long). In this files36Fix.zip , I've put the extenddiagnostics and the isolate file.
I was not able to use the flag
--trace-maps(I'm using node 6.5.0, maybe its an option who appeared later ?),but --trace-ic worked
amcasey commentedon Nov 13, 2019
Ikaer sorry, it didn't even occur to me to mention that we needed a trace from a newer version of node (we generally use 10 or 12, but I suspect 8 would work as well). In any case, the full trace (thanks for your patience - that thing is huge) is less likely to be less useful than the output of
--generateCpuProfilein this particular case. Did you have a chance to try it? It may also depend on Node >= 8.The extended diagnostics were very interesting. It looks like it did partly address the regression - just not enough to be useful. I'll see if I can find another change that might have had a similar effect.
Edit: in local tests, Node 8 + TS 3.7 is sufficient for
--generateCpuProfile(which is new in 3.7).Ikaer commentedon Nov 14, 2019
Andrew Casey (@amcasey) So.... I've installed node 12.13 and TS 3.7.2 and the compilation time is reasonable again, I have also run a test with the 3.6.2 and same outcome.
Compilation is still longer than before with 3.5.2 (221s vs 57s) but it's manageable.
I've attached diagnostics file (isolate file have been made with --trace-ic and --trace-maps this time.)
3.5.zip: extendedDiagnostics + isolate file
3.6.zip: extendedDiagnostics + isolate file
3.6withfix.zip: extendedDiagnostics + isolate file
3.7.zip: extendedDiagnostics +profile.cpuprofile
amcasey commentedon Nov 15, 2019
Ikaer Thanks for the update! I believe Node 12 removed the default memory cap (~1GB), so my guess would be that it's no longer running out of memory and then thrashing the GC. However, there's still about 25% of time devoted to GC in the 3.7 trace, so I'd still like to understand what's allocating. Obviously, every version of TS adds new checks (i.e. does more work and allocates more memory), but it's also possible that something is leaking. I'll have to see if there's a way I can get an allocation trace without access to your source.
amcasey commentedon Dec 3, 2019
I haven't forgotten about this. I've been iterating with another customer on how to figure out which compiler objects are being allocated without exposing user data and so far there isn't a clear solution.
Ikaer commentedon Dec 3, 2019
Andrew Casey (@amcasey) thanks for the update!
We can have an intermediate exposing. If it's just object names, types, paths, callstacks, any kind of aggregated information, I'm fine with it. Its just the source code I can't provide.
Btw, I've opened a ticket in visualstudiocommunity because the intellisense in visual studio 2019 with our project is really bad,
I'm not sure if it's related, because it is tsserver.js incriminated and not tsc.js. Just for you to know all the facts.
Also, do you think if we split this project into multiple project references, there could be room for significative compilation time improvements ? It's not an easy task to do (a lot of circular references to fix), so I prefer to ask for your opinion first.
amcasey commentedon Dec 3, 2019
Ikaer Thanks! If I come up with a solution with that level of information exposure, I'll let you know. Unfortunately, the default trace includes string contents and the compiler's strings are your source code. 😢
Thanks for linking the ticket - I wouldn't have connected the two otherwise. Yes, it's probably the same issue since tsc and tsserver share most of their code. I'll try to confirm though.
I can't make any guarantees, but project references were specifically created to speed up checking of large code bases and have proven effective for other large projects (including TypeScript itself). So, yes, I would expect moving to project references to help with both compilation time and language service (i.e. IntelliSense) performance. If you go ahead, please keep me posted.
amcasey commentedon Jan 31, 2020
As part of another investigation, I found these perf regressions between 3.5 and 3.7:
mui/material-ui#19113 (comment)
Ikaer commentedon Feb 1, 2020
Andrew Casey (@amcasey) This is very interesting.
Our project is using a homemade framework for designing and styling components which is inspired by React and there is an heavy use of CSSStyleDeclaration and methods which look like what you called "thunked CSS properties"
Here is a sample of code you can find a lot in our project:
A difference however is that we are not using the package https://www.npmjs.com/package/csstype for css, we directly use CSSStyleDeclaration from lib.dom.ts which is just a bunch of property:string for most of it
amcasey commentedon Feb 3, 2020
Ikaer I believe that makes yours at least the third project we've seen having performance problems with that sort of pattern. I think we're going to step back and think about that scenario as a whole (not a quick process, unfortunately).
amcasey commentedon Feb 7, 2020
Ikaer Do you want to try the latest nightly build and let me know if it's any better? It sounds like your project has similarities to material-ui and we've recently made several performance improvements that have gotten us back to roughly TS 3.5 speeds.
Ikaer commentedon Feb 8, 2020
Andrew Casey (@amcasey) Yep there is definitely significant improvements with this build. We go down from 4.30 min to 1.40 min in full mode (no change in incremental, around 7 seconds)
Check time go down from 253.29s to 74.43s
attached: extended diagnostics and prof-process of isolates
extendedDiagnostics_prof-process_3.7.4.zip
extendedDiagnostics_prof-process_3.8.0next.zip
amcasey commentedon Feb 10, 2020
Ikaer does that mean you're back to 3.5.2 perf?
Ikaer commentedon Feb 10, 2020
Andrew Casey (@amcasey) yep and with a little gain, in the O.P, I was at least above 2min of compilation with 3.5, now I'm under 2 minutes, so yeah, We are back to 3.5.2 perf and even better.
amcasey commentedon Feb 10, 2020
Cool. For bookkeeping purposes, I'm going to close this issue but, obviously, we're still focused on perf. It sounds like the changes we make for material-ui and styled-components are likely to benefit your project as well, so I'd keep an eye on those.