microsoft / TypeScript

TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
https://www.typescriptlang.org
Apache License 2.0
100.37k stars 12.4k forks source link

Build watch takes 30x as long as cold build, high transformTime #35729

Closed lingz closed 1 month ago

lingz commented 4 years ago

TypeScript Version: 3.7.3 and 3.4.5

Search Terms: transformTime, Watch, Slow compilation

Code

When building our source code, we can do a cold build in about 25 seconds, but a watch build takes 15 minutes to start on Typescript 3.4.5. On Typescript 3.7.3, the watch time doubles to 30 minutes (60x as slow).

Running extended diagnostics shows that the vast majority of the time (96%) is spent on "transformTime". Is there any way to speed this up, as I do not consider our project too large on the grander scale (600k LOC).

One thing that was causing slow builds that I already fixed and ruled out was the inlined type definitions bug mentioned in #34119, which cut my build time by a third. But even after this, I still get a very slow transformTime.

Files:                  3043
Lines:                637432
Nodes:               2372135
Identifiers:          850259
Symbols:             1167934
Types:                462989
Memory used:        2036527K
I/O Read time:         1.03s
Parse time:            2.81s
Program time:          6.12s
Bind time:             3.05s
Check time:           11.54s
transformTime time:  473.05s
commentTime time:      0.14s
I/O Write time:        0.43s
printTime time:      474.27s
Emit time:           474.27s
Total time:          494.99s

Expected behavior:

Watch build is slightly slower than cold build

Actual behavior:

Watch build is significantly slower

Playground Link:

Related Issues:

sheetalkamat commented 4 years ago

Can you please provide more details on repro. This seems like its taking long time to do declaration emit but I cant be certain.. Did you try running tsc --d --extendedDiagnostics. What do you see then.

lingz commented 4 years ago

@sheetalkamat the above pasted diagnostics is in fact from extendedDiagnostics and declarations emit only as you suggested. Let me know if any other information could help give clues.

sheetalkamat commented 4 years ago

We would need sample code for repro..

weswigham commented 4 years ago

Yeah, definitely going to need to see some sample code - when declaration emit takes a long time, it's usually because some type somewhere was easy to compute, but complicated to serialize. Did you check the sizes (and contents) of your output .d.ts files by compiling with declarations on?

lingz commented 4 years ago

I can't provide the source code unfortunately, but I did a CPU profile, and it seems like almost all the time is spent in GC, and trySymbolTable. I ran a size profile on the generated .d.ts, and they are all small files, almost all the files are only a few lines long (see size profile treemap below)

Screenshot 2019-12-18 at 11 38 54 71001691-b54bfb80-20d5-11ea-9f69-faa5186a614e
lingz commented 4 years ago

Seems like the 1 mil symbols might be what is causing the slowdown. But I'm not sure what is causing such a high number of symbols, perhaps generated types?

Do you have any advice on identifying which files might be causing this high number of symbols?

lingz commented 4 years ago

I've managed to find out the culprit, and reduced the transform time from 473 seconds to 6 seconds.

It turns out it was a recursive type that was used only a few places in our code:

/**
 * The JSON version, without functions, methods, class
 */
export type LitNative = string | number | boolean | undefined | null | void;
export type WithoutFunctions<T> = T extends any
  ? Omit<T, FunctionKeys<Required<T>>>
  : T

export type Serialized<T> = T extends any[]
  ? InnerSerialized<T[number]>[]
  : (T extends LitNative ? T : InnerSerialized<WithoutFunctions<T>>);

type InnerSerialized<T> = {
  [k in keyof T]: T[k] extends any[]
    ? Serialized<T[k][number]>[]
    : Serialized<T[k]>
};

This type Serialized is recursive, and takes an object and gives a version of it without any functions (as if it went through JSON.serialize). It was only used a few places in the code but it was exploding the transformTime.

The way I found it, was after seeing that trySymbolTable was taking up most of the time, I ran the tsc compiler with the chrome inspector, and set a breakpoint on the function. I saw all the function calls were looking up Serialized over and over again. I would speculate that this could be mitigated by some caching in the tsc architecture?

The command I ran (in case it is helpful to others) is:

node --inspect-brk $(which tsc) -p ./tsconfig.json --declaration --emitDeclarationOnly --extendedDiagnostics --declarationDir ~/Temp/declarations/out > ~/Temp/declarations/diagnostics.txt

AnyhowStep commented 4 years ago

Are there functions that are supposed to return Serialized<>? Is the return type of those functions implicit or explicit?

I ask because the return type of a generic function should almost always be explicitly annotated. This goes double for complex recursive types.

I have opened a bunch of issues in the past where emit goes crazy because I did not use an explicit return type annotation on a generic function.

TS is pretty bad at figuring out good emit for generic return types.

jamshally commented 4 years ago

I ran the tsc compiler with the chrome inspector

Hi @lingz - I am running into a similar issue, and trying to follow your debug process. Thanks for providing the command. Could you share a little more info about you managed to find the trySymbolTable function, and then set a breakpoint on it?

lingz commented 4 years ago

Hi @ahrnee , The whole typescript compiler is one flat JS file (on production builds), So just step inside the definition from the chrome terminal and search for the trySymbolTable function.

lingz commented 4 years ago

@AnyhowStep It was always explicit, but nonetheless, still causing this bug to emit.

jrmyio commented 4 years ago

Ran into similar issues with a project that uses https://github.com/mobxjs/mobx-state-tree and managed to fix my issues going from 200s to 13s in watch mode (on initial type check).

In my case I was using exported interfaces instead of types for most of the typings, but not all. This resulted in many of the types (when referenced by other files) being recalculated because there is apparently not much caching going on with typescript types (while there is when you export interfaces). For mobx-state-tree this means using export interface ModelSnapshot extends SnapshotIn<typeof Model>{} and using ModelSnapshot instead of SnapshotIn<typeof Model> directly.

After optimizing some typings from types and inline types to interfaces I went from 200s initial watch time to just 13 seconds while using tsc without watch was always fast and didn't improve much of anything.

I used the same methods as listed above, using tsc --noEmit false --declaration --emitDeclarationOnly --extendedDiagnostics --declarationDir ./declarationsto find the biggest files with windirstat. In these files there were tons of duplicated nested types, one file was as large as 17MB. Because I run typescript with --noEmit via webpack I never knew this was the actual reason for it being so slow.

Just like OP for me "transformTime time" was also taking the longest time. After my changes that value dropped from minutes to just seconds.

ShuiRuTian commented 4 years ago

@lingz Sorry for asking, how does FunctionKeys\<T> implement? It is amazing for me!

kumar303 commented 4 years ago

TL;DR it would be nice to have better diagnostics tools to tell us which exact types are the slowest (and what file / module they come from)

After my own debugging adventure, I tracked down the slowness to a third party library type. Because of that, the above techniques didn't help me discover it. Here was my process, in case it helps someone else.

For context, I was converting an 80k LOC monorepo from Flow to TypeScript. When editing any file during tsc --watch, it was taking 57 seconds to re-compile (every time).

code mod to add @ts-nocheck ```js // I named this ./codemods/transforms/add-ts-nocheck.ts // // I ran it from ./codemods like: // jscodeshift -t ./transforms/add-ts-nocheck.ts ../my-actual-project --extensions=tsx --parser=tsx import { Transform } from "jscodeshift"; /* * Add a @ts-nocheck comment to the top of every file. */ const transform: Transform = function (fileInfo, api) { const filePath = fileInfo.path ?? ""; // I was eliminating types by directory like this: // if (!filePath.startsWith("../my-actual-project/packages/some-package")) { // return null; // } if (filePath.includes("node_modules")) { return null; } const root = api.jscodeshift(fileInfo.source); root.get().node.program.body.unshift("// @ts-nocheck"); return root.toSource(); }; transform.parser = "ts"; export default transform; ```
@types/reakit/index.d.ts ```ts declare module "reakit" { var x: any; export = x; } ```

This brought my watch mode re-compiles down from 57 seconds to 3 seconds ✨ 🌈 πŸ₯‡

I tried narrowing down the exact type in reakit like this:

@types/reakit/index.d.ts ```ts import { Provider, // Tooltip, } from "reakit"; declare module "reakit" { // Replace just this one export: var Tooltip: any; var allExports = { Provider, Tooltip, // Re-add all original exports ... }; export = allExports; export default allExports; } ```

...but I couldn't find a single export that was slow. They were all slow. I guess there is a shared internal type somewhere causing the problem.

If I hadn't gotten lucky and guessed the bad third party lib, I probably would have written a script to override all third party types then re-enable them one by one. I looked for an easier way to do that in TS but couldn't find one.

I was really in the dark here so better diagnostic tools would have been super helpful.

grumd commented 3 years ago

Just wanted to contribute that I get the same situation in my 600k LOC codebase (most of it is JS): image

Just running a typecheck with no emit takes 15 seconds, adding --watch results in it taking 10 minutes.

TS team should really look into making --watch possible without serializing types

kumar303 commented 3 years ago

Just FYI, the new --enableTrace flag (I think that's it?) is documented in https://github.com/microsoft/vscode/pull/110534