Skip to content

Only use resolutionStart when pushing resolution stack #58824

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

Draft
wants to merge 3 commits into
base: main
Choose a base branch
from

Conversation

jakebailey
Copy link
Member

@jakebailey jakebailey commented Jun 10, 2024

Fixes #58805

#58337 resets the stack by moving its start up temporarily. However, there are other parts of the checker other than the push/pop circular error code which rely on the stack. It looks like for #58805, isResolvingReturnTypeOfSignature in particular stops knowing that a particular return type is being resolved, causing us to start doing extra work that won't go anywhere.

"Fix" this by always using the full stack for these non-circularity-checking stack users.

To make this more clear, the second commit refactors the code a bit into clear functions that show which do and don't use the full stack.

Perhaps this isn't the right fix; this passes all tests, but maybe we shouldn't be using the stack for anything but circularity checking in push/pop anyway. That's a more invasive change.

@typescript-bot typescript-bot added Author: Team For Uncommitted Bug PR for untriaged, rejected, closed or missing bug labels Jun 10, 2024
@jakebailey
Copy link
Member Author

@typescript-bot test it
@typescript-bot pack this

@typescript-bot
Copy link
Collaborator

typescript-bot commented Jun 10, 2024

Starting jobs; this comment will be updated as builds start and complete.

Command Status Results
test top400 ✅ Started ✅ Results
user test this ✅ Started ✅ Results
run dt ✅ Started ✅ Results
perf test this faster ✅ Started 👀 Results
pack this ✅ Started ✅ Results

@typescript-bot
Copy link
Collaborator

typescript-bot commented Jun 10, 2024

Hey @jakebailey, I've packed this into an installable tgz. You can install it for testing by referencing it in your package.json like so:

{
    "devDependencies": {
        "typescript": "https://typescript.visualstudio.com/cf7ac146-d525-443c-b23c-0d58337efebc/_apis/build/builds/162158/artifacts?artifactName=tgz&fileId=5467C79554455AB6B7A3891F7AEEC985DDCEC30BC2488FAF842EEF0088B3DA1E02&fileName=/typescript-5.6.0-insiders.20240610.tgz"
    }
}

and then running npm install.


There is also a playground for this build and an npm module you can use via "typescript": "npm:@typescript-deploys/[email protected]".;

@typescript-bot
Copy link
Collaborator

Hey @jakebailey, the results of running the DT tests are ready.

Everything looks the same!

You can check the log here.

@typescript-bot
Copy link
Collaborator

@jakebailey Here are the results of running the user tests with tsc comparing main and refs/pull/58824/merge:

Everything looks good!

@typescript-bot
Copy link
Collaborator

@jakebailey
The results of the perf run you requested are in!

Here they are:

tsc

