A case of constant CPU usage

[vbfox]

So I started my investigation by noticing some nice RED power usage in Task Manager when I was doing something else than F#

Turns out it's an FSAC connected to Ionide in VSCode with my https://github.com/vbfox/MasterOfFoo project open... The CPU never goes down, always ~20%

Attaching a debugger show a constant barrage of background parsing :

fsautocomplete.exe Information: 0 : FCS: Unknown.TimeStampReferencedProject(g:\Code\MasterOfFoo\artifacts\BlackFox.MasterOfFoo\netstandard2.0\BlackFox.MasterOfFoo.dll).TryGetLogicalTimeStampForProject.CreateOneIncrementalBuilder (g:\Code\MasterOfFoo\src\BlackFox.MasterOfFoo\BlackFox.MasterOfFoo.fsproj)
fsautocomplete.exe Information: 0 : Reactor: 81,705.710 <-- Unknown.GetBackgroundCheckResultsForFileInProject, took 12.5769 ms
fsautocomplete.exe Information: 0 : Reactor: 81,705.711 pausing 10 milliseconds
fsautocomplete.exe Information: 0 : Reactor: 81,705.713 --> Unknown.GetBackgroundCheckResultsForFileInProject (g:\Code\MasterOfFoo\src\BlackFox.MasterOfFoo\FormatSpecification.fs), remaining 9
fsautocomplete.exe Information: 0 : FCS: Unknown.CreateOneIncrementalBuilder (g:\Code\MasterOfFoo\src\BlackFox.MasterOfFoo\BlackFox.MasterOfFoo.fsproj)
fsautocomplete.exe Information: 0 : Reactor: 81,705.731 enqueue Unknown.GetBackgroundCheckResultsForFileInProject (g:\Code\MasterOfFoo\src\BlackFox.MasterOfFoo\obj\Debug\net45\BlackFox.MasterOfFoo.AssemblyInfo.fs), length 9
fsautocomplete.exe Information: 0 : Reactor: 81,705.738 enqueue Unknown.GetBackgroundCheckResultsForFileInProject (g:\Code\MasterOfFoo\artifacts\Version.fs), length 10
fsautocomplete.exe Information: 0 : Reactor: 81,705.768 enqueue Unknown.GetBackgroundCheckResultsForFileInProject (g:\Code\MasterOfFoo\src\BlackFox.MasterOfFoo\FormatSpecification.fs), length 11
fsautocomplete.exe Information: 0 : Reactor: 81,705.768 <-- Unknown.GetBackgroundCheckResultsForFileInProject, took 54.5193 ms
fsautocomplete.exe Information: 0 : Reactor: 81,705.792 pausing 10 milliseconds
fsautocomplete.exe Information: 0 : Reactor: 81,705.793 --> Unknown.GetBackgroundCheckResultsForFileInProject (g:\Code\MasterOfFoo\src\BlackFox.MasterOfFoo\PrintableElement.fs), remaining 11
fsautocomplete.exe Information: 0 : Reactor: 81,705.812 enqueue Unknown.GetBackgroundCheckResultsForFileInProject (g:\Code\MasterOfFoo\src\BlackFox.MasterOfFoo\PrintableElement.fs), length 11
fsautocomplete.exe Information: 0 : Reactor: 81,705.812 <-- Unknown.GetBackgroundCheckResultsForFileInProject, took 17.3633 ms

Attaching a profiler show a single working thread doing things with a long tail of calls in TypeChecker (dotTrace file):

Ionide settings:

{
  "FSharp.showProjectExplorerIn": "fsharp",
  "FSharp.showCodeOutlineIn": "fsharp",
  "FSharp.codeOutline": false,
  "FSharp.minimizeBackgroundParsing": true,
  "FSharp.resolveNamespaces": false,
  "FSharp.externalAutocomplete": false,
  "FSharp.projectExplorer.autoReveal":"off",
  "FSharp.disableFailedProjectNotifications": true,
  "FSharp.lineLens.enabled": "always",
  "FSharp.showExplorerOnStartup": false
}

I didn't have language service requests debugging enabled so I'm not 100% sure that ionide wasn't the cause of the calls (But that would be surprising) enabling them live only give the websocket logs that looked like a repetition of the following lines :

