Analysis painfully slow in IntelliJ after update

[johnniwinther]

Having updated IntelliJ to version 2016.3.2, Dart plugin to version 163.11306 and Dart SDK to 1.22.0-dev.6.0
analysis has become painfully slow.

Changes like signature changes or removing/added interface members trigger reanalysis of a huge number of (sometimes completely unaffected) files often taking ~15 seconds, sometimes up to ~1 minute.

[dgrove]

@bwilkerson is the analysis driver on in this version?

[bwilkerson]

The analysis driver was enabled by 7e560a6. As far as I can see, that means that it was enabled in dev.6.0.

[scheglov]

Could you please provide more details - which folders you have open in IDEA, files of which packages you change, example of a change, what you see.

If you see that unrelated files are analyzed, also please provide examples. If files are really unrelated, meaning that their library import/export closure does not include the changed file, then analysis results are served from the cache on the file system. I'd like to verify how it works in your example.

As an experiment I opened pkg/compiler and made several changes. For example I changed SourceFile to SourceFile2. It took Analysis Server 8782 ms to analyze. That's not so much IMHO. And with the new analysis driver background analysis does not preclude other features, like search and refactoring.

[johnniwinther]

I have pkg/compiler and tests/compiler/dart2js/ open in one "dart2js+unittests" project.

Remove/reinserting 'MemberEntity.isAssignable' in pkg/compiler/lib/src/elements/entities.dart trigger reanalysis of pkg/compiler/lib/src/util/setlet.dart and tests/compiler/dart2js/sha1_test.dart (none of the files opened in the editor when doing the change).

I normally have two "dart2js+unittests" projects open for two different checkouts of the repository. This sometime confuses the analyser (thinking files from one repo is used in the other). The observations above were made both with one and two projects open at a time.

[scheglov]

Unfortunately I cannot reproduce the performance problem.
Here is some statistics that I observe:

Start cold: 33242 ms
Start cached: 3157 ms
Remove 'MemberEntity.isAssignable': 20766 ms
Restore: 198 ms
Remove again: 188 ms
Restore again: 194 ms

The new analysis server keeps results of analysis cached on disk, in ~/.dartServer/.analysis-driver folder. So, when you rollback some changes to already seen state, analysis results are quickly restored. Could you verify that you have this folder and it has files?

Actually pkg/compiler/lib/src/util/setlet.dart and tests/compiler/dart2js/sha1_test.dart DOES depend on the file pkg/compiler/lib/src/elements/entities.dart, see the attach with the transitive closure of files - all 388 of them.

What would happen if you try to ignore the fact that analysis is performed in background?
Do you see that some features don't work for you?

sha1_test_transitive.txt

[johnniwinther]

The .analysis-driver folder exists, currently holding 1.6Mb in 235344 files.

Regarding features, some are no longer working; must annoyingly the link from class to subclasses is gone (so I have to search for 'extends ClassName') and the link to overriding methods is also gone.

[scheglov]

Hm... 1.6Mb is way too low for such number of files. Are the most of the files empty?

Yes, subclass and implementation indicators are not implemented. This feature require multiple search requests, which might be too expensive. Do you have other problems with features and their performance in an open file?

For subclasses and method implementations there is an explicit action Navigate | Implementation(s). Explicit actions are OK, because when the user explicitly request something, she can wait a bit.

[bwilkerson]

FWIW, I really think we need to restore these indicators. I think it's a major usability regression (it certainly is for me).

[dgrove]

Is it worth tarring up this directory so that that Konstantin can take a look?

…

On Thu, Jan 19, 2017 at 8:54 AM, Brian Wilkerson ***@***.***> wrote: FWIW, I really think we need to restore these indicators. I think it's a major usability regression (it certainly is for me). — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#28383 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/ACAsW9jgWQntnXfKBOS3TYUWdKLgRZYqks5rT5U7gaJpZM4Li-OQ> .

[johnniwinther]

Do you need more information from me? I'm still seeing these minute long analyses - seriously degrading my work flow.

[scheglov]

If features - errors, semantic highlighting, navigation, completion, search and refactoring work in the current file fast enough, then no. We think that it's OK for background analysis to take time.

If features don't work in the current file, then yes, it's a problem.

Could you please clarify which is your situation regarding to the current file editing?

[johnniwinther]

As soon as I start editing it fires of a huge analysis leaving the current file with no assistance - and often with errors "hanging" with a message like "FooMix is not a class..." when long after I have typed the full word "FooMixin".

[scheglov]

Yeah, that's pretty bad.

Let's look into details.

I need you to turn logging.