Comparison Report - baseline..pr
Metric baseline pr Delta Best Worst p-value
Compiler-Unions - node (v18.15.0, x64)
Errors 30 30 ~ ~ ~ p=1.000 n=6
Symbols 62,153 62,153 ~ ~ ~ p=1.000 n=6
Types 50,242 50,242 ~ ~ ~ p=1.000 n=6
Memory used 193,006k (± 0.74%) 193,532k (± 0.97%) ~ 192,289k 196,079k p=0.575 n=6
Parse Time 1.31s (± 0.57%) 1.30s (± 0.76%) ~ 1.29s 1.31s p=0.109 n=6
Bind Time 0.72s 0.72s ~ ~ ~ p=1.000 n=6
Check Time 9.64s (± 0.55%) 9.55s (± 0.59%) -0.09s (- 0.93%) 9.47s 9.64s p=0.020 n=6
Emit Time 2.76s (± 1.06%) 2.76s (± 0.71%) ~ 2.73s 2.78s p=0.935 n=6
Total Time 14.43s (± 0.35%) 14.33s (± 0.30%) -0.10s (- 0.68%) 14.28s 14.41s p=0.020 n=6
angular-1 - node (v18.15.0, x64)
Errors 5 5 ~ ~ ~ p=1.000 n=6
Symbols 944,109 943,959 -150 (- 0.02%) ~ ~ p=0.001 n=6
Types 407,049 407,029 -20 (- 0.00%) ~ ~ p=0.001 n=6
Memory used 1,222,225k (± 0.00%) 1,222,184k (± 0.00%) ~ 1,222,151k 1,222,233k p=0.199 n=6
Parse Time 6.77s (± 0.77%) 6.81s (± 0.65%) ~ 6.76s 6.88s p=0.199 n=6
Bind Time 1.88s (± 0.62%) 1.88s (± 0.43%) ~ 1.87s 1.89s p=1.000 n=6
Check Time 31.31s (± 0.18%) 31.32s (± 0.13%) ~ 31.27s 31.38s p=0.936 n=6
Emit Time 15.33s (± 0.17%) 15.30s (± 0.44%) ~ 15.20s 15.38s p=0.748 n=6
Total Time 55.29s (± 0.15%) 55.30s (± 0.22%) ~ 55.13s 55.45s p=0.810 n=6
mui-docs - node (v18.15.0, x64)
Errors 5 5 ~ ~ ~ p=1.000 n=6
Symbols 2,061,575 2,061,575 ~ ~ ~ p=1.000 n=6
Types 905,189 905,189 ~ ~ ~ p=1.000 n=6
Memory used 2,071,941k (± 0.00%) 2,071,943k (± 0.00%) ~ 2,071,785k 2,071,999k p=0.230 n=6
Parse Time 6.83s (± 0.28%) 6.84s (± 0.33%) ~ 6.80s 6.86s p=0.328 n=6
Bind Time 2.30s (± 0.36%) 2.31s (± 0.51%) ~ 2.30s 2.33s p=0.077 n=6
Check Time 69.92s (± 0.33%) 69.98s (± 0.50%) ~ 69.60s 70.47s p=1.000 n=6
Emit Time 0.14s (± 3.60%) 0.14s ~ ~ ~ p=0.174 n=6
Total Time 79.19s (± 0.28%) 79.26s (± 0.46%) ~ 78.85s 79.77s p=0.873 n=6
self-build-src - node (v18.15.0, x64)
Errors 0 0 ~ ~ ~ p=1.000 n=6
Symbols 1,230,424 1,230,428 +4 (+ 0.00%) ~ ~ p=0.001 n=6
Types 261,178 261,179 +1 (+ 0.00%) ~ ~ p=0.001 n=6
Memory used 2,351,511k (± 0.05%) 2,351,541k (± 0.05%) ~ 2,349,991k 2,353,599k p=0.936 n=6
Parse Time 4.98s (± 1.38%) 4.97s (± 0.77%) ~ 4.92s 5.00s p=0.873 n=6
Bind Time 1.90s (± 0.43%) 1.90s (± 0.92%) ~ 1.87s 1.91s p=0.730 n=6
Check Time 34.08s (± 0.23%) 34.08s (± 0.23%) ~ 34.01s 34.21s p=0.748 n=6
Emit Time 2.65s (± 3.75%) 2.64s (± 2.46%) ~ 2.57s 2.71s p=0.688 n=6
Total Time 43.63s (± 0.40%) 43.61s (± 0.23%) ~ 43.51s 43.75s p=0.810 n=6
self-build-src-public-api - node (v18.15.0, x64)
Errors 0 0 ~ ~ ~ p=1.000 n=6
Symbols 1,230,424 1,230,428 +4 (+ 0.00%) ~ ~ p=0.001 n=6
Types 261,178 261,179 +1 (+ 0.00%) ~ ~ p=0.001 n=6
Memory used 2,503,829k (± 3.35%) 2,428,341k (± 0.03%) ~ 2,427,014k 2,429,250k p=0.689 n=6
Parse Time 6.22s (± 0.54%) 6.24s (± 1.27%) ~ 6.11s 6.31s p=0.423 n=6
Bind Time 2.02s (± 0.85%) 2.00s (± 0.75%) ~ 1.99s 2.03s p=0.138 n=6
Check Time 40.57s (± 0.30%) 40.62s (± 0.32%) ~ 40.44s 40.80s p=0.521 n=6
Emit Time 3.14s (± 4.11%) 3.12s (± 2.74%) ~ 3.01s 3.27s p=0.689 n=6
Total Time 51.98s (± 0.39%) 52.01s (± 0.39%) ~ 51.85s 52.34s p=0.810 n=6
self-compiler - node (v18.15.0, x64)
Errors 0 0 ~ ~ ~ p=1.000 n=6
Symbols 259,181 259,185 +4 (+ 0.00%) ~ ~ p=0.001 n=6
Types 105,173 105,174 +1 (+ 0.00%) ~ ~ p=0.001 n=6
Memory used 428,784k (± 0.00%) 428,895k (± 0.02%) +112k (+ 0.03%) 428,835k 429,036k p=0.005 n=6
Parse Time 4.07s (± 0.40%) 4.07s (± 0.63%) ~ 4.04s 4.10s p=0.685 n=6
Bind Time 1.63s (± 1.42%) 1.61s (± 1.16%) ~ 1.59s 1.64s p=0.331 n=6
Check Time 22.29s (± 0.23%) 22.27s (± 0.46%) ~ 22.17s 22.41s p=0.423 n=6
Emit Time 1.72s (± 1.02%) 1.75s (± 0.84%) +0.02s (+ 1.45%) 1.73s 1.77s p=0.035 n=6
Total Time 29.71s (± 0.14%) 29.70s (± 0.31%) ~ 29.59s 29.84s p=0.748 n=6
ts-pre-modules - node (v18.15.0, x64)
Errors 35 35 ~ ~ ~ p=1.000 n=6
Symbols 224,565 224,565 ~ ~ ~ p=1.000 n=6
Types 93,734 93,734 ~ ~ ~ p=1.000 n=6
Memory used 369,737k (± 0.02%) 369,783k (± 0.02%) ~ 369,649k 369,877k p=0.298 n=6
Parse Time 2.79s (± 0.29%) 2.79s (± 0.64%) ~ 2.77s 2.82s p=1.000 n=6
Bind Time 1.59s (± 1.05%) 1.59s (± 1.01%) ~ 1.57s 1.61s p=0.935 n=6
Check Time 15.73s (± 0.33%) 15.74s (± 0.54%) ~ 15.63s 15.86s p=0.872 n=6
Emit Time 0.00s 0.00s ~ ~ ~ p=1.000 n=6
Total Time 20.10s (± 0.26%) 20.12s (± 0.47%) ~ 20.01s 20.26s p=0.748 n=6
vscode - node (v18.15.0, x64)
Errors 0 0 ~ ~ ~ p=1.000 n=6
Symbols 2,852,851 2,852,847 -4 (- 0.00%) ~ ~ p=0.001 n=6
Types 967,821 967,819 -2 (- 0.00%) ~ ~ p=0.001 n=6
Memory used 3,024,859k (± 0.00%) 3,024,817k (± 0.00%) ~ 3,024,739k 3,024,882k p=0.335 n=6
Parse Time 13.85s (± 0.19%) 13.84s (± 0.34%) ~ 13.78s 13.89s p=0.747 n=6
Bind Time 4.21s (± 2.01%) 4.24s (± 2.47%) ~ 4.16s 4.38s p=0.867 n=6
Check Time 75.58s (± 2.78%) 74.43s (± 1.94%) ~ 73.58s 77.33s p=0.521 n=6
Emit Time 22.24s (± 8.41%) 23.14s (± 6.38%) ~ 20.17s 23.93s p=1.000 n=6
Total Time 115.88s (± 0.27%) 115.65s (± 0.36%) ~ 115.13s 116.39s p=0.230 n=6
webpack - node (v18.15.0, x64)
Errors 0 0 ~ ~ ~ p=1.000 n=6
Symbols 266,899 266,899 ~ ~ ~ p=1.000 n=6
Types 108,686 108,686 ~ ~ ~ p=1.000 n=6
Memory used 412,038k (± 0.01%) 412,029k (± 0.02%) ~ 411,942k 412,119k p=0.810 n=6
Parse Time 4.75s (± 1.16%) 4.77s (± 1.03%) ~ 4.73s 4.85s p=0.624 n=6
Bind Time 2.05s (± 0.60%) 2.05s (± 0.53%) ~ 2.04s 2.07s p=0.487 n=6
Check Time 21.06s (± 0.29%) 21.14s (± 0.24%) +0.08s (+ 0.36%) 21.04s 21.19s p=0.024 n=6
Emit Time 0.00s 0.00s ~ ~ ~ p=1.000 n=6
Total Time 27.87s (± 0.35%) 27.96s (± 0.30%) ~ 27.81s 28.06s p=0.064 n=6
xstate-main - node (v18.15.0, x64)
Errors 0 0 ~ ~ ~ p=1.000 n=6
Symbols 526,436 526,271 -165 (- 0.03%) ~ ~ p=0.001 n=6
Types 179,425 179,401 -24 (- 0.01%) ~ ~ p=0.001 n=6
Memory used 464,174k (± 0.07%) 463,952k (± 0.08%) ~ 463,483k 464,358k p=0.298 n=6
Parse Time 3.16s (± 0.84%) 3.15s (± 0.79%) ~ 3.12s 3.18s p=0.685 n=6
Bind Time 1.19s (± 0.69%) 1.18s (± 0.35%) ~ 1.18s 1.19s p=0.248 n=6
Check Time 18.09s (± 0.86%) 18.15s (± 0.80%) ~ 17.96s 18.39s p=0.688 n=6
Emit Time 0.00s 0.00s (±244.70%) ~ 0.00s 0.02s p=0.405 n=6
Total Time 22.43s (± 0.74%) 22.48s (± 0.61%) ~ 22.29s 22.69s p=0.575 n=6
System info unknown
Hosts
  • node (v18.15.0, x64)
