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

Modifying "packages/flutter/lib/src/widgets/binding.dart" causes analysis that takes ~30s #60293

Open
DanTup opened this issue Mar 10, 2025 · 8 comments
Labels
area-dart-model Use area-dart-model for issues related to packages analyzer, front_end, and kernel. model-performance Performance/memory issues in analyzer/cfe

Comments

@DanTup
Copy link
Collaborator

DanTup commented Mar 10, 2025

There are multiple performance issues coming up in #55281 which makes it a bit hard to track them (and their solutions), so I'm adding sub-issues for some individual issues that have been identified.

One issue is that modifying the file lib/src/widgets/binding.dart in the Flutter framework causes analysis that takes around 30 seconds. This was noted at #55281 (comment) by @knopp and I can reproduce myself:

  • Check out the Flutter repo at 082497087c
  • Open the packages/flutter folder in VS Code
  • Open the lib\src\widgets\binding.dart file and wait for all analysis to complete
  • Paste some code like void h() {} into the body of abstract mixin class WidgetsBindingObserver
  • Wait for analysis to complete
  • Rename the method to something different (eg. select h and type g)
  • Observe "Analyzing..." for 20-30s

Some numbers from the timings:

    (name: analyzeFile, count: 1348, elapsed: 0:00:21.550138, elapsedSelf: 0:00:01.157371)
      (name: libraryContext, count: 1348, elapsed: 0:00:00.002411, elapsedSelf: 0:00:00.001833)
        (name: libraryCycle, count: 1348, elapsed: 0:00:00.000578, elapsedSelf: 0:00:00.000578)
      (name: LibraryAnalyzer, count: 1348, elapsed: 0:00:20.390356, elapsedSelf: 0:00:00.015265)
        (name: parseAndResolve, count: 1348, elapsed: 0:00:08.263939, elapsedSelf: 0:00:08.263939)
        (name: computeDiagnostics, count: 1348, elapsed: 0:00:12.111152, elapsedSelf: 0:00:12.111152)

