Dart-code: Code Helper continuously runs at 400% CPU

[ened]

Issue Type: Performance Issue

May have started in the latest VSCode version.

Code Helper occasionally spikes to up to 400% CPU and entire system / VS Code is unresponsive.

Extension version: 3.0.1
VS Code version: Code 1.33.1 (51b0b28134d51361cf996d2f0a1c698247aeabd8, 2019-04-11T08:22:55.268Z)
OS version: Darwin x64 18.5.0

System Info

|Item|Value|
|---|---|
|CPUs|Intel(R) Core(TM) i7-6920HQ CPU @ 2.90GHz (8 x 2900)|
|GPU Status|2d_canvas: enabled
checker_imaging: disabled_off
flash_3d: enabled
flash_stage3d: enabled
flash_stage3d_baseline: enabled
gpu_compositing: enabled
multiple_raster_threads: enabled_on
native_gpu_memory_buffers: enabled
rasterization: enabled
surface_synchronization: enabled_on
video_decode: enabled
webgl: enabled
webgl2: enabled|
|Load (avg)|8, 6, 8|
|Memory (System)|16.00GB (0.47GB free)|
|Process Argv|packages/dashcam|
|Screen Reader|no|
|VM|0%|

Process Info

CPU %   Mem MB     PID  Process
   19       98   36447  code main
    0       98   36448     gpu-process
    0       82   36449     window (dashcam.dart — dashcam)
    0       33   36452       extensionHost
    0       33   36456         /Users/ened/dev/flutter/bin/cache/dart-sdk/bin/dart /Users/ened/dev/flutter/bin/cache/dart-sdk/bin/snapshots/analysis_server.dart.snapshot --client-id=Dart-Code.dart-code --client-version=3.0.1
    0        0   36457         bash /Users/ened/dev/flutter/bin/flutter daemon
    0       49   36473           /Users/ened/dev/flutter/bin/cache/dart-sdk/bin/dart /Users/ened/dev/flutter/bin/cache/flutter_tools.snapshot daemon
    2        0   95528             /bin/bash /Applications/Xcode.app/Contents/Developer/usr/bin/simctl list --json devices
    0       33   95529               /Applications/Xcode.app/Contents/Developer/usr/bin/xcodebuild -runFirstLaunch
    0       33   36453       watcherService
    0       66   36484     shared-process
    0      279   43251     window (dashcam_listener.dart — com.company.app)
    0     2916   43259       extensionHost
    0      508   43263         /Users/ened/dev/flutter/bin/cache/dart-sdk/bin/dart /Users/ened/dev/flutter/bin/cache/dart-sdk/bin/snapshots/analysis_server.dart.snapshot --client-id=Dart-Code.dart-code --client-version=3.0.1
    0        0   43264         bash /Users/ened/dev/flutter/bin/flutter daemon
    3       49   43279           /Users/ened/dev/flutter/bin/cache/dart-sdk/bin/dart /Users/ened/dev/flutter/bin/cache/flutter_tools.snapshot daemon
    0       66   43260       watcherService
    0       49   43262       searchService
    0        0   86131       /bin/bash -l
    0       82   95516     window (Issue Reporter)
    0        0   95530     /bin/ps -ax -o pid=,ppid=,pcpu=,pmem=,command=

Workspace Info

|  Window (dashcam_listener.dart — com.company.app)
|  Window (dashcam.dart — dashcam)
|    Folder (com.company.app): more than 26356 files
|      File types: xml(5478) flat(4601) json(2557) png(2186) h(1629) jar(984)
|                  dart(703) plist(569) m(458) swift(439)
|      Conf files: cmake(21) launch.json(11) settings.json(5) makefile(2)
|                  package.json(1)
|    Folder (dashcam): more than 21084 files
|      File types: class(2774) flat(2760) xml(2346) swift(1447) dex(1308)
|                  jar(1108) png(971) json(962) dart(762) h(539)
|      Conf files: launch.json(11) settings.json(6);

[ened]

Will collect further logs as instructed here: https://github.com/microsoft/vscode/wiki/Performance-Issues

[DanTup]

Can you try to run code --status in a terminal when the CPU is high? In the log above the total CPU only adds up to 24% and only 5% is in the Dart processes.

It also looks you were fairly low on RAM when you captured this ("16.00GB (0.47GB free)"), maybe that's why your system was running slow. Your log shows 2.9GB for the extension host (which sounds very high, though nowhere near 16GB) but it's not clear what's using that (the numbers in the tree don't come anywhere close). It'd be worth also trying to get a capture of what's using all the RAM when this happens.

[ened]

~ $ code --status
Version:          Code 1.33.1 (51b0b28134d51361cf996d2f0a1c698247aeabd8, 2019-04-11T08:22:55.268Z)
OS Version:       Darwin x64 18.5.0
CPUs:             Intel(R) Core(TM) i7-6920HQ CPU @ 2.90GHz (8 x 2900)
Memory (System):  16.00GB (0.33GB free)
Load (avg):       4, 4, 4
VM:               0%
Screen Reader:    no
Process Argv:     
GPU Status:       2d_canvas:                    disabled_software
                  checker_imaging:              disabled_off
                  flash_3d:                     disabled_software
                  flash_stage3d:                disabled_software
                  flash_stage3d_baseline:       disabled_software
                  gpu_compositing:              disabled_software
                  multiple_raster_threads:      enabled_on
                  native_gpu_memory_buffers:    enabled
                  rasterization:                disabled_software
                  surface_synchronization:      enabled_on
                  video_decode:                 disabled_software
                  webgl:                        disabled_off
                  webgl2:                       disabled_off

CPU %   Mem MB     PID  Process
    1       66    1737  code main
    0       66    1741     gpu-process
    0       33    2120     shared-process
    0      246   13875     window (company_news_view_state.dart — com.mycompany.connect)
  257     2146   13877       extensionHost
    0      459   13880         /Users/ened/dev/flutter/bin/cache/dart-sdk/bin/dart /Users/ened/dev/flutter/bin/cache/dart-sdk/bin/snapshots/analysis_server.dart.snapshot --client-id=Dart-Code.dart-code --client-version=3.0.2
    0        0   13881         bash /Users/ened/dev/flutter/bin/flutter daemon
    1       49   13898           /Users/ened/dev/flutter/bin/cache/dart-sdk/bin/dart /Users/ened/dev/flutter/bin/cache/flutter_tools.snapshot daemon
    0        0   16676         /Applications/Visual Studio Code.app/Contents/Frameworks/Code Helper.app/Contents/MacOS/Code Helper /Applications/Visual Studio Code.app/Contents/Resources/app/extensions/json-language-features/server/dist/jsonServerMain --node-ipc --clientProcessId=13877
    0        0   18462         electron_node server.js 
    0       66   26774         /Library/Java/JavaVirtualMachines/jdk1.8.0_192.jdk/Contents/Home/bin/java -Declipse.application=org.eclipse.jdt.ls.core.id1 -Dosgi.bundles.defaultStartLevel=4 -Declipse.product=org.eclipse.jdt.ls.core.product -Dfile.encoding=utf8 -noverify -Xmx1G -XX:+UseG1GC -XX:+UseStringDeduplication -jar /Users/ened/.vscode/extensions/redhat.java-0.44.0/server/plugins/org.eclipse.equinox.launcher_1.5.300.v20190213-1655.jar -configuration /Users/ened/.vscode/extensions/redhat.java-0.44.0/server/config_mac -data /Users/ened/Library/Application Support/Code/User/workspaceStorage/d667c5b2671ed0c6b6efdba67cbe11a5/redhat.java/jdt_ws
    0        0   60052         bash /Users/ened/dev/flutter/bin/flutter run --machine -t lib/main.dart -d HT83G1A03545 --track-widget-creation --start-paused
    0      147   60066           /Users/ened/dev/flutter/bin/cache/dart-sdk/bin/dart /Users/ened/dev/flutter/bin/cache/flutter_tools.snapshot run --machine -t lib/main.dart -d HT83G1A03545 --track-widget-creation --start-paused
    0        0   60210             /usr/local/opt/android-sdk/platform-tools/adb -s HT83G1A03545 shell -x logcat -v time
    0      459   60606             /Users/ened/dev/flutter/bin/cache/dart-sdk/bin/dart /Users/ened/dev/flutter/bin/cache/artifacts/engine/darwin-x64/frontend_server.dart.snapshot --sdk-root /Users/ened/dev/flutter/bin/cache/artifacts/engine/common/flutter_patched_sdk/ --incremental --strong --target=flutter --output-dill build/app.dill.track.dill --packages /Users/ened/git/com.mycompany.connect/.packages --track-widget-creation
    0       49   13878       watcherService
    0        0   14621       /bin/bash -l
    0       33   53647       searchService

Workspace Stats: 
|  Window (company_news_view_state.dart — com.mycompany.connect)
|    Folder (com.mycompany.connect): more than 22466 files
|      File types: xml(5171) flat(4377) json(2405) png(1630) jar(892)
|                  dart(715) h(675) swift(439) m(404) txt(399)
|      Conf files: cmake(22) launch.json(11) settings.json(5) makefile(2)
|                  package.json(1)
~ $ 

[ened]

0.33GB available RAM (I have seen the number go as low as 0.02GB). Code Helper does consume up to 2.5GB though. Will continue testing.

[DanTup]

It would be useful to try and get a profile of the Dart extension when this happens (run Show Running Extensions, select Dart then click the Start Profiling Extension Host button, let ot run for a while, then stop it and save it).

0.33GB available RAM (I have seen the number go as low as 0.02GB).

Having so little available memory is probably not going to help performance (it may result in a lot of paging) so I'd also use your OSes task manager/resource monitor to see if you have anything running consuming lots of RAM unnecessarily (the extension host here is using 2GB which isn't great, but is still a long way off 16GB).

[ened]

Dart-Code.dart-code-unresponsive.cpuprofile.txt
CPU-20190514T103159.882Z.cpuprofile.txt

[ened]

CPU-20190514T103441.332Z.cpuprofile.txt

May have been triggered by dartfmt. I frequently use Alt-Shift-F to clean up my code which may have caused the problem.

[ened]

Once the issue happens, auto-complete dies with it. May be the connection with the Dart process?

I'm using Flutter on the dev channel:

~ $ flutter doctor -v
[✓] Flutter (Channel dev, v1.5.8, on Mac OS X 10.14.4 18E226, locale en-US)
    • Flutter version 1.5.8 at /Users/ened/dev/flutter
    • Framework revision 0ba67226ee (3 weeks ago), 2019-04-24 17:18:28 -0700
    • Engine revision c63d1cf9c9
    • Dart version 2.3.0 (build 2.3.0-dev.0.1 1f1592edce)


[✓] Android toolchain - develop for Android devices (Android SDK version 28.0.3)
    • Android SDK at /usr/local/opt/android-sdk
    • Android NDK location not configured (optional; useful for native profiling support)
    • Platform android-28, build-tools 28.0.3
    • ANDROID_HOME = /usr/local/opt/android-sdk
    • Java binary at: /Applications/Android Studio.app/Contents/jre/jdk/Contents/Home/bin/java
    • Java version OpenJDK Runtime Environment (build 1.8.0_152-release-1343-b01)
    • All Android licenses accepted.

[!] iOS toolchain - develop for iOS devices (Xcode 10.2.1)
    • Xcode at /Applications/Xcode.app/Contents/Developer
    • Xcode 10.2.1, Build version 10E1001
    ✗ Verify that all connected devices have been paired with this computer in Xcode.
      If all devices have been paired, libimobiledevice and ideviceinstaller may require updating.
      To update with Brew, run:
        brew update
        brew uninstall --ignore-dependencies libimobiledevice
        brew uninstall --ignore-dependencies usbmuxd
        brew install --HEAD usbmuxd
        brew unlink usbmuxd
        brew link usbmuxd
        brew install --HEAD libimobiledevice
        brew install ideviceinstaller
    • ios-deploy 1.9.4
    • CocoaPods version 1.7.0.rc.1

[✓] Android Studio (version 3.4)
    • Android Studio at /Applications/Android Studio.app/Contents
    • Flutter plugin version 35.3.1
    • Dart plugin version 183.6270
    • Java version OpenJDK Runtime Environment (build 1.8.0_152-release-1343-b01)

[✓] VS Code (version 1.33.1)
    • VS Code at /Applications/Visual Studio Code.app/Contents
    • Flutter extension version 3.0.2

[✓] Connected device (1 available)
    • Pixel 2 • HT83G1A03545 • android-arm64 • Android 9 (API 28)

! Doctor found issues in 1 category.

[DanTup]

Thanks for the traces! I had a look through, and it didn't look too bad except for an instance showing around half a second being spent converting completions (we seem to be doing a lot of work, and the garbage collector seems to be running many times too):

It's possible the garbage collector is running because we're generating a lot of objects, but I also wonder if it's running more frequently because you don't have a lot of RAM (I can't find anything online documenting what triggers GC in V8 to confirm this).

Could you try disabling the auto-import completions (with the dart.autoImportCompletions) and see whether it seems to make any significant difference?

[DanTup]

By the way, what type of project do you have open? I noticed in the stats above there are a lot of files in your workspace:

Folder (com.company.app): more than 26356 files

Maybe if I can open a comparable project I can reproduce similar locally.

[ened]

By the way, what type of project do you have open? I noticed in the stats above there are a lot of files in your workspace:

Folder (com.company.app): more than 26356 files

Maybe if I can open a comparable project I can reproduce similar locally.

It's a mono-repo flutter project, which contains various modules in a packages/ folder.

/pubspec.yaml includes them via simple path: packages/xxx references.

[ened]

So far so good after setting dart.autoImportCompletions to false.

[DanTup]

It looks like you have two open folders (com.company.app and dashcam), is this a multi-root workspace, or just a single workspace with two top level folders? Are they both Flutter projects?

So far so good after setting dart.autoImportCompletions to false.

How confident are you that it has made a difference - would you normally have seen the issue occur by now? If so, I'll take a look at what we can do to optimise this. I guess it doesn't scale particularly well - the larger your project, the more unimported symbols there are going to be, and we need to convert them all from server objects into VS Code's API objects.

[ened]

The root project is a Flutter App projects.

The packages in the packages/ folder are all Flutter plugin projects with native code portions, and their own example folder app projects etc.

Will continue working today and submit feedback later on.

[ened]

@DanTup Your suggestion improved performance significantly. Although I miss the new auto-completer, the IDE is responsive again.

[DanTup]

Thanks for the feedback - I'll see what I can do to improve the performance of this for the next version. Sorry for the inconvenience!

[DanTup]

@ened I'm unable to reproduce poor performance on this bit of code, even on a large project. I suspect being low on RAM may be a factor.

I have made some changes that may help, but it's hard to verify. Would you be able to test them for me?

You can download a VSIX build from here:

https://github.com/Dart-Code/Dart-Code/releases/tag/v3.1.0-alpha.completion-perf.1

Instructions for installing it are here:

https://dartcode.org/docs/installing-a-preview-release/

You can see the changes it makes here:

https://github.com/Dart-Code/Dart-Code/commit/b30b1d7f1b0491c43b3f498d479a11d97a311508

It doesn't improve the performance of processing the completions, however it will now skip that processing if VS Code has told us completion has cancelled. This may help in the case where VS Code asks us for completions, we start the work, then VS Code cancels (eg. the document changed such that it wanted us to re-compute completions, or you closed completion, etc). Previously we would still process the results once they arrived (ignoring the cancellation).

If your issue was a result of completion requests backing up, this might help.

I'll keep looking, but do let me know if this seems to make any difference at all.

[DanTup]

@ened I found a serious memory leak in VS Code recently, which may have contributed to this issue. It's been fixed by the VS Code team and is shipping in v1.35 (which I believe is planned to release tomorrow - but I don't know if it'll slip).

https://github.com/microsoft/vscode/issues/74446

Please let me know if you're still seeing perf issues on that release.

[ened]

@DanTup So far so good! Have not been able to find issues in 1.35 after a few hours of coding.
Also re-enabled dart.autoImportCompletions.

Closing for now and will open now issue if it reappears.

Thank you!

[DanTup]

Great! Hopefully it was the same issue then, but do shout if you see it again and we'll dig some more. Thanks!