Scenarios
  • Compiler-Unions - node (v18.15.0, x64)
  • angular-1 - node (v18.15.0, x64)
  • mui-docs - node (v18.15.0, x64)
  • self-build-src - node (v18.15.0, x64)
  • self-build-src-public-api - node (v18.15.0, x64)
  • self-compiler - node (v18.15.0, x64)
  • ts-pre-modules - node (v18.15.0, x64)
  • vscode - node (v18.15.0, x64)
  • webpack - node (v18.15.0, x64)
  • xstate-main - node (v18.15.0, x64)
Benchmark Name Iterations
Current pr 6
Baseline baseline 6

Developer Information:

Download Benchmarks

@typescript-bot
Copy link
Collaborator

@jakebailey Here are the results of running the top 400 repos with tsc comparing main and refs/pull/58824/merge:

Everything looks good!

@DanielRosenwasser
Copy link
Member

The perf tests seem to have a decent amount of variance - can you give a clue on what sorts of savings you're seeing specifically on arktype (the report in #58805)?

@jakebailey
Copy link
Member Author

Just finished running this:

Benchmark 1: 5.4.5
  Time (mean ± σ):     18.920 s ±  0.045 s    [User: 18.532 s, System: 0.300 s]
  Range (min … max):   18.834 s … 18.980 s    20 runs

Benchmark 2: main
  Time (mean ± σ):     20.088 s ±  0.031 s    [User: 19.679 s, System: 0.320 s]
  Range (min … max):   20.043 s … 20.146 s    20 runs

Benchmark 3: PR
  Time (mean ± σ):     19.012 s ±  0.056 s    [User: 18.625 s, System: 0.299 s]
  Range (min … max):   18.822 s … 19.081 s    20 runs

Summary
  5.4.5 ran
    1.00 ± 0.00 times faster than PR
    1.06 ± 0.00 times faster than main

@ssalbdivad
Copy link

@jakebailey @DanielRosenwasser Awesome, this seems to totally address the regression on my end:

5.4.5:
{
    "checkTime": 8.74,
    "types": 479804,
    "instantiations": 2612248
}


5.5.1-rc
{
    "checkTime": 9.92,
    "types": 514330,
    "instantiations": 2812921
}

fix-58805
{
    "checkTime": 8.66,
    "types": 483064,
    "instantiations": 2622889
}

Thanks for taking this so seriously. It's ridiculously impressive how well your team integrates real-world perf feedback from across the ecosystem into your dev process.

@ahejlsberg
Copy link
Member

Hmm, I'm not 100% sure about this one. The whole idea with resolutionStart is that we can temporarily suspend some ongoing work and make it appear it isn't actually in process. But with this change it will appear to be in process sometimes. We're basically letting a subset of potential ghost errors back in, specifically in cases that depend on isInResolutionStack. Those cases aren't too common, but this will definitely make them more unpredictable.

@ssalbdivad
Copy link

ssalbdivad commented Jun 11, 2024

@jakebailey Do we know what led to this change impacting ArkType more than the other repos that were tested?

If it stems from some obscure pattern that is unlikely to exist in other projects, then identifying it will (hopefully) give me a chance to refactor the affected code.

If it stems from something more ubiquitous, it may be worth weighing the more consistent errors @ahejlsberg mentioned against the perf cost if there is no way to provide both.

@jakebailey
Copy link
Member Author

jakebailey commented Jun 11, 2024

I didn't have time to debug further, but my impression is that there's something very specific to signatures here; the new stack resetting happens as a part of resolving a signature, but this check is checking for a resolving signature, more or less. Makes me think that we're pushing onto the stack then shortly after, resetting it such that we forget that we're resolving. (Which is probably clear given the fact that it works once we look past the new start.)

So, it sort of feels it may be the case that there's some way to avoid that.

I plan to look harder when I have a little more time.

@jakebailey jakebailey marked this pull request as draft June 11, 2024 15:01
@jakebailey
Copy link
Member Author

jakebailey commented Jun 11, 2024

FWIW this regression is measurable with ts-perf (not surprising); 5.4 vs main:

┌─────────────┬────────────────────┬────────────────────┬────────────────────┬──────────┬──────────┬─────────────┐
│ Project     │           Baseline │            Current │              Delta │     Best │    Worst │     p-value │
╞═════════════╧════════════════════╧════════════════════╧════════════════════╧══════════╧══════════╧═════════════╡
│ arktype - node (v18.15.0, x64)                                                                                 │
├─────────────┬────────────────────┬────────────────────┬────────────────────┬──────────┬──────────┬─────────────┤
│ Errors      │                  0 │                  0 │                  ~ │        ~ │        ~ │ p=1.000 n=6 │
│ Symbols     │          1,033,514 │          1,058,345 │  +24,831 (+ 2.40%) │        ~ │        ~ │ p=0.001 n=6 │
│ Types       │            477,728 │            504,614 │  +26,886 (+ 5.63%) │        ~ │        ~ │ p=0.001 n=6 │
│ Memory used │ 816,991k (± 0.00%) │ 847,235k (± 0.02%) │ +30,243k (+ 3.70%) │ 847,106k │ 847,534k │ p=0.005 n=6 │
├─────────────┼────────────────────┼────────────────────┼────────────────────┼──────────┼──────────┼─────────────┤
│ Parse Time  │    1.99s (± 0.20%) │    1.96s (± 0.32%) │   -0.03s (- 1.59%) │    1.95s │    1.97s │ p=0.003 n=6 │
│ Bind Time   │    0.82s (± 1.20%) │    0.81s (± 0.50%) │                  ~ │    0.81s │    0.82s │ p=0.213 n=6 │
│ Check Time  │   22.02s (± 0.31%) │   23.43s (± 0.36%) │   +1.40s (+ 6.37%) │   23.34s │   23.58s │ p=0.005 n=6 │
│ Emit Time   │              0.00s │              0.00s │                  ~ │        ~ │        ~ │ p=1.000 n=6 │
├─────────────┼────────────────────┼────────────────────┼────────────────────┼──────────┼──────────┼─────────────┤
│ Total Time  │   24.83s (± 0.29%) │   26.20s (± 0.32%) │   +1.37s (+ 5.50%) │   26.10s │   26.35s │ p=0.004 n=6 │
└─────────────┴────────────────────┴────────────────────┴────────────────────┴──────────┴──────────┴─────────────┘