• In IntelliJ, Ctrl-Shift-A
• Search for ‘Registry…’
• In dart.server.additional.arguments, add ‘--enable-new-analysis-driver’
• Turn on saving instrumentation into a file: --instrumentation-log-file=/Users/scheglov/tmp/server-logs/instrumentation.log
• Turn on the driver log: --new-analysis-driver-log=file:/path/to/analysis-driver.log

Then, when you see a problem with performance, or stale errors, archive both files and deliver them to me with a description what you see. Remove the files and restart Analysis Server to get new files with fresh problems smaller.

[johnniwinther]

Where should I add the --instrumentation-log-file and --new-analysis-driver-log options?

[bwilkerson]

Also in dart.server.additional.arguments.

[johnniwinther]

If I set dart.server.addition.arguments to

--enable-new-analysis-driver --instrumentation-log-file=c:/Users/johnniwinther/tmp/server-logs/instrumentation.log --new-analysis-driver-log=file:///C:/Users/johnniwinther/tmp/analysis-logs/analysis-driver.log

the 'Dart Analysis' view remain empty (crashed perhaps?)

[bwilkerson]

Were either of the log files created?

[johnniwinther]

No.

[bwilkerson]

Then I'd try running the server from the command-line to see what output does get produced.

[johnniwinther]

How? We're the executable?

[bwilkerson]

You can run server from the command line using

<sdk>/bin/dart <sdk>/bin/snapshots/analysis_server.dart.snapshot

(where <sdk> is the path to your sdk).

I tried the arguments you gave on my machine (modified to match my directory structure) and it worked fine. But I noticed that you passed in a path for the instrumentation log that uses forward slashes rather than backward slashes, even though it appears that you're running on Windows. I suspect that this path is used as a path rather than a URI, so we might well be getting an exception when we try to open that file.

[johnniwinther]

Apparently both paths have to be of the form c:\dir\file and c:\dir must exist.

[bwilkerson]

Does that mean that you got it running? Was there any output?

[bobjackman]

Any updates on this? I'm still experiencing similar slowness on Windows 10 (only a single repo inside a single project)

[johnniwinther]

I'm a bit concerned about the approach of storing analysis in a lot of (small) files (in AppData\Local\.dartServer\.analysis-driver on Windows). Current my folder contains 190084 files and just loading the directory content in Windows Explorer or Total Commander takes a couple of seconds. In practice I often see the harddrive as the bottle-neck of my system and dart.exe is often one of the top images in the 'Disk Activity' in 'Resource Monitor'.

[scheglov]

At least on Mac and Linux speed of listing many files in the command line, or the more so in UI tool (which would do a lot more processing, like fetching icons, associations, creating widgets) does not correlate with the speed of opening individual files for writing or reading. So, while it would be possible to implement our own file system in single physical file, I think that the file system service is one of the main tasks for operating systems, and it is not wise to compete with them.

The fact that there is a lot of IO might be a sing that there is a lot of analysis done, and results are written to disk. Can you see whether this is mostly read or write? How much bytes are read and how much is written. Analysis Server has in-memory cache for reading, so for not too large projects almost everything what current analysis roots need gets eventually read into memory and we don't perform a lot of reads from disk. OTOH, when we analyze, we have to write new results in order to be able to reuse them between restarts and if in-memory cache overflows.

[bwilkerson]

Assumed stale.

[supermuka]

This problem on Windows occurs yet. The workaround is delete frequently all files on AppData\Local.dartServer.analysis-driver

[bobjackman]

+1 still slow for me on windows10 as well

[gctommy]

Originally Posted by @supermuka

This problem on Windows occurs yet. The workaround is delete frequently all files on AppData\Local.dartServer.analysis-driver

Thanks for mentioning this. That folder for me was more than a gigabyte, cleared it out and now the dart analyzing takes about 5 seconds instead 10-15 minutes stalling on a few files. No more slow dart analysis!

Added this to my clean command:

flutter packages get && flutter packages upgrade && flutter clean && del /q "C:\Users\Tommy\AppData\Local\.dartServer\.analysis-driver\*"

[dgrove]

Reopening.

[scheglov]

That's interesting information.

Where is your AppData\Local\.dartServer\.analysis-driver located?
Is it on local disk? Or somewhere on network?

The whole point of this file system cache is to provide results reasonably fast. Is it a know problem on Windows, that large directories cause problems with opening and reading files from them and / or writing new files? I myself don't see problems with reading / writing / deleting files in large directories under Windows 7. And correspondingly Analysis Server in IntelliJ works fast there. However I don't have Windows 10 to try.

[supermuka]

The directory is on local disk. The full path is: D:\Users\MyUser\AppData\Local\.dartServer\.analysis-driver
Using Windows 7 (6.1.7601).

[scheglov]

I don't know what's going on.
We need more information.