[23:22:38 DEBUG] WebSocket message: '{"Kind":"errors","Data":{"File":"g:\\Code\\MasterOfFoo\\src\\BlackFox.MasterOfFoo\\FormatSpecification.fs","Errors":[]}}'
[23:22:38 DEBUG] WebSocket message: '{"Kind":"errors","Data":{"File":"g:\\Code\\MasterOfFoo\\src\\BlackFox.MasterOfFoo\\PrintableElement.fs","Errors":[]}}'
[23:22:38 DEBUG] WebSocket message: '{"Kind":"errors","Data":{"File":"g:\\Code\\MasterOfFoo\\src\\BlackFox.MasterOfFoo\\PrintfEnv.fs","Errors":[]}}'
[23:22:38 DEBUG] WebSocket message: '{"Kind":"errors","Data":{"File":"g:\\Code\\MasterOfFoo\\src\\BlackFox.MasterOfFoo\\Core.Helpers.fs","Errors":[]}}'
[23:22:38 DEBUG] WebSocket message: '{"Kind":"errors","Data":{"File":"g:\\Code\\MasterOfFoo\\src\\BlackFox.MasterOfFoo\\Core.FormatOptions.fs","Errors":[]}}'
[23:22:38 DEBUG] WebSocket message: '{"Kind":"errors","Data":{"File":"g:\\Code\\MasterOfFoo\\src\\BlackFox.MasterOfFoo\\Core.FormatString.fs","Errors":[]}}'
[23:22:38 DEBUG] WebSocket message: '{"Kind":"errors","Data":{"File":"g:\\Code\\MasterOfFoo\\src\\BlackFox.MasterOfFoo\\Core.FormatToString.fs","Errors":[]}}'
[23:22:38 DEBUG] WebSocket message: '{"Kind":"errors","Data":{"File":"g:\\Code\\MasterOfFoo\\src\\BlackFox.MasterOfFoo\\Core.PrintfBuilding.fs","Errors":[]}}'
[23:22:38 DEBUG] WebSocket message: '{"Kind":"errors","Data":{"File":"g:\\Code\\MasterOfFoo\\src\\BlackFox.MasterOfFoo\\Core.PrintfCache.fs","Errors":[]}}'
[23:22:38 DEBUG] WebSocket message: '{"Kind":"errors","Data":{"File":"g:\\Code\\MasterOfFoo\\src\\BlackFox.MasterOfFoo\\MasterOfFoo.fs","Errors":[]}}'
[23:22:38 DEBUG] WebSocket message: '{"Kind":"errors","Data":{"File":"g:\\Code\\MasterOfFoo\\src\\BlackFox.MasterOfFoo\\obj\\Debug\\net45\\BlackFox.MasterOfFoo.AssemblyInfo.fs","Errors":[]}}'
[23:22:38 DEBUG] WebSocket message: '{"Kind":"errors","Data":{"File":"g:\\Code\\MasterOfFoo\\artifacts\\Version.fs","Errors":[]}}'

The problem also doesn't reproduce on restart, so I guess nothing really actionable on this issue but I wanted the diagnostic info out there in case it happens to someone else and we can get more insight.

[cartermp]

I tried reproducing this by leaving it open a bit and typing up some more stuff in various files, but can't reproduce this

[Krzysztof-Cieslak]

I've seen this happen but can't find reliable reproduction.

[juselius]

I'm experiencing similar things, having serious performance issues with fsa.

I have a fairly complex project, consisting of 9 subprojects (using EF Core, WebSharper, some C#, yadda, yadda). I'm not able to open the whole solution at once, because fsa is then using 60-80% cpu constantly, and +4GB of memory after a while. If I work on a project, by project basis I'm able to get work done, but I must restart vscode every 30 min because of fsa memory and cpu usage.

I'm on NixOS 19.03pre165037.eebd1a92637, dotnet 2.2.101, ionide 3.30.0, vscode 1.30.2.

@cartermp or @Krzysztof-Cieslak: I can give you access to the code if you want to test (it's proprietary, but I trust you to treat like that)

[cartermp]

@juselius If you'd like, you can email me (phcart at microsoft dot com) with additional repro info or a copy of the project. I'm under NDA when communicating via email. If I profile it and find something, is it okay to post back here, or create a separate issue?

[juselius]

@cartermp I'll send you the repo in a few minutes. You can post here, no problem. There is nothing super secret about the project, it's just not open source.

[cartermp]

Thanks @juselius , I could reproduce high memory usage and pretty high CPU as well after doing a Find all References and modifying a single function. This was ~3 minutes after opening the solution.

The biggest culprit is the use of FSharp.Data. It's responsible for 1.5GB of large object heap allocations, which is enormous:

This specific problem is the same as these two:

dotnet/fsharp#5929
dotnet/fsharp#5931

Either the compiler or FSharp.Data or both have work to do to stop re-creating type provider instances over and over again. This also represents 6% of all CPU time in the sample, which is pretty wild considering that you'd only expect a type provider to be created once:

Another notable source of allocations in the compiler that showed up here has been fixed: dotnet/fsharp#6048

[cartermp]

After leaving the project open a bit longer and trying things again, I can confirm that memory and CPU usage is dominated by FSharp.Data here. Total CPU time is now 7% for the type provider instantiation path and the LOH allocations are now nearing 3GB (!!!!).

I'm pretty confident that issues here aren't going to be related to FSAC. We still need to investigate the type provider issue a bit more thoroughly. It's clear that having a separate process for running F# doesn't help much when this package is involved.

cc @dsyme

[juselius]

Glad you managed to pinpoint the problem. I've also had problems with SQLProvider, which I have deprecated in favor of EF Core.

I found a workaround for SQLProvider, which should work for FSharp.Data too: Refactor all TP dependent code into a small, independent project, build and pack as a nuget. Then use the a package reference instead of a project reference. The biggest problem is versioning. If you update the project and build a new nuget, but you don't update the version number (which is always a pain), the new package will not end up in the nuget cache. Then you end up with a scripting kluge to first remove the old nuget from ~/.nuget/packages/, rebuild and pack and install.

[juselius]

I removed every single type provider from the project, and use FSharp.Data.CsvFile.Load() for CVS parsing instead. Interestingly, FSAC still goes haywire with CPU consumption and huge 3+ GB memory usage.

[cartermp]

@juselius If you have another version you can share with me, I can look into it to see if there is another specific problem that hasn't bee filed already

[juselius]

@cartermp I'll send you a link in a moment.

[cartermp]

@juselius at least with the latest link, I'm still seeing the majority of work coming from Provided Types in the following scenario:

• Restore and build the project
• Open in VSCode
• Open up a few files
• Wait for CPU and memory to spike up (currently 12% CPU and 5.5 GB memory)

It's dominated by LOH allocations (1.3 GB) which ends up in constant GC churn that pauses the process. Working set memory is also dominated by this.

The good news that other issues (such as allocations from range comparisons) are fixed and should be available with F# 4.6.

Another thing to note is that the project parsing seems to sort of fail, or something, because I don't get IntelliSense in the project with Ionide. Perhaps something is caught in a bit of a loop, because CPU and memory usage keep going up with no visible effect.

[juselius]

Thanks for the update @cartermp! I'm really looking forward to 4.6 and anonymous records!

I'm not explicitly using any provided types, but perhaps FSharp.Data.CsvFile uses them internally?

As for the IntelliSense problem, my colleague figured it out: The root of problem is in the Entity Framework project, which is a C# project with a number of F# dependencies. The F# subprojects seem to make Ionide(?) lose track of where it is going. If you replace the F# code with C# code, everything works.

[cartermp]

@juselius Just wanted to let you know that the issues with Type Providers are now addressed. An update to FSharp.Compiler.Service is required, but with that + the latest FSharp.Data (which uses the latest Type Provider SDK), there should be notable reductions in memory usage.

[juselius]

Fantastic! I'll test it as soon as I have a chance. Thank you @cartermp!

[deyanp]

I have got the same problem, filed it with ionide though: ionide/ionide-vscode-fsharp#1117

How should I update FSharp.Compiler.Service? I dont have it referenced in my projects, I only have:

<PackageReference Include="FSharp.Core" Version="4.6.0" />
<PackageReference Include="Microsoft.Azure.DocumentDB.Core" Version="2.3.0" />
<PackageReference Include="Microsoft.Azure.Cosmos.Table" Version="1.0.1" />
<PackageReference Include="Microsoft.NET.Sdk.Functions" Version="1.0.27" />
<PackageReference Include="NewtonSoft.Json" Version="11.0.2" />
<PackageReference Include="TaskBuilder.fs" Version="2.1.0" />
<PackageReference Include="CosmoStore" Version="2.1.0" />
<PackageReference Include="CosmoStore.CosmosDb" Version="2.1.0" />

[Krzysztof-Cieslak]

I believe the issue (original issue reported by @vbfox) is solved in latest master / Ionide 4.0

[deyanp]

Just to note that after updating package references to FSharp.Core 4.6.2 my issue seems to be gone ...