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

Analysis server sends Analyzing=true frequently during flutter builds #31564

Open
DanTup opened this Issue Dec 6, 2017 · 15 comments

Comments

Projects
None yet
4 participants
@DanTup
Member

DanTup commented Dec 6, 2017

In Dart Code we show "Analyzing..." in the status bar whenever the analysis server says it's analyzing. I noticed it flickers a lot during Flutter builds, even though (at least as far as the user is concerned) nothing is changing.

Would it simple/reasonable to avoid sending these when modifications on disk are unrelated?

Here's an example snippet from the instrumentation log:

1512584383484:Watch:/Users/danny/Dev/Testing/flutter_gallery:/Users/danny/Dev/Testing/flutter_gallery/build/ios/iphonesimulator/Runner.app/Frameworks/Flutter.framework/Info.plist:modify
1512584383484:Watch:/Users/danny/Dev/Testing/flutter_gallery:/Users/danny/Dev/Testing/flutter_gallery/build/ios/iphonesimulator/Runner.app/Frameworks/App.framework/_CodeSignature/CodeResources:modify
1512584383485:Watch:/Users/danny/Dev/Testing/flutter_gallery:/Users/danny/Dev/Testing/flutter_gallery/build/ios/iphonesimulator/Runner.app/Frameworks/App.framework/App:modify
1512584383485:Watch:/Users/danny/Dev/Testing/flutter_gallery:/Users/danny/Dev/Testing/flutter_gallery/build/ios/iphonesimulator/Runner.app/Frameworks/App.framework/Info.plist:modify
1512584383485:Watch:/Users/danny/Dev/Testing/flutter_gallery:/Users/danny/Dev/Testing/flutter_gallery/build/ios/iphonesimulator/Runner.app/Frameworks/url_launcher.framework/_CodeSignature/CodeResources:modify
1512584383485:Watch:/Users/danny/Dev/Testing/flutter_gallery:/Users/danny/Dev/Testing/flutter_gallery/build/ios/iphonesimulator/Runner.app/Frameworks/url_launcher.framework/url_launcher:modify
1512584383485:Watch:/Users/danny/Dev/Testing/flutter_gallery:/Users/danny/Dev/Testing/flutter_gallery/build/ios/iphonesimulator/Runner.app/Frameworks/url_launcher.framework/Info.plist:modify
1512584383489:Noti:{"event"::"server.status","params"::{"analysis"::{"isAnalyzing"::false}}}
1512584383581:Watch:/Users/danny/Dev/Testing/flutter_gallery:/Users/danny/Dev/Testing/flutter_gallery/build/ios/iphonesimulator/Runner.app/AppIcon20x20~ipad.png:modify
1512584383581:Watch:/Users/danny/Dev/Testing/flutter_gallery:/Users/danny/Dev/Testing/flutter_gallery/build/ios/iphonesimulator/Runner.app/AppIcon20x20@2x~ipad.png:modify
1512584383582:Noti:{"event"::"server.status","params"::{"analysis"::{"isAnalyzing"::true}}}
1512584383582:Watch:/Users/danny/Dev/Testing/flutter_gallery:/Users/danny/Dev/Testing/flutter_gallery/build/ios/iphonesimulator/Runner.app/Info.plist:modify
1512584383582:Watch:/Users/danny/Dev/Testing/flutter_gallery:/Users/danny/Dev/Testing/flutter_gallery/build/ios/iphonesimulator/Runner.app/PkgInfo:modify
1512584383582:Watch:/Users/danny/Dev/Testing/flutter_gallery:/Users/danny/Dev/Testing/flutter_gallery/build/ios/iphonesimulator/Runner.app/AppIcon76x76~ipad.png:modify
1512584383584:Noti:{"event"::"server.status","params"::{"analysis"::{"isAnalyzing"::false}}}

I don't know if the files listed here are what triggered it, or whether it was before this (the log is quite long) but lmk if you need more info I can dig further.

(cc @bwilkerson)

@devoncarew