Open Registry... action in your IDEA.
In this dialog find dart.server.vm.options option and give it the following value: --observe --max_profile_depth=256 --collect_code=false --code_comments=true --old_gen_growth_rate=2800 --pause_isolates_on_unhandled_exceptions=false. Restart Analysis Server. This will start Observatory profiler, at 127.0.0.1:8181. Open it, after the slow down go to cpu profile (table) and try to find what happens, and why. Post here data that you find interesting. This is exploratory process, it is hard to say what exactly to look for. Maybe I/O, maybe some analysis parts.

[supermuka]

When IntelliJ is opened and the process Analyzing is running, a snapshopt of the partial cpu profile (table) on Observatory:

Directory D:\Users\MyUser\AppData\Local\.dartServer\.analysis-driver information (pt-BR):

Timeline (hh:mm:ss) on IntelliJ:

13:13:00 started IntelliJ

OPEN PROJECT 1 (default)
13:13:45 loading project started
13:14:45 analyzing... started
13:16:45 analyzing finished (# 2:00).

OPEN PROJECT 2
13:17:15 loading project started
13:17:45 analyzing... started
13:21:00 analyzing finished (# 3:15).

Environment:
Windows 7 (6.1.7601) x64 .
Dart 2.1
Analyzer 0.34.0
Intel i7
RAM 8GB

Important: The analyzer is slow when IntelliJ is first opened after Windows restarts. If IntelliJ is closed and reopened (without restarting Windows), the parser runs quickly.

[scheglov]

@supermuka
It definitely looks like very slow I/O, and after first run it gets cached, so the next analysis is fast.

I don't have any good solution for this, other than clearing the cache :-(

It might be that the solution that works well on Mac and Linux does not work so well on (all? some?) Windows computers. Specifically it might be that having many files in one directory is somehow too heavy for Windows. Or maybe the cache clean up isolate that lists all files in the cache, checks access stamps, and removes old files; that it prevents / radically slows down reading the cache in the main DAS isolate.

@zanderso do you have any experience with Windows I/O, or maybe know who worked on Windows I/O in Dart VM? Are there any know pitfalls, conflicts, locks in Windows I/O in Dart?

[scheglov]

It might be also caused by having too many files in a single directory, about 140,000 on my Mac, and similar number in the Win 7 VM.

I'm going to try perform sharing using two levels of intermediate directories, based on the first and the second letter of keys. All keys are currently MD5 hashes, so this should give even distribution.

[scheglov]

I landed the change that uses one-level, two-characters sharding.
I tested it on Windows, and it seems to work.
But I had never had the performance problem that you see.

Could you download the bleeding edge build of Dart VM and give it a try?
https://storage.googleapis.com/dart-archive/channels/be/raw/latest/sdk/dartsdk-windows-x64-release.zip

[zanderso]

Yes, in general file IO is slow on Windows, especially in a directory with lots of files. Out of curiosity, though it probably doesn't make a difference, is this directory populated with regular files or symlinks?

[scheglov]

@zanderso Good to know, thanks! The directory has only regular files.

[scheglov]

@supermuka @johnniwinther @kogi Have you tried a bleeding edge build, with sharding analysis cache into multiple directories? Does it make things better?

[zanderso]

More details: microsoft/WSL#873 (comment)

[scheglov]

Thanks, this link has interesting information.
It was sent to me several days ago, because of this issue, and I read it.

Not sure what conclusions I should make from this, and what actions.
Yes, the file system in Windows is slower, and sometimes unpredictably.
Maybe if the sharding approach does not help, we would have to try something else.

For example using single cache file with database like page managing in it, so that we don't have to open and close files often, make access time requests, etc. It was really easy to use file system to ensure that read/write operation are atomic, but then I don't work on Windows, so don't feel if it causes any pain.

[bobjackman]

I've been away for the holidays and haven't had a chance to test with your bleeding edge build, yet. However, I checked the cache directory and confirmed what @gctommy reported. The cache directory was at 1.2+ gigs and after deleting it, analysis in my project is lightning fast again! It hasn't slowed down, yet, but when it does, I'll give the bleeding edge build you posted.

…

[supermuka]

@scheglov, with ~ 88k files in ..\AppData\Local\.dartServer\.analysis-driver, before with just this folder the analizer took 3m15s. Now using the above build, with similar number of files distributed in 256 sub-folders that were created, is taking 40 seconds all the process analyzer since start and finish (based on the messages displayed in IntelliJ). It's fast now.

[kinex]

I had similar issue with VS Code, it was painfully slow. After each hot reload the whole UI hanged for tens of seconds. It was practically unusable. Deleting all files in ..\AppData\Local\.dartServer\.analysis-driver fixed the issue.