Skip to content
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

Cache flow branch label results the same way as flow loop results #41387

Closed
wants to merge 1 commit into from

Conversation

weswigham
Copy link
Member

Fixes #41124

Fundamentally, the underlying issue actually wasn't tied to control flow call nodes, but rather the repeated branch labels produced by the && expressions. As we checked the file, on the first call expression line, we'd check a control flow graph like

image

and then on the second:

image

and so on. The graph of the last call expression line grows linearly with lines, however because no results were cached across invocations (as only branch labels were actually considered, since all the Call nodes are noops), this meant that the actual number of control flow nodes checked across all invocations would grow at a much faster rate than input size. By caching the results at branch label locations (like we already do for loop labels, since we always knew we visit them multiple times), we can avoid this growth in most circumstances. Technically this caching is extraneous in certain edge cases where the full control flow graph is trivially small (so is essentially one label and a Start, so we won't revisit the branch on a future invocation because there won't be a future invocation), but the structure of the control flow graph precludes detecting those scenarios (we can't know if the graph we're looking at is a subset of a large graph or not).

I say we can avoid super-linear growth in most circumstances because there is an exception - ReduceLabel control flow nodes, used for finally block handling, require we bust the cache, as they cause us to mutate other nodes, which has follow on undesirable analysis effects if cached. Discovering this leads me to believe we may have an existing bug with for loops and finally blocks not giving correct results, but as I couldn't come up with a test case, I left the for-loop label result caching logic as-is.

@typescript-bot typescript-bot added Author: Team For Milestone Bug PRs that fix a bug with a specific milestone labels Nov 3, 2020
@weswigham
Copy link
Member Author

@typescript-bot perf test this

@typescript-bot
Copy link
Collaborator

typescript-bot commented Nov 3, 2020

Heya @weswigham, I've started to run the perf test suite on this PR at 6874d65. You can monitor the build here.

Update: The results are in!

@typescript-bot
Copy link
Collaborator

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

Here they are:

Comparison Report - master..41387

Metric master 41387 Delta Best Worst
Angular - node (v10.16.3, x64)
Memory used 344,612k (± 0.02%) 345,161k (± 0.02%) +549k (+ 0.16%) 345,076k 345,335k
Parse Time 2.00s (± 0.48%) 1.99s (± 0.46%) -0.01s (- 0.50%) 1.97s 2.01s
Bind Time 0.84s (± 0.57%) 0.84s (± 0.92%) +0.00s (+ 0.48%) 0.83s 0.86s
Check Time 4.97s (± 0.60%) 4.98s (± 0.41%) +0.01s (+ 0.16%) 4.93s 5.01s
Emit Time 5.35s (± 0.69%) 5.35s (± 0.73%) -0.00s (- 0.04%) 5.29s 5.45s
Total Time 13.16s (± 0.53%) 13.16s (± 0.42%) +0.01s (+ 0.05%) 13.05s 13.29s
Monaco - node (v10.16.3, x64)
Memory used 354,649k (± 0.03%) 355,602k (± 0.02%) +953k (+ 0.27%) 355,509k 355,782k
Parse Time 1.61s (± 0.77%) 1.62s (± 0.51%) +0.00s (+ 0.19%) 1.60s 1.64s
Bind Time 0.73s (± 0.55%) 0.73s (± 1.04%) +0.00s (+ 0.55%) 0.72s 0.76s
Check Time 5.13s (± 0.44%) 5.16s (± 0.41%) +0.02s (+ 0.47%) 5.10s 5.19s
Emit Time 2.82s (± 0.83%) 2.82s (± 0.50%) +0.00s (+ 0.11%) 2.78s 2.85s
Total Time 10.29s (± 0.41%) 10.33s (± 0.26%) +0.03s (+ 0.32%) 10.24s 10.37s
TFS - node (v10.16.3, x64)
Memory used 307,914k (± 0.02%) 309,502k (± 0.03%) +1,589k (+ 0.52%) 309,337k 309,788k
Parse Time 1.24s (± 0.52%) 1.24s (± 0.81%) -0.00s (- 0.08%) 1.21s 1.26s
Bind Time 0.68s (± 1.54%) 0.68s (± 0.54%) +0.01s (+ 0.74%) 0.68s 0.69s
Check Time 4.58s (± 0.54%) 4.63s (± 0.60%) +0.06s (+ 1.22%) 4.56s 4.68s
Emit Time 2.97s (± 0.64%) 2.95s (± 0.97%) -0.02s (- 0.81%) 2.87s 3.00s
Total Time 9.47s (± 0.30%) 9.50s (± 0.59%) +0.03s (+ 0.35%) 9.33s 9.59s
material-ui - node (v10.16.3, x64)
Memory used 489,243k (± 0.02%) 489,246k (± 0.01%) +4k (+ 0.00%) 489,100k 489,390k
Parse Time 2.07s (± 0.58%) 2.07s (± 0.41%) +0.00s (+ 0.10%) 2.05s 2.09s
Bind Time 0.66s (± 0.72%) 0.66s (± 0.88%) 0.00s ( 0.00%) 0.65s 0.67s
Check Time 13.60s (± 0.91%) 13.61s (± 0.68%) +0.01s (+ 0.04%) 13.44s 13.79s
Emit Time 0.00s (± 0.00%) 0.00s (± 0.00%) 0.00s ( NaN%) 0.00s 0.00s
Total Time 16.33s (± 0.82%) 16.33s (± 0.62%) +0.00s (+ 0.03%) 16.14s 16.54s
Angular - node (v12.1.0, x64)
Memory used 322,456k (± 0.03%) 323,015k (± 0.03%) +559k (+ 0.17%) 322,785k 323,219k
Parse Time 1.97s (± 0.66%) 1.97s (± 0.54%) 0.00s ( 0.00%) 1.94s 1.99s
Bind Time 0.82s (± 1.10%) 0.81s (± 1.17%) -0.01s (- 0.85%) 0.80s 0.84s
Check Time 4.89s (± 0.33%) 4.91s (± 0.48%) +0.03s (+ 0.55%) 4.87s 4.97s
Emit Time 5.53s (± 0.46%) 5.49s (± 0.42%) -0.05s (- 0.85%) 5.45s 5.54s
Total Time 13.21s (± 0.34%) 13.18s (± 0.36%) -0.02s (- 0.17%) 13.08s 13.28s
Monaco - node (v12.1.0, x64)
Memory used 336,800k (± 0.02%) 337,770k (± 0.02%) +970k (+ 0.29%) 337,674k 337,892k
Parse Time 1.59s (± 0.37%) 1.59s (± 0.94%) +0.00s (+ 0.06%) 1.56s 1.64s
Bind Time 0.71s (± 1.25%) 0.71s (± 0.63%) -0.00s (- 0.42%) 0.70s 0.72s
Check Time 4.90s (± 0.52%) 4.96s (± 0.25%) +0.05s (+ 1.08%) 4.92s 4.98s
Emit Time 2.87s (± 0.81%) 2.87s (± 0.76%) -0.00s (- 0.03%) 2.84s 2.94s
Total Time 10.08s (± 0.51%) 10.13s (± 0.25%) +0.05s (+ 0.52%) 10.08s 10.20s
TFS - node (v12.1.0, x64)
Memory used 292,104k (± 0.02%) 293,676k (± 0.02%) +1,573k (+ 0.54%) 293,573k 293,769k
Parse Time 1.26s (± 0.96%) 1.27s (± 0.51%) +0.01s (+ 0.96%) 1.25s 1.28s
Bind Time 0.66s (± 0.72%) 0.66s (± 0.84%) +0.00s (+ 0.15%) 0.65s 0.67s
Check Time 4.52s (± 0.72%) 4.56s (± 0.60%) +0.04s (+ 0.82%) 4.48s 4.62s
Emit Time 2.96s (± 0.72%) 2.97s (± 1.54%) +0.00s (+ 0.14%) 2.87s 3.10s
Total Time 9.40s (± 0.43%) 9.45s (± 0.49%) +0.05s (+ 0.56%) 9.32s 9.54s
material-ui - node (v12.1.0, x64)
Memory used 467,049k (± 0.08%) 466,974k (± 0.09%) -74k (- 0.02%) 466,045k 467,403k
Parse Time 2.09s (± 0.57%) 2.08s (± 0.39%) -0.01s (- 0.48%) 2.06s 2.10s
Bind Time 0.65s (± 0.72%) 0.65s (± 0.69%) -0.00s (- 0.31%) 0.64s 0.66s
Check Time 12.19s (± 0.63%) 12.19s (± 0.61%) -0.00s (- 0.00%) 12.03s 12.31s
Emit Time 0.00s (± 0.00%) 0.00s (± 0.00%) 0.00s ( NaN%) 0.00s 0.00s
Total Time 14.93s (± 0.56%) 14.91s (± 0.47%) -0.02s (- 0.12%) 14.75s 15.03s
Angular - node (v8.9.0, x64)
Memory used 347,161k (± 0.02%) 347,751k (± 0.02%) +590k (+ 0.17%) 347,639k 347,966k
Parse Time 2.52s (± 0.63%) 2.53s (± 0.44%) +0.01s (+ 0.28%) 2.51s 2.56s
Bind Time 0.87s (± 0.51%) 0.88s (± 0.42%) +0.00s (+ 0.34%) 0.87s 0.88s
Check Time 5.60s (± 0.54%) 5.62s (± 0.67%) +0.02s (+ 0.38%) 5.53s 5.69s
Emit Time 6.33s (± 0.81%) 6.37s (± 1.23%) +0.04s (+ 0.58%) 6.25s 6.61s
Total Time 15.32s (± 0.43%) 15.39s (± 0.67%) +0.07s (+ 0.46%) 15.22s 15.66s
Monaco - node (v8.9.0, x64)
Memory used 358,530k (± 0.02%) 359,451k (± 0.02%) +921k (+ 0.26%) 359,356k 359,616k
Parse Time 1.93s (± 0.41%) 1.94s (± 0.52%) +0.00s (+ 0.21%) 1.91s 1.96s
Bind Time 0.92s (± 0.92%) 0.91s (± 0.89%) -0.01s (- 0.65%) 0.89s 0.93s
Check Time 5.67s (± 0.52%) 5.68s (± 0.41%) +0.02s (+ 0.30%) 5.63s 5.73s
Emit Time 3.43s (± 0.66%) 3.38s (± 1.00%) -0.05s (- 1.43%) 3.29s 3.44s
Total Time 11.95s (± 0.40%) 11.91s (± 0.46%) -0.04s (- 0.30%) 11.75s 12.00s
TFS - node (v8.9.0, x64)
Memory used 310,390k (± 0.01%) 311,927k (± 0.01%) +1,537k (+ 0.50%) 311,819k 312,027k
Parse Time 1.58s (± 0.48%) 1.57s (± 0.52%) -0.00s (- 0.13%) 1.56s 1.60s
Bind Time 0.68s (± 0.54%) 0.69s (± 0.58%) +0.01s (+ 0.88%) 0.68s 0.70s
Check Time 5.36s (± 0.74%) 5.40s (± 0.60%) +0.04s (+ 0.84%) 5.30s 5.46s
Emit Time 2.98s (± 0.73%) 2.96s (± 1.21%) -0.01s (- 0.47%) 2.89s 3.06s
Total Time 10.59s (± 0.45%) 10.63s (± 0.62%) +0.04s (+ 0.36%) 10.45s 10.76s
material-ui - node (v8.9.0, x64)
Memory used 496,209k (± 0.01%) 496,318k (± 0.02%) +109k (+ 0.02%) 496,193k 496,680k
Parse Time 2.50s (± 0.42%) 2.50s (± 0.64%) +0.00s (+ 0.04%) 2.47s 2.53s
Bind Time 0.82s (± 1.61%) 0.81s (± 1.69%) -0.00s (- 0.61%) 0.79s 0.84s
Check Time 18.06s (± 0.98%) 18.19s (± 0.99%) +0.14s (+ 0.75%) 17.64s 18.48s
Emit Time 0.00s (± 0.00%) 0.00s (± 0.00%) 0.00s ( NaN%) 0.00s 0.00s
Total Time 21.38s (± 0.86%) 21.51s (± 0.88%) +0.14s (+ 0.65%) 20.94s 21.84s
Angular - node (v8.9.0, x86)
Memory used 199,008k (± 0.02%) 199,329k (± 0.02%) +321k (+ 0.16%) 199,208k 199,399k
Parse Time 2.45s (± 0.77%) 2.43s (± 0.79%) -0.02s (- 0.65%) 2.40s 2.48s
Bind Time 1.04s (± 0.87%) 1.02s (± 0.36%) -0.01s (- 1.35%) 1.02s 1.03s
Check Time 5.08s (± 0.42%) 5.06s (± 1.01%) -0.02s (- 0.37%) 4.97s 5.23s
Emit Time 6.11s (± 1.09%) 6.14s (± 0.49%) +0.03s (+ 0.49%) 6.06s 6.20s
Total Time 14.67s (± 0.68%) 14.66s (± 0.52%) -0.02s (- 0.10%) 14.51s 14.91s
Monaco - node (v8.9.0, x86)
Memory used 203,026k (± 0.01%) 203,483k (± 0.01%) +457k (+ 0.23%) 203,447k 203,514k
Parse Time 1.98s (± 0.61%) 1.99s (± 1.29%) +0.00s (+ 0.15%) 1.95s 2.07s
Bind Time 0.72s (± 0.47%) 0.72s (± 0.70%) -0.01s (- 1.11%) 0.71s 0.73s
Check Time 5.77s (± 1.20%) 5.81s (± 0.66%) +0.03s (+ 0.59%) 5.76s 5.94s
Emit Time 2.80s (± 2.83%) 2.74s (± 0.69%) -0.06s (- 2.14%) 2.70s 2.79s
Total Time 11.28s (± 0.64%) 11.25s (± 0.41%) -0.03s (- 0.27%) 11.16s 11.35s
TFS - node (v8.9.0, x86)
Memory used 177,509k (± 0.02%) 178,255k (± 0.02%) +746k (+ 0.42%) 178,178k 178,328k
Parse Time 1.62s (± 1.18%) 1.61s (± 0.72%) -0.02s (- 1.11%) 1.59s 1.64s
Bind Time 0.65s (± 0.80%) 0.65s (± 1.54%) +0.00s (+ 0.46%) 0.64s 0.69s
Check Time 4.88s (± 0.71%) 4.87s (± 0.71%) -0.02s (- 0.31%) 4.79s 4.93s
Emit Time 2.83s (± 1.22%) 2.85s (± 1.07%) +0.02s (+ 0.78%) 2.77s 2.91s
Total Time 9.99s (± 0.63%) 9.98s (± 0.58%) -0.01s (- 0.07%) 9.82s 10.07s
material-ui - node (v8.9.0, x86)
Memory used 279,274k (± 0.02%) 279,318k (± 0.02%) +45k (+ 0.02%) 279,217k 279,481k
Parse Time 2.55s (± 0.73%) 2.56s (± 0.83%) +0.01s (+ 0.24%) 2.51s 2.61s
Bind Time 0.72s (± 4.46%) 0.72s (± 2.24%) -0.00s (- 0.55%) 0.69s 0.76s
Check Time 16.48s (± 0.84%) 16.50s (± 0.54%) +0.01s (+ 0.08%) 16.32s 16.73s
Emit Time 0.00s (± 0.00%) 0.00s (± 0.00%) 0.00s ( NaN%) 0.00s 0.00s
Total Time 19.76s (± 0.63%) 19.77s (± 0.44%) +0.01s (+ 0.07%) 19.58s 19.99s
System
Machine Namets-ci-ubuntu
Platformlinux 4.4.0-166-generic
Architecturex64
Available Memory16 GB
Available Memory1 GB
CPUs4 × Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz
Hosts
  • node (v10.16.3, x64)
  • node (v12.1.0, x64)
  • node (v8.9.0, x64)
  • node (v8.9.0, x86)