This comment has been minimized.

Show comment
Hide comment
@devoncarew

devoncarew Dec 7, 2017

Member

I believe we de-bounce the notifications a bit in IntelliJ - which is why we don't see this - but it seems reasonable to not send notifications until we hit a file which might need analysis.

Member

devoncarew commented Dec 7, 2017

I believe we de-bounce the notifications a bit in IntelliJ - which is why we don't see this - but it seems reasonable to not send notifications until we hit a file which might need analysis.

@DanTup

This comment has been minimized.

Show comment
Hide comment
@DanTup

DanTup Dec 7, 2017

Member

Now you mention it, Dart Code does the same so not sure why I'm seeing this. I'll do some digging.

I think it'll still be good to filter these out (stuff improved in the analyzer avoids work by all clients) but if there's just something wrong with our debounce code it should be easily fixable in Dart Code.

Member

DanTup commented Dec 7, 2017

Now you mention it, Dart Code does the same so not sure why I'm seeing this. I'll do some digging.

I think it'll still be good to filter these out (stuff improved in the analyzer avoids work by all clients) but if there's just something wrong with our debounce code it should be easily fixable in Dart Code.

@DanTup

This comment has been minimized.

Show comment
Hide comment
@DanTup

DanTup Dec 7, 2017

Member

Ok, here's why I still see it:

[20:07:35.350]: <== {"event":"server.status","params":{"analysis":{"isAnalyzing":false}}}
[20:07:41.857]: <== {"event":"analysis.flushResults","params":{"files":["/Users/danny/Dev/Google/flutter/examples/stocks/build/flx/LICENSE"]}}
[20:07:41.857]: <== {"event":"analysis.flushResults","params":{"files":["/Users/danny/Dev/Google/flutter/examples/stocks/build/flx/AssetManifest.json"]}}
[20:07:41.858]: <== {"event":"server.status","params":{"analysis":{"isAnalyzing":true}}}
[20:07:42.409]: <== {"event":"analysis.flushResults","params":{"files":["/Users/danny/Dev/Google/flutter/examples/stocks/build/flx/FontManifest.json"]}}
[20:07:42.409]: <== {"event":"analysis.flushResults","params":{"files":["/Users/danny/Dev/Google/flutter/examples/stocks/build/flx/fonts/MaterialIcons-Regular.ttf"]}}
[20:07:43.531]: <== {"event":"server.status","params":{"analysis":{"isAnalyzing":false}}}

The timestamps on the last true/false are [20:07:41.858] and [20:07:43.531]. We're only debouncing at 250ms so this (almost two seconds) still causes the flicker.

I'm running this on my MacBook. It might not be the most powerful dev machine but this probably also isn't the biggest Flutter app I'm building (Stocks example). I might increase the timeout to 500ms-1s (I don't think below that it's particularly useful to the user) but obviously it'll still occur a little (for me on this machine, at least).