(via microsoft/typescript-benchmarking#73)

@ssalbdivad
Copy link

Any additional thoughts on either potential plans to address this or ideas about what the culprit may be in the ArkType repo that's causing the performance issues? Is there maybe a broader suite of repos that can be checked for perf changes stemming from this change?

As mentioned, I'm happy to refactor some internal types if need be to accommodate these changes, but I don't have very good intuitions about what code is most likely responsible for the delta.

@DanielRosenwasser
Copy link
Member

Any additional thoughts on either potential plans to address this or ideas about what the culprit may be in the ArkType repo that's causing the performance issues?

Jake might, but the only advice I have at the moment is to try @typescript/analyze-trace to figure out specific statements/expressions that may be taking a long time.

@ssalbdivad
Copy link

@DanielRosenwasser Would getting some more data on the broader perf impact of that change be valuable so that it's clear the regression that occurred in ArkType is a clear outlier?

From what I understood, the core fix was already an edge case and Jake's PR (which had negligible overhead) apparently still addresses the majority of those cases. I understand wanting to guarantee ideal behavior as often as possible, but a very noticeable performance hit that could potentially occur in other repos as well seems like a hefty price to pay in this case for that extra bit of certainty.

@jakebailey
Copy link
Member Author

I am continuing to look at this; doing some extra tracing of the code involved here to try and compare before/after.

@jakebailey
Copy link
Member Author

jakebailey commented Jun 13, 2024

I've instrumented some basic tracing of the push/pop of signatures and isResolvingReturnTypeOfSignature, and it has pretty much confirmed my suspicion; the stack resetting is perfectly placed to cut off the initial push that we're resolving a particular signature.

Here's an example (not "the" example, but one that can fit in one screenshot):

image

On the left is main, on the right is with #58337 effectively reverted.

We can see that we pushTypeResolution () => hasDomain({}, "b") in getReturnTypeOfSignature for the signature for this node. But then, we drop down into getResolvedSignature, which resets the stack, cutting off that entry. Later calls to isResolvingReturnTypeOfSignature now say that the current signature is not being processed, even though it really is and the stack resetting just happened as a part of that process.

This PR works because it allows isResolvingReturnTypeOfSignature to still see that resolution is in progress for this signature.

If this PR isn't acceptable, then I'm not totally sure what the right fix will be. I was thinking that maybe the stack could only be reset back up until the signature being resolved, but we're resetting in getResolvedSignature, which means that we have a call expression and not the signature (of course), so we can't actually go find the right entry to know where to move the stack start up to.

I also think that using the stack like this for non push-pop circularity checking reasons may itself be the bad thing, but changing that seems challenging.

Maybe the resetting needs to be somewhere other than getResolvedSignature?

Any ideas, people smarter than me? 😄 @ahejlsberg

@jakebailey
Copy link
Member Author

Here is the trace: https://gist.github.com/jakebailey/6718e643e3399316962bd8edf53f4558

If you're looking for "expensive" calls, I would search the "main.txt" for \dms$; these are calls which took more than 50ms, and there are 21 of them on main, but only 8 with the revert. That may help find what specific calls could be changed in arktype itself, maybe.

@jakebailey
Copy link
Member Author

I am however able to recover maybe 50% of the loss by doing what we do for the variance reset and only doing it once; the comment in the code for the getResolvedSignature reset implies that it happens only once, but I don't think it ended up implemented that way.

@mikearnaldi
Copy link

mikearnaldi commented Jun 14, 2024

@DanielRosenwasser Would getting some more data on the broader perf impact of that change be valuable so that it's clear the regression that occurred in ArkType is a clear outlier?

From what I understood, the core fix was already an edge case and Jake's PR (which had negligible overhead) apparently still addresses the majority of those cases. I understand wanting to guarantee ideal behavior as often as possible, but a very noticeable performance hit that could potentially occur in other repos as well seems like a hefty price to pay in this case for that extra bit of certainty.

Unfortunately that's not the case, only Anders PR addressed the bug, we tested the other proposed fixes and they did not work except for small isolated cases. I would not pick perf over correctness

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Author: Team For Uncommitted Bug PR for untriaged, rejected, closed or missing bug
Projects
Status: Needs merge
Development

Successfully merging this pull request may close these issues.

Typescript 5.5 performance regression on arktype
6 participants