I ran the CPU profiler over this but nothing stood out to me. A lot of the time is in linting, and the call stack gets very deep in the lint visitor, but I'm not sure if that's unusual (I don't know of this number of files is typical to be reanalyzed on a single change).

I've exported the CPU profile info from DevTools here: dart_devtools_2025-03-10_11_30_50.358.json

cc @bwilkerson @scheglov

@DanTup DanTup added the area-analyzer Use area-analyzer for Dart analyzer issues, including the analysis server and code completion. label Mar 10, 2025
@knopp
Copy link
Contributor

knopp commented Mar 10, 2025

The linter takes a while, but to me it seems that linking is even bigger problem, happens every time the file structure changes significantly, i.e. adding a method.

@johnniwinther johnniwinther added area-dart-model Use area-dart-model for issues related to packages analyzer, front_end, and kernel. model-performance Performance/memory issues in analyzer/cfe and removed area-analyzer Use area-analyzer for Dart analyzer issues, including the analysis server and code completion. labels Mar 10, 2025
@knopp
Copy link
Contributor

knopp commented Mar 10, 2025

      (name: link, count: 3, elapsed: 0:00:30.073118, elapsedSelf: 0:00:00.000133)
        (name: LibraryBuilder.build, count: 3, elapsed: 0:00:09.483828, elapsedSelf: 0:00:00.063373)
          (name: libraryFile, count: 1326, elapsed: 0:00:09.420455, elapsedSelf: 0:00:00.007854)
            (name: parseCode, count: 1326, elapsed: 0:00:09.412601, elapsedSelf: 0:00:09.412601)(length: 48431158)
        (name: buildOutlines, count: 3, elapsed: 0:00:18.240424, elapsedSelf: 0:00:14.398082)
          (name: computeLibraryScopes, count: 3, elapsed: 0:00:03.842342, elapsedSelf: 0:00:03.842342)
        (name: writeLibraries, count: 3, elapsed: 0:00:02.348733, elapsedSelf: 0:00:02.178561)(length: 20786812)
          (name: bundleWriteFinish, count: 3, elapsed: 0:00:00.170172, elapsedSelf: 0:00:00.170172)

@DanTup
Copy link
Collaborator Author

DanTup commented Mar 10, 2025

I disabled all lints, but I didn't see any real improvement in times. Here is the driver log showing approx 22s analysis after changing the name of the method in a single keystroke:

driver-log.txt

And of the files reanalyzed, those with 3-digit millisecond times:

PS D:\Dev\Google\Flutter\Flutter main\packages\flutter> select-string -pattern "\.dart in \d\d\d+ ms" -Path "C:\Users\danny\Downloads\driver-log.txt"

Compute analysis result for D:\Dev\Google\Flutter\Flutter main\packages\flutter\lib\src\widgets\binding.dart in 2008 ms.
Compute analysis result for D:\Dev\Google\Flutter\Flutter main\packages\flutter\lib\src\material\animated_icons\animated_icons.dart in 671 ms.
Compute analysis result for D:\Dev\Google\Flutter\Flutter main\packages\flutter\lib\src\material\icons.dart in 285 ms.
Compute analysis result for D:\Dev\Google\Flutter\Flutter main\packages\flutter\test\material\input_decorator_test.dart in 267 ms.
Compute analysis result for D:\Dev\Google\Flutter\Flutter main\packages\flutter\test\material\text_field_test.dart in 260 ms.
Compute analysis result for D:\Dev\Google\Flutter\Flutter main\packages\flutter\test\widgets\editable_text_test.dart in 213 ms.
Compute analysis result for D:\Dev\Google\Flutter\Flutter main\packages\flutter\test\material\navigation_rail_test.dart in 207 ms.
Compute analysis result for D:\Dev\Google\Flutter\Flutter main\packages\flutter\test\material\icon_button_test.dart in 141 ms.
Compute analysis result for D:\Dev\Google\Flutter\Flutter main\packages\flutter\test\material\tabs_test.dart in 141 ms.
Compute analysis result for D:\Dev\Google\Flutter\Flutter main\packages\flutter\test\cupertino\text_field_test.dart in 140 ms.
Compute analysis result for D:\Dev\Google\Flutter\Flutter main\packages\flutter\test\widgets\navigator_test.dart in 127 ms.
Compute analysis result for D:\Dev\Google\Flutter\Flutter main\packages\flutter\test\material\search_anchor_test.dart in 122 ms.
Compute analysis result for D:\Dev\Google\Flutter\Flutter main\packages\flutter\test\material\chip_test.dart in 112 ms.
Compute analysis result for D:\Dev\Google\Flutter\Flutter main\packages\flutter\test\material\bottom_navigation_bar_test.dart in 111 ms.
Compute analysis result for D:\Dev\Google\Flutter\Flutter main\packages\flutter\test\widgets\selectable_region_test.dart in 106 ms.

PS D:\Dev\Google\Flutter\Flutter main\packages\flutter>

@bwilkerson
Copy link
Member

A lot of the time is in linting, and the call stack gets very deep in the lint visitor, but I'm not sure if that's unusual (I don't know of this number of files is typical to be reanalyzed on a single change).

The call stack in the linter should never be deeper than the AST structure used to represent the code, but deeply nested code probably isn't as uncommon as one might hope. I'm not aware of anything we could do to reduce the depth of the call stack, other than rewriting our visitors to not use recursion, but I'm also not aware of a significant performance cost to having a deep stack.

The number of files being reanalyzed is a function of the size of the library cycle being analyzed or relinked. Unfortunately, large library cycles are also not uncommon. We are working on reducing the amount of effort required to relink a library cycle after such a change, so we're hoping to be ale to make progress here.

@knopp
Copy link
Contributor

knopp commented Mar 10, 2025

Not sure we can do anything about the size of the cycle in Framework :-/ About half of it is material + cupertino, which import the barrel files, but also the rest of the framework is not exactly being shy with importing barrel files.

@bwilkerson
Copy link
Member

The Flutter team could reduce the use of barrel files in their own code by importing what they really depend on, but I don't think that's likely to happen and I don't have any evidence that that would reduce the size of the cycle.

@scheglov
Copy link
Contributor

scheglov commented Mar 10, 2025

I'm busy right now with something else that should be done first, but I have an experimental implementation of fine-grained dependencies that significantly improve re-analysis times after incremental changes, like adding a method. It is not at the point where I would recommend using it.

A simple operation below shows that re-analysis time goes from 54.4 seconds to 2.52 seconds, or about 20x faster.

The workspace below consists of only flutter/packages/flutter, without other sibling packages.
Specifically, no flutter_test and flutter_tools, just one (the biggest) package from the Flutter repository.

Initial analysis

(name: <scheduler>, count: 0, elapsed: 0:00:00.000000, elapsedSelf: -0:01:06.556254)
  (name: produceErrors, count: 1570, elapsed: 0:01:06.556254, elapsedSelf: 0:00:00.090364)
    (name: libraryContext, count: 1570, elapsed: 0:00:14.216095, elapsedSelf: 0:00:00.229959)(bytesPut: 14482376, cycleCount: 1741, libraryCount: 2358)
      (name: libraryCycle, count: 1570, elapsed: 0:00:02.061044, elapsedSelf: 0:00:00.257790)
        (name: fileState.refresh, count: 1049, elapsed: 0:00:01.803254, elapsedSelf: 0:00:00.365507)
          (name: getUnlinkedUnit, count: 1049, elapsed: 0:00:01.437747, elapsedSelf: 0:00:00.014908)
            (name: parseCode, count: 837, elapsed: 0:00:00.815606, elapsedSelf: 0:00:00.815606)(length: 12152308)
            (name: compute, count: 837, elapsed: 0:00:00.607233, elapsedSelf: 0:00:00.174551)
              (name: serializeAstUnlinked2, count: 837, elapsed: 0:00:00.432682, elapsedSelf: 0:00:00.250030)
                (name: apiSignature, count: 837, elapsed: 0:00:00.182652, elapsedSelf: 0:00:00.182652)
      (name: link, count: 1741, elapsed: 0:00:11.925092, elapsedSelf: 0:00:00.010674)
        (name: LibraryBuilder.build, count: 1741, elapsed: 0:00:03.055747, elapsedSelf: 0:00:00.046965)
          (name: libraryFile, count: 2358, elapsed: 0:00:03.008782, elapsedSelf: 0:00:00.005323)
            (name: parseCode, count: 2358, elapsed: 0:00:03.003459, elapsedSelf: 0:00:03.003459)(length: 51596135)
        (name: buildOutlines, count: 1741, elapsed: 0:00:08.047657, elapsedSelf: 0:00:06.398175)
          (name: computeLibraryScopes, count: 1741, elapsed: 0:00:01.649482, elapsedSelf: 0:00:01.649482)
        (name: writeLibraries, count: 1741, elapsed: 0:00:00.811014, elapsedSelf: 0:00:00.744986)(length: 14482376)
          (name: bundleWriteFinish, count: 1741, elapsed: 0:00:00.066028, elapsedSelf: 0:00:00.066028)
    (name: analyzeFile, count: 1570, elapsed: 0:00:52.249795, elapsedSelf: 0:00:00.328175)
      (name: libraryContext, count: 1570, elapsed: 0:00:00.003676, elapsedSelf: 0:00:00.002947)
        (name: libraryCycle, count: 1570, elapsed: 0:00:00.000729, elapsedSelf: 0:00:00.000729)
      (name: LibraryAnalyzer, count: 1570, elapsed: 0:00:51.917944, elapsedSelf: 0:00:00.025304)
        (name: parseAndResolve, count: 1570, elapsed: 0:00:20.230265, elapsedSelf: 0:00:20.230265)
        (name: computeDiagnostics, count: 1570, elapsed: 0:00:31.662375, elapsedSelf: 0:00:31.662375)

Change WidgetsBindingObserver.didPopRoute() to didPopRoute2().
Current version.

(name: <scheduler>, count: 0, elapsed: 0:00:00.000000, elapsedSelf: -0:00:54.406987)
  (name: produceErrors, count: 1569, elapsed: 0:00:54.406987, elapsedSelf: 0:00:00.080533)
    (name: libraryContext, count: 1569, elapsed: 0:00:07.004646, elapsedSelf: 0:00:01.748282)(bytesGet: 1026678, bytesPut: 4711665, cycleCount: 1070, libraryCount: 1371, libraryLoadCount: 188)
      (name: libraryCycle, count: 1569, elapsed: 0:00:00.061455, elapsedSelf: 0:00:00.061455)
      (name: bundleReader, count: 154, elapsed: 0:00:00.005425, elapsedSelf: 0:00:00.005425)
      (name: link, count: 916, elapsed: 0:00:05.189484, elapsedSelf: 0:00:00.006795)
        (name: LibraryBuilder.build, count: 916, elapsed: 0:00:01.959876, elapsedSelf: 0:00:00.013703)
          (name: libraryFile, count: 1183, elapsed: 0:00:01.946173, elapsedSelf: 0:00:00.002671)
            (name: parseCode, count: 1183, elapsed: 0:00:01.943502, elapsedSelf: 0:00:01.943502)(length: 33275478)
        (name: buildOutlines, count: 916, elapsed: 0:00:02.986693, elapsedSelf: 0:00:02.540354)
          (name: computeLibraryScopes, count: 916, elapsed: 0:00:00.446339, elapsedSelf: 0:00:00.446339)
        (name: writeLibraries, count: 916, elapsed: 0:00:00.236120, elapsedSelf: 0:00:00.213219)(length: 4711665)
          (name: bundleWriteFinish, count: 916, elapsed: 0:00:00.022901, elapsedSelf: 0:00:00.022901)
    (name: analyzeFile, count: 1347, elapsed: 0:00:47.321808, elapsedSelf: 0:00:00.562216)
      (name: libraryContext, count: 1347, elapsed: 0:00:00.002411, elapsedSelf: 0:00:00.001693)
        (name: libraryCycle, count: 1347, elapsed: 0:00:00.000718, elapsedSelf: 0:00:00.000718)
      (name: LibraryAnalyzer, count: 1347, elapsed: 0:00:46.757181, elapsedSelf: 0:00:00.018351)
        (name: parseAndResolve, count: 1347, elapsed: 0:00:18.112725, elapsedSelf: 0:00:18.112725)
        (name: computeDiagnostics, count: 1347, elapsed: 0:00:28.626105, elapsedSelf: 0:00:28.626105)

Change WidgetsBindingObserver.didPopRoute() to didPopRoute2().
Fine-grained dependencies.

(name: <scheduler>, count: 0, elapsed: 0:00:00.000000, elapsedSelf: -0:00:02.521815)
  (name: produceErrors, count: 1569, elapsed: 0:00:02.521815, elapsedSelf: 0:00:00.044294)
    (name: libraryContext, count: 1569, elapsed: 0:00:02.111416, elapsedSelf: 0:00:00.160912)(bytesGet: 3609900, bytesPut: 2128443, cycleCount: 1070, libraryCount: 1371, libraryLoadCount: 1106)
      (name: libraryCycle, count: 1569, elapsed: 0:00:00.033732, elapsedSelf: 0:00:00.033732)
      (name: libraryContext(isSatisfied), count: 1070, elapsed: 0:00:00.092748, elapsedSelf: 0:00:00.092748)
      (name: bundleReader, count: 1069, elapsed: 0:00:00.018206, elapsedSelf: 0:00:00.018206)
      (name: link, count: 1, elapsed: 0:00:01.502440, elapsedSelf: 0:00:00.000024)
        (name: LibraryBuilder.build, count: 1, elapsed: 0:00:00.550001, elapsedSelf: 0:00:00.002416)
          (name: libraryFile, count: 265, elapsed: 0:00:00.547585, elapsedSelf: 0:00:00.000279)
            (name: parseCode, count: 265, elapsed: 0:00:00.547306, elapsedSelf: 0:00:00.547306)(length: 8870743)
        (name: buildOutlines, count: 1, elapsed: 0:00:00.887592, elapsedSelf: 0:00:00.735765)
          (name: computeLibraryScopes, count: 1, elapsed: 0:00:00.151827, elapsedSelf: 0:00:00.151827)
        (name: writeLibraries, count: 1, elapsed: 0:00:00.064823, elapsedSelf: 0:00:00.059023)(length: 2128443)
          (name: bundleWriteFinish, count: 1, elapsed: 0:00:00.005800, elapsedSelf: 0:00:00.005800)
      (name: computeManifests, count: 1, elapsed: 0:00:00.303378, elapsedSelf: 0:00:00.303378)(libraryCount: 265, structureMatchedCount: 22122, structureMismatchedCount: 1, transitiveAffectedCount: 1, transitiveMatchedCount: 22122)
    (name: errors(isSatisfied), count: 1569, elapsed: 0:00:00.095515, elapsedSelf: 0:00:00.091125)
      (name: getBytes, count: 5, elapsed: 0:00:00.000059, elapsedSelf: 0:00:00.000059)
      (name: readRequirements, count: 4, elapsed: 0:00:00.004331, elapsedSelf: 0:00:00.004331)
    (name: analyzeFile, count: 4, elapsed: 0:00:00.270590, elapsedSelf: 0:00:00.001356)
      (name: libraryContext, count: 4, elapsed: 0:00:00.000006, elapsedSelf: 0:00:00.000005)
        (name: libraryCycle, count: 4, elapsed: 0:00:00.000001, elapsedSelf: 0:00:00.000001)
      (name: LibraryAnalyzer, count: 4, elapsed: 0:00:00.267196, elapsedSelf: 0:00:00.000094)
        (name: parseAndResolve, count: 4, elapsed: 0:00:00.166929, elapsedSelf: 0:00:00.166929)
        (name: computeDiagnostics, count: 4, elapsed: 0:00:00.100173, elapsedSelf: 0:00:00.100173)
      (name: writeResolvedLibrary, count: 4, elapsed: 0:00:00.002032, elapsedSelf: 0:00:00.002032)

@DanTup
Copy link
Collaborator Author

DanTup commented Mar 10, 2025

A simple operation below shows that re-analysis time goes from 54.4 seconds to 2.52 seconds, or about 20x faster.

This sounds fantastic, I hope you're able to get back to it soon! 🙂

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area-dart-model Use area-dart-model for issues related to packages analyzer, front_end, and kernel. model-performance Performance/memory issues in analyzer/cfe
Projects
None yet
Development

No branches or pull requests

5 participants