Still, I don't consider this hugely important; it's just a minor annoyance (mainly because when we're building Flutter apps there is other text in the status bar, and the two labels together look wonky!). If it bugs me enough, I'll see if I can easily suppress the analyzing ones while the other is visible (or, if this change isn't difficult and you can point me in the right direction, I can take a stab).

Member

DanTup commented Dec 7, 2017

Ok, here's why I still see it:

[20:07:35.350]: <== {"event":"server.status","params":{"analysis":{"isAnalyzing":false}}}
[20:07:41.857]: <== {"event":"analysis.flushResults","params":{"files":["/Users/danny/Dev/Google/flutter/examples/stocks/build/flx/LICENSE"]}}
[20:07:41.857]: <== {"event":"analysis.flushResults","params":{"files":["/Users/danny/Dev/Google/flutter/examples/stocks/build/flx/AssetManifest.json"]}}
[20:07:41.858]: <== {"event":"server.status","params":{"analysis":{"isAnalyzing":true}}}
[20:07:42.409]: <== {"event":"analysis.flushResults","params":{"files":["/Users/danny/Dev/Google/flutter/examples/stocks/build/flx/FontManifest.json"]}}
[20:07:42.409]: <== {"event":"analysis.flushResults","params":{"files":["/Users/danny/Dev/Google/flutter/examples/stocks/build/flx/fonts/MaterialIcons-Regular.ttf"]}}
[20:07:43.531]: <== {"event":"server.status","params":{"analysis":{"isAnalyzing":false}}}

The timestamps on the last true/false are [20:07:41.858] and [20:07:43.531]. We're only debouncing at 250ms so this (almost two seconds) still causes the flicker.

I'm running this on my MacBook. It might not be the most powerful dev machine but this probably also isn't the biggest Flutter app I'm building (Stocks example). I might increase the timeout to 500ms-1s (I don't think below that it's particularly useful to the user) but obviously it'll still occur a little (for me on this machine, at least).

Still, I don't consider this hugely important; it's just a minor annoyance (mainly because when we're building Flutter apps there is other text in the status bar, and the two labels together look wonky!). If it bugs me enough, I'll see if I can easily suppress the analyzing ones while the other is visible (or, if this change isn't difficult and you can point me in the right direction, I can take a stab).

@devoncarew

This comment has been minimized.

Show comment
Hide comment
@devoncarew

devoncarew Dec 7, 2017

Member

Yeah, likely some work on our side. I think we shouldn't be sending analysis.flushResults notifications for files we haven't previously sent notifications for, and we likely should send notifications for files we're never going to analyze (like ttf files).

Member

devoncarew commented Dec 7, 2017

Yeah, likely some work on our side. I think we shouldn't be sending analysis.flushResults notifications for files we haven't previously sent notifications for, and we likely should send notifications for files we're never going to analyze (like ttf files).

DanTup added a commit to Dart-Code/Dart-Code that referenced this issue Dec 8, 2017

@DanTup

This comment has been minimized.

Show comment
Hide comment
@DanTup

DanTup Feb 26, 2018

Member

@bwilkerson @devoncarew Is this something I could easily do? It bugs me that our status bar shows two things during build (Analyzing... and the build progress) but fixing on my side will be a kludge!

Member

DanTup commented Feb 26, 2018

@bwilkerson @devoncarew Is this something I could easily do? It bugs me that our status bar shows two things during build (Analyzing... and the build progress) but fixing on my side will be a kludge!

@bwilkerson

This comment has been minimized.

Show comment
Hide comment
@bwilkerson

bwilkerson Feb 26, 2018

Member

Sorry for the delay in responding.

The instrumentation log doesn't explain why server is switching state to analyzing and back. It should be ignoring watch events for anything other than .dart or .yaml files, and I don't see those in the log.

Not knowing what's causing this, I don't know how easy it will be for anyone to fix. I suppose I would probably start by writing a test to try to reproduce the behavior. Without a way to reproduce it it will probably be fairly difficult to fix.

Member

bwilkerson commented Feb 26, 2018

Sorry for the delay in responding.

The instrumentation log doesn't explain why server is switching state to analyzing and back. It should be ignoring watch events for anything other than .dart or .yaml files, and I don't see those in the log.

Not knowing what's causing this, I don't know how easy it will be for anyone to fix. I suppose I would probably start by writing a test to try to reproduce the behavior. Without a way to reproduce it it will probably be fairly difficult to fix.

@DanTup

This comment has been minimized.

Show comment
Hide comment
@DanTup

DanTup Feb 27, 2018

Member

I think I found two causes!

In Driver there's a driver.hasFilesToAnalyze that checks _fileTracker.hasChangedFiles which checks a hashset it's keeping of files. That hashset contains files we don't want to analyze. Here's a stack of where they're added:

Adding file m:\Coding\Applications\flutter\examples\flutter_gallery\ios\Runner\GeneratedPluginRegistrant.m to changed files
#0      FileTracker.changeFile (package:analyzer/src/dart/analysis/file_tracker.dart:169:39)
#1      AnalysisDriver._changeFile (package:analyzer/src/dart/analysis/driver.dart:1119:18)
#2      AnalysisDriver.changeFile (package:analyzer/src/dart/analysis/driver.dart:567:5)
#3      ContextManagerImpl._handleWatchEventImpl (package:analysis_server/src/context_manager.dart:1479:18)
#4      ContextManagerImpl._handleWatchEvent (package:analysis_server/src/context_manager.dart:1356:5)
#5      _rootRunUnary (dart:async/zone.dart:1134)

Looking inside _handleWatchEventImpl in context_manager.dart there is some code handling adds that looks like:

if (resource is File) {
  File file = resource;
  if (_shouldFileBeAnalyzed(file)) {
    info.analysisDriver.addFile(path);
  }
}

Note the call to _shouldFileBeAnalyzed. However the code for modify is just:

case ChangeType.MODIFY:
  for (AnalysisDriver driver in driverMap.values) {
    driver.changeFile(path);
  }
  break;

So, I think cause 1 is that we're not checking files should be analyzed if they're modified. I think a fix would be wrapped the loop with:

Resource resource = resourceProvider.getResource(path);
if (resource is File) {
  File file = resource;
  if (_shouldFileBeAnalyzed(file)) {

(Note: as well as adding _shouldFileBeAnalyzed here, this is also adding a file check which doesn't exist before - I don't know if that's correct).

So, I changed that locally anyway and I still saw the issue (though on a smaller scale). So, I added some more logging and found:

+++ Analyzing.
	Adding file m:\Coding\Applications\flutter\examples\flutter_gallery\build\app\intermediates\assets\debug\flutter_assets\lib\gallery\example_code.dart to changed files
--- Analyzing in 740 ms.

So in this case, it is a dart file which is deployed as part of the build (it's the flutter gallery app which ships example code in a dart file into the app to show the user how things were achieved):

flutter:
  assets:
    - lib/gallery/example_code.dart

So, I'm not sure how that one can be fixed without some sort of assumption about the build folder.

@bwilkerson If the above to the file modification watching looks good, lmk and I'll submit a review for it. The second issue I'm not sure what you want to do - it's a complete fluke I happened to test with a project that has .dart files in its output. The impact here is much less (this is very unlikely), though I don't know if it's a waste of resources (or may result in sending errors to the editor) that we don't want.

Member

DanTup commented Feb 27, 2018

I think I found two causes!

In Driver there's a driver.hasFilesToAnalyze that checks _fileTracker.hasChangedFiles which checks a hashset it's keeping of files. That hashset contains files we don't want to analyze. Here's a stack of where they're added:

Adding file m:\Coding\Applications\flutter\examples\flutter_gallery\ios\Runner\GeneratedPluginRegistrant.m to changed files
#0      FileTracker.changeFile (package:analyzer/src/dart/analysis/file_tracker.dart:169:39)
#1      AnalysisDriver._changeFile (package:analyzer/src/dart/analysis/driver.dart:1119:18)
#2      AnalysisDriver.changeFile (package:analyzer/src/dart/analysis/driver.dart:567:5)
#3      ContextManagerImpl._handleWatchEventImpl (package:analysis_server/src/context_manager.dart:1479:18)
#4      ContextManagerImpl._handleWatchEvent (package:analysis_server/src/context_manager.dart:1356:5)
#5      _rootRunUnary (dart:async/zone.dart:1134)

Looking inside _handleWatchEventImpl in context_manager.dart there is some code handling adds that looks like:

if (resource is File) {
  File file = resource;
  if (_shouldFileBeAnalyzed(file)) {
    info.analysisDriver.addFile(path);
  }
}

Note the call to _shouldFileBeAnalyzed. However the code for modify is just:

case ChangeType.MODIFY:
  for (AnalysisDriver driver in driverMap.values) {
    driver.changeFile(path);
  }
  break;

So, I think cause 1 is that we're not checking files should be analyzed if they're modified. I think a fix would be wrapped the loop with:

Resource resource = resourceProvider.getResource(path);
if (resource is File) {
  File file = resource;
  if (_shouldFileBeAnalyzed(file)) {

(Note: as well as adding _shouldFileBeAnalyzed here, this is also adding a file check which doesn't exist before - I don't know if that's correct).

So, I changed that locally anyway and I still saw the issue (though on a smaller scale). So, I added some more logging and found:

+++ Analyzing.
	Adding file m:\Coding\Applications\flutter\examples\flutter_gallery\build\app\intermediates\assets\debug\flutter_assets\lib\gallery\example_code.dart to changed files
--- Analyzing in 740 ms.

So in this case, it is a dart file which is deployed as part of the build (it's the flutter gallery app which ships example code in a dart file into the app to show the user how things were achieved):

flutter:
  assets:
    - lib/gallery/example_code.dart

So, I'm not sure how that one can be fixed without some sort of assumption about the build folder.

@bwilkerson If the above to the file modification watching looks good, lmk and I'll submit a review for it. The second issue I'm not sure what you want to do - it's a complete fluke I happened to test with a project that has .dart files in its output. The impact here is much less (this is very unlikely), though I don't know if it's a waste of resources (or may result in sending errors to the editor) that we don't want.

@bwilkerson

This comment has been minimized.

Show comment
Hide comment
@bwilkerson

bwilkerson Feb 27, 2018

Member

The file modification looks good to me. Please add scheglov@ to the review; he's more familiar with this code than I am.

As for the other, I don't want to have an assumption about the build directory, but if it's a standard output location for Flutter apps, then it seems like we ought to handle it automatically. Is it always named build, or is it configurable?

(A short term work around would be for users to explicitly ignore the directory in the analysis options file.)

Member

bwilkerson commented Feb 27, 2018

The file modification looks good to me. Please add scheglov@ to the review; he's more familiar with this code than I am.

As for the other, I don't want to have an assumption about the build directory, but if it's a standard output location for Flutter apps, then it seems like we ought to handle it automatically. Is it always named build, or is it configurable?

(A short term work around would be for users to explicitly ignore the directory in the analysis options file.)

@devoncarew

This comment has been minimized.

Show comment
Hide comment
@devoncarew

devoncarew Feb 27, 2018

Member

It is the standard output location for flutter; it's not configurable. I'm not sure how I feel about hardcoding knowledge about build/ either, but will note that it's also the output location that pub build uses.

Member

devoncarew commented Feb 27, 2018

It is the standard output location for flutter; it's not configurable. I'm not sure how I feel about hardcoding knowledge about build/ either, but will note that it's also the output location that pub build uses.

@bwilkerson

This comment has been minimized.

Show comment
Hide comment
@bwilkerson

bwilkerson Feb 27, 2018

Member

I suppose for Flutter, we could add an "excludes" list that contains build (to the analysis options file) when generating a new project, but that will only help people that use flutter to create new projects. It won't help other Flutter uses, nor pub build users.

But if we hardcode the handling of build and have users that have non-generated code in build, then we'd stop analyzing it, with no way for them to work around it. And a unlikely as those conditions seem, we thought the same thing about users having a directory named packages and we saw that happen.

Member

bwilkerson commented Feb 27, 2018

I suppose for Flutter, we could add an "excludes" list that contains build (to the analysis options file) when generating a new project, but that will only help people that use flutter to create new projects. It won't help other Flutter uses, nor pub build users.

But if we hardcode the handling of build and have users that have non-generated code in build, then we'd stop analyzing it, with no way for them to work around it. And a unlikely as those conditions seem, we thought the same thing about users having a directory named packages and we saw that happen.

@DanTup

This comment has been minimized.

Show comment
Hide comment
@DanTup

DanTup Feb 27, 2018

Member

The file modification looks good to me

Cool; I'll try and put a failing test in first so this is covered. I can see a somewhat related test test_watch_modifyFile which is marked TODO without an assert so I'll see if I can make that work and then copy/adapt for this.

And a unlikely as those conditions seem, we thought the same thing about users having a directory named packages and we saw that happen.

Yeah, let's at least fix that one before we replace it with another :D

I have no strong opinion on this; I'm not concerned about it for the original issue (few people will have Dart files in their Flutter build output) but I don't know of other implications of it analysing build output, you two are much better positioned to decide than I. (Though I reserve the right to become upset about it if/when we one day have pub build in Dart Code ;-))

Member

DanTup commented Feb 27, 2018

The file modification looks good to me

Cool; I'll try and put a failing test in first so this is covered. I can see a somewhat related test test_watch_modifyFile which is marked TODO without an assert so I'll see if I can make that work and then copy/adapt for this.

And a unlikely as those conditions seem, we thought the same thing about users having a directory named packages and we saw that happen.

Yeah, let's at least fix that one before we replace it with another :D

I have no strong opinion on this; I'm not concerned about it for the original issue (few people will have Dart files in their Flutter build output) but I don't know of other implications of it analysing build output, you two are much better positioned to decide than I. (Though I reserve the right to become upset about it if/when we one day have pub build in Dart Code ;-))

@devoncarew

This comment has been minimized.

Show comment
Hide comment
@devoncarew

devoncarew Feb 27, 2018

Member

But if we hardcode the handling of build and have users that have non-generated code in build

Flutter does manage the build/ dir, and will delete content out of it (and, flutter clean will delete it completely). So, the problem of non-generated code in build will self-correct periodically :)

Member

devoncarew commented Feb 27, 2018

But if we hardcode the handling of build and have users that have non-generated code in build

Flutter does manage the build/ dir, and will delete content out of it (and, flutter clean will delete it completely). So, the problem of non-generated code in build will self-correct periodically :)

@bwilkerson

This comment has been minimized.

Show comment
Hide comment
@bwilkerson

bwilkerson Feb 27, 2018

Member

Minor edit:

So, the problem of non-generated code in {the build directory of a flutter package} will self-correct periodically.

If we can identify which packages are Flutter packages (such as by looking for a dependency on flutter), then we could use that to solve one part of the issue.

Is there a similar technique we can use to identify a package that is using pub build?

Member

bwilkerson commented Feb 27, 2018

Minor edit:

So, the problem of non-generated code in {the build directory of a flutter package} will self-correct periodically.

If we can identify which packages are Flutter packages (such as by looking for a dependency on flutter), then we could use that to solve one part of the issue.

Is there a similar technique we can use to identify a package that is using pub build?

@devoncarew

This comment has been minimized.

Show comment
Hide comment
@devoncarew

devoncarew Feb 27, 2018

Member

Not sure re: auto-detection, however, some options I can think of to address reacting to changes in the build/ folder:

Member

devoncarew commented Feb 27, 2018

Not sure re: auto-detection, however, some options I can think of to address reacting to changes in the build/ folder:

@DanTup

This comment has been minimized.

Show comment
Hide comment
@DanTup

DanTup Mar 1, 2018

Member

I've fixed the issue with non-Dart files trigger this in https://dart-review.googlesource.com/c/sdk/+/44421/

Do you want this case keeping open (or perhaps another creating?) for the build output folders?

Member

DanTup commented Mar 1, 2018

I've fixed the issue with non-Dart files trigger this in https://dart-review.googlesource.com/c/sdk/+/44421/

Do you want this case keeping open (or perhaps another creating?) for the build output folders?

dart-bot pushed a commit that referenced this issue Mar 1, 2018

Don't send modifications for files that should not be analyzed
Bug: #31564
Change-Id: I91b952cf8f47e5c8b8d12ef137cc2ef1575372d3
Reviewed-on: https://dart-review.googlesource.com/44421
Commit-Queue: Danny Tuppeny <danny@tuppeny.com>
Reviewed-by: Konstantin Shcheglov <scheglov@google.com>
Reviewed-by: Brian Wilkerson <brianwilkerson@google.com>

@bwilkerson bwilkerson added the type-bug label Sep 2, 2018

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment