Debugging long check times with TypeScript?

[AnyhowStep]

TypeScript Version: 2.9.0-dev.20180516

I have a toy project I've been working on and, in general, it takes about 50-60s to type check, and, sometimes, I get out of memory exceptions.

> node --max-old-space-size=8192 ./node_modules/typescript/lib/tsc.js --noEmit --noErrorTruncation --diagnostics

Files:            166
Lines:          57676
Nodes:         312303
Identifiers:   108968
Symbols:       158671
Types:          75995
Memory used: 1354006K
I/O read:       0.04s
I/O write:      0.00s
Parse time:     2.18s
Bind time:      0.90s
Check time:    60.80s
Emit time:      0.00s
Total time:    63.89s

I'm unsure if such wait times are normal or if it's just me.

I'm finally writing this question because I added one method to a class and it caused tsc to not terminate. I've waited over twenty minutes and it's still not ending.

If I comment out the method I just added, I can get tsc to terminate without errors.

---

The code in question is here

(Ignore that the folder is called declaration-v2, I never got around to renaming it)

---

Is there a way to get tsc to output what phase of the check it's at and what files it's reading as it checks, etc.?

Something like,

Reading file X.ts
Checking class A
Checking class B
Reading file Y.ts
Checking class C

--listFiles isn't particularly helpful for this case because it outputs that at the end, and tsc won't even terminate at the moment.

Or are there other guidelines I can use to debug long check times?

I understand the type system is very complex but I feel my productivity has been taking a huge hit when I can barely get IntelliSense and type checking to work with VS code, and Atom with atom-typescript just crashes, (I assume it's related to the long check times) and have to resort to using the terminal every once in a while to sanity check my code.

---

I understand that this issues page is not for questions like these but I've found the answers on StackOverflow unsatisfactory, and sitting here waiting for tsc to terminate is kind of frustrating.

I'm unsure if I can even reduce this to a minimal example because the project is huge. But at least I've found the method to comment/uncomment to reproduce the issue.

---

[EDIT]

This is also the first time I've encountered this problem. I'd actually be relieved if I could get an out of memory exception right now. Memory usage is actually surprisingly low. But it's just not terminating...

Maybe an infinite loop?

[AnyhowStep]

After much effort, I finally shifted around enough code that the compiler terminated. I would still like to know if there's anything I can do to debug these long compile times, though.

[RyanCavanaugh]

60s+ compile times generally indicate a bug on our side unless you have truly huge amounts of code. Is the linked repo sufficient to reproduce the issue, and if so what are the steps to do so?

[AnyhowStep]

Yeah, the linked repo is enough to reproduce the issue.

I guess just,

1. Download the repo
2. npm install
3. npm run build (Which really just runs tsc -d --diagnostics)

I just tried building again and got 67.58s

Files:           175
Lines:         59137
Nodes:        318532
Identifiers:  110994
Symbols:      175785
Types:         86670
Memory used: 584460K
I/O read:      0.05s
I/O write:     0.17s
Parse time:    1.72s
Bind time:     0.73s
Check time:   39.40s
Emit time:    25.74s
Total time:   67.58s

I'm not sure if the project can be considered super-huge; it's certainly smaller than the TypeScript project, itself.

---

[EDIT]

That's weird. The check time above is 39.40s. I didn't take any special steps to reduce the check/compile time. I only shifted around enough code to get tsc to terminate at that point in time.

I just checked a bunch of previous commits, too. And it seems like all the check times are now 20-30s...

Now I look foolish =/ I was getting 60s check times for at least a week, and it all goes away 3 days after I submit a question. I didn't even restart my computer, or anything (for the past week).

My original problem with tsc not terminating was with this, commit 7ba70257c7edacbca2b3cd9b105f706b4b4a27d4

It looks like it still causes tsc to not terminate if uncommented, though.

1. Download the repo
2. Checkout 7ba70257c7edacbca2b3cd9b105f706b4b4a27d4
3. Open src/main/declaration-v2/table/table.ts
4. Line 11, uncomment the AddUniqueKeyDelegate import
5. Line 230, uncomment the addUniqueKey<>() method
6. npm run install
7. npm run build (Just runs tsc -d)

[AnyhowStep]

It seems like using the generated .d.ts files in another project will also cause very long check times, though.

Initially, a personal project of mine had 2216 files, and took 732.01s to check.

Before removing @anyhowstep/data-validation
Files:          2216
Lines:        357150
Nodes:       1748973
Identifiers:  200544
Symbols:      552752
Types:        145115
Memory used: 653146K
I/O read:      0.17s
I/O write:     0.00s
Parse time:    7.26s
Bind time:     2.16s
Check time:  732.01s
Emit time:     0.00s
Total time:  741.42s

I assumed it must be the sheer number of files. So...

After removing @anyhowstep/data-validation
Files:           244
Lines:        325625
Nodes:       1439619
Identifiers:  126281
Symbols:      477558
Types:        121826
Memory used: 576804K
I/O read:      0.04s
I/O write:     0.00s
Parse time:    4.05s
Bind time:     1.21s
Check time:  501.18s
Emit time:     0.00s
Total time:  506.44s

After removing about 1800 files, check times only improved by about 230s. It still took 501.18s to check.

I thought I might need to reboot my computer,

After rebooting
Files:           244
Lines:        325625
Nodes:       1439619
Identifiers:  126281
Symbols:      477558
Types:        121826
Memory used: 576871K
I/O read:      1.04s
I/O write:     0.00s
Parse time:    4.38s
Bind time:     1.10s
Check time:  357.48s
Emit time:     0.00s
Total time:  362.97s

Still pretty long, 357.48s, makes any kind of code completion and type inference useless.

---

I decided to modify the include field of tsconfig.json to not include files that use the SelectBuilder class of the linked repository

Files:            239
Lines:         325304
Nodes:        1437953
Identifiers:   125751
Symbols:       470499
Types:         119507
Memory used: 1094144K
I/O read:       0.04s
I/O write:      0.00s
Parse time:     4.03s
Bind time:      1.45s
Check time:    39.58s
Emit time:      0.00s
Total time:    45.05s

Check times improved a lot to 39.58s, with 239 files

---

I added just one file to the check, which was using SelectBuilder

Files:            240
Lines:         325404
Nodes:        1438311
Identifiers:   125864
Symbols:       475666
Types:         121228
Memory used: 1099974K
I/O read:       0.03s
I/O write:      0.00s
Parse time:     2.93s
Bind time:      1.19s
Check time:   497.42s
Emit time:      0.00s
Total time:   501.54s

497.42s, with 240 files

The one usage of SelectBuilder looks like this,

const reading = await this.db.from(t.readingComponent)
    .whereIsEqual(c => c.readingId, readingId)
    .orderBy(c => [
        [c.sortOrder, true]
    ])
    .leftJoinUsing(t.furiganaReadingComponent, c => [c.readingComponentId])
    .leftJoinUsing(t.ideogramReadingComponent, c => [c.readingComponent.readingComponentId])
    .leftJoinUsing(t.ideogram, c => [c.ideogramReadingComponent.ideogramId])
    .selectAll()
    .fetchAll()
    .then((components) => {
        //Using Promise.all() because I planned to add another `component` that would require a database call to compute the furigana and logogram
        return Promise.all(
            components.map((component) => {
                if (component.furiganaReadingComponent != undefined) {
                    return {
                        furigana : component.furiganaReadingComponent.furigana,
                    };
                }

                if (
                    component.ideogramReadingComponent != undefined &&
                    component.ideogram != undefined
                ) {
                    return {
                        furigana : component.ideogramReadingComponent.furigana,
                        logogram : component.ideogram.logogram,
                    };
                }

                throw new Error(`Unknown reading component ${component.readingComponent.readingComponentId}`);
            })
        );
    });

---

I've tried commenting out the then() part and got,

Files:            240
Lines:         325404
Nodes:        1438214
Identifiers:   125832
Symbols:       474799
Types:         120989
Memory used: 1030886K
I/O read:       0.04s
I/O write:      0.00s
Parse time:     3.64s
Bind time:      1.26s
Check time:   188.99s
Emit time:      0.00s
Total time:   193.89s

[AnyhowStep]

I made the usage,

const reading = await this.db.from(t.readingComponent)
    .whereIsEqual(c => c.readingId, readingId)
    .orderBy(c => [
        [c.sortOrder, true]
    ])
    .selectAll()
    .fetchAll()

And got,

Files:           244
Lines:        325573
Nodes:       1439136
Identifiers:  126131
Symbols:      472478
Types:        120145
Memory used: 972240K
I/O read:      0.03s
I/O write:     0.00s
Parse time:    3.33s
Bind time:     1.60s
Check time:   30.75s
Emit time:     0.00s
Total time:   35.69s

---

With the following,

const reading = await this.db.from(t.readingComponent)
    .whereIsEqual(c => c.readingId, readingId)
    .orderBy(c => [
        [c.sortOrder, true]
    ])
    .leftJoinUsing(t.furiganaReadingComponent, c => [c.readingComponentId])
    .leftJoinUsing(t.ideogramReadingComponent, c => [c.readingComponent.readingComponentId])
    //.leftJoinUsing(t.ideogram, c => [c.ideogramReadingComponent.ideogramId])
    .selectAll()
    .fetchAll()

Files:           244
Lines:        325573
Nodes:       1439173
Identifiers:  126144
Symbols:      474470
Types:        120883
Memory used: 576553K
I/O read:      0.02s
I/O write:     0.00s
Parse time:    3.27s
Bind time:     2.94s
Check time:   42.02s
Emit time:     0.00s
Total time:   48.22s

With the following,

const reading = await this.db.from(t.readingComponent)
    .whereIsEqual(c => c.readingId, readingId)
    .orderBy(c => [
        [c.sortOrder, true]
    ])
    .leftJoinUsing(t.furiganaReadingComponent, c => [c.readingComponentId])
    .leftJoinUsing(t.ideogramReadingComponent, c => [c.readingComponent.readingComponentId])
    .leftJoinUsing(t.ideogram, c => [c.ideogramReadingComponent.ideogramId])
    .selectAll()
    .fetchAll()

Files:           244
Lines:        325573
Nodes:       1439193
Identifiers:  126151
Symbols:      475742
Types:        121309
Memory used: 565708K
I/O read:      0.04s
I/O write:     0.00s
Parse time:    4.09s
Bind time:     1.35s
Check time:  168.49s
Emit time:     0.00s
Total time:  173.93s

A spike of about 130s with one line of code.

---

It seems like the code for SelectBuilder.leftJoinUsing() has a type that slows down tsc

I tried to simplify it,

leftJoinUsing<ToTableT extends AnyAliasedTable, FromDelegateT extends JoinFromDelegate<DataT["joins"]>>(this: SelectBuilder<{
        hasSelect: any;
        hasFrom: true;
        hasUnion: any;
        joins: any;
        selects: any;
        aggregateDelegate: any;
        hasParentJoins: any;
        parentJoins: any;
    }>, toTable: ToTableT, fromDelegate: FromDelegateT): (
        //Error extends JoinCollectionUtil.LeftJoinUsing<SelectBuilder<DataT>, ToTableT, FromDelegateT> ?
            //JoinCollectionUtil.LeftJoinUsing<SelectBuilder<DataT>, ToTableT, FromDelegateT> :
            SelectBuilder<{
                readonly [key in keyof this["data"]] : (
                    key extends "joins" ?
                    TupleWPush<
                        AnyJoin,
                        this["data"]["joins"],
                        Join<ToTableT, ToTableT["columns"], true>
                    > :
                    this["data"][key]
                )
            }>
    );

This gave me a 40s improvement

Files:           244
Lines:        325588
Nodes:       1439195
Identifiers:  126141
Symbols:      474627
Types:        120561
Memory used: 565635K
I/O read:      0.03s
I/O write:     0.00s
Parse time:    3.03s
Bind time:     1.16s
Check time:   94.35s
Emit time:     0.00s
Total time:   98.54s

[AnyhowStep]

At this point, the only conclusion I have is that the type aliases in my tuple.ts file is what's causing all this slowness.

[AnyhowStep]

I refactored TupleWPush<> to be

export type TupleWPush<WidenT, TupleT extends Tuple<WidenT>, NextT extends WidenT> = (
    {
        [index in TupleKeys<TupleT>] : (
            TupleT[index] extends WidenT ?
                TupleT[index] :
                never
        )
    } &
    {
        [index in TupleNextKey<TupleT>] : (
            NextT extends WidenT ?
                NextT :
                never
        )
    } &
    {
        "0" : (
            TupleT[0] extends WidenT ?
                TupleT[0] :
                never
        ),
    } &
    {
        length : TupleNextLength<TupleT>
    } &
    (
        WidenT[]
    )
);

And it ran in 23.93s!

Files:           244
Lines:        325616
Nodes:       1439276
Identifiers:  126168
Symbols:      460847
Types:        114267
Memory used: 559765K
I/O read:      0.04s
I/O write:     0.00s
Parse time:    2.79s
Bind time:     1.22s
Check time:   23.93s
Emit time:     0.00s
Total time:   27.94s

It was originally,

export type TupleWPush<WidenT, TupleT extends Tuple<WidenT>, NextT extends WidenT> = (
    TupleWiden<TuplePush<TupleT, NextT>, WidenT>
);

Which I suppose is really inefficient.

[AnyhowStep]

@RyanCavanaugh Sorry for all the spam. It's just been a really mentally draining issue for me to debug. I had to use the typed-orm project I wrote across multiple projects before finally being able to isolate the issue.

I don't really know what to do with this issue anymore.

On one hand, the problem is resolved for me, for now. On the other hand, I'm worried I'll encounter something like this again in future.

---

I've always found existing SQL query building libraries very lacking in the structural, and type safety departments. Always needing string literals in queries, or trusting that a type is what it says it is, and trusting that the columns you say exist in the query actually do come out, etc.

TypeScript is my first exposure to a type system that has enabled me to experiment with a query building library that doesn't expose any of those hacks to the user.

It's basically my favourite language at the moment, and I wouldn't even touch JS with a ten-foot pole.

---

I do have a few things that I would like to see in TypeScript after going through this ordeal, though (I am unsure if proposals have been written for them).

None of it's a serious proposal, just throwing some thoughts out there.

• Some kind of native support for Add<T extends number, U extends number> and Sub<T extends number, U extends number> types,

  Add<23, 45> would be the type 68

  Right now, it's being "faked" with this; it has an upper-limit that is however many times I can copy+paste code to implement those types.

  My particular use-case is just pushing elements, and concatenating tuples to tuple types.

• I'm unsure of how to word this next thing that would be cool to see. Something like a "type-function",

type Map<ObjectT, TypeFunctionT> = (
     {
          [key in keyof ObjectT] : TypeFunctionT<ObjectT[key]>
     }
);

type SomeTypeFunction<T> = (
    T extends string ? T : ["T is not a string", T]
);
type X = Map<
    {
        field0 : "a string",
        field1 : ["not", "a", "string"]
    },
    SomeTypeFunction //As far as I know, there's no way to do this but to copy-paste code around
>

I have generic types that map one type to another quite often in my personal projects. I see myself copy-pasting the same mapping boilerplate code every now and then.

• Some kind of compiler flag that displays how much time was spent on checking each data type?

If I had seen that TupleWPush<> was contributing the most amount of time to the type checking process, I would have immediately tried to find a way to make the type declaration more efficient.

But I don't know how feasible such a thing is.

---

Should this issue be closed? Or should I leave it open?