Scenarios
  • Angular - node (v10.16.3, x64)
  • Angular - node (v12.1.0, x64)
  • Angular - node (v8.9.0, x64)
  • Angular - node (v8.9.0, x86)
  • Monaco - node (v10.16.3, x64)
  • Monaco - node (v12.1.0, x64)
  • Monaco - node (v8.9.0, x64)
  • Monaco - node (v8.9.0, x86)
  • TFS - node (v10.16.3, x64)
  • TFS - node (v12.1.0, x64)
  • TFS - node (v8.9.0, x64)
  • TFS - node (v8.9.0, x86)
  • material-ui - node (v10.16.3, x64)
  • material-ui - node (v12.1.0, x64)
  • material-ui - node (v8.9.0, x64)
  • material-ui - node (v8.9.0, x86)
Benchmark Name Iterations
Current 41387 10
Baseline master 10

@weswigham
Copy link
Member Author

Excellent - perf seems fine. @ahejlsberg any opinions? You've been pretty vocal about how we approach caching in control flow in the past, but I figure this is probably pretty safe, since it's an extension of the caching we already did at loop labels.

@ahejlsberg
Copy link
Member

I'm concerned that we'll be caching a lot more data than we currently do as branch labels are far more common than loop labels. It does look like we're consuming more memory in the Angular, Monaco, and TFS suites, and the check times are slightly higher for those as well. It'd be great to find a way to only cache when it matters, particularly as it very rarely does.

@weswigham
Copy link
Member Author

weswigham commented Nov 4, 2020

It does look like we're consuming more memory in the Angular, Monaco, and TFS suites, and the check times are slightly higher for those as well. It'd be great to find a way to only cache when it matters, particularly as it very rarely does.

Less than half a percent, and not uniformly across node versions. Memory usage in material-ui in node 12 is actually reported as down a fraction of a percent - the perf results are in the noise, so the perf, memory included, definitely seems fine to me.

@weswigham
Copy link
Member Author

It'd be great to find a way to only cache when it matters, particularly as it very rarely does.

It matters in every case more complex than

function f(s: boolean) {
  f2(aa as any && aa);
}

(which is to say a control flow graph with only a single statement with a single branch label) and those trivial examples likely make up a very small fraction of code...

@JoostK
Copy link
Contributor

JoostK commented Nov 4, 2020

I think I found the root cause of the issue. After digging into the flow graph a bit, it became apparent that the Call flow node is marked as Shared, which should allow its result to be cached. However, the Call flow ends up not resolving to any flow type, in which case the while-loop in getTypeAtFlowNode will try its antecedent, which is not shared. This means that although the Call node was marked as shared, its computed result is never captured in the shared type cache and we end up walking the full flow graph over and over again (as all shared cache opportunities are missed).

If we keep track of the shared node and register its result as computed for the antecedent I no longer see this blowing up:

--- src/compiler/checker.ts	(revision 6874d6514dea4679c39185790764bbf990777567)
+++ src/compiler/checker.ts	(date 1604522021008)
@@ -21685,6 +21685,13 @@
                 return key = getFlowCacheKey(reference, declaredType, initialType, flowContainer);
             }
 
+            function addSharedFlowType(flow: FlowNode, type: FlowType) {
+                // Record visited node and the associated type in the cache.
+                sharedFlowNodes[sharedFlowCount] = flow;
+                sharedFlowTypes[sharedFlowCount] = type;
+                sharedFlowCount++;
+            }
+
             function getTypeAtFlowNode(flow: FlowNode): FlowType {
                 if (flowDepth === 2000) {
                     // We have made 2000 recursive invocations. To avoid overflowing the call stack we report an error
@@ -21695,6 +21702,7 @@
                     return errorType;
                 }
                 flowDepth++;
+                let sharedFlow: FlowNode | undefined;
                 while (true) {
                     const flags = flow.flags;
                     if (flags & FlowFlags.Shared) {
@@ -21719,6 +21730,9 @@
                     else if (flags & FlowFlags.Call) {
                         type = getTypeAtFlowCall(<FlowCall>flow);
                         if (!type) {
+                            if (!sharedFlow && flags & FlowFlags.Shared) {
+                                sharedFlow = flow;
+                            }
                             flow = (<FlowCall>flow).antecedent;
                             continue;
                         }
@@ -21775,11 +21789,11 @@
                         // simply return the non-auto declared type to reduce follow-on errors.
                         type = convertAutoToAny(declaredType);
                     }
+                    if (sharedFlow) {
+                        addSharedFlowType(sharedFlow, type);
+                    }
                     if (flags & FlowFlags.Shared) {
-                        // Record visited node and the associated type in the cache.
-                        sharedFlowNodes[sharedFlowCount] = flow;
-                        sharedFlowTypes[sharedFlowCount] = type;
-                        sharedFlowCount++;
+                        addSharedFlowType(flow, type);
                     }
                     flowDepth--;
                     return type;

@weswigham @ahejlsberg If this does indeed look like a correct approach then I'd be interested in opening a PR with this change 😃

@weswigham
Copy link
Member Author

@JoostK that looks like another valid approach to the issue - a PR seems welcome to me.

@sandersn sandersn added this to Not started in PR Backlog Nov 18, 2020
@sandersn sandersn moved this from Not started to Needs review in PR Backlog Nov 23, 2020
@sandersn sandersn moved this from Needs review to Waiting on author in PR Backlog Nov 23, 2020
@ahejlsberg
Copy link
Member

See #41665 for what I think is the simplest possible fix.

@weswigham weswigham closed this Nov 25, 2020
PR Backlog automation moved this from Waiting on author to Done Nov 25, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Author: Team For Milestone Bug PRs that fix a bug with a specific milestone
Projects
PR Backlog
  
Done
Development

Successfully merging this pull request may close these issues.

perf: exponential slowdown in flow analysis
4 participants