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

100% CPU usage - Reproducible (caused by complex dependency graph passed to project cracker) #105

Open
deapsquatter opened this Issue Apr 21, 2016 · 44 comments

Comments

Projects
None yet
9 participants
@deapsquatter
Copy link

deapsquatter commented Apr 21, 2016

I originally logged this issue at the Ionide project ionide/ionide-vscode-fsharp#55 but I think it needs to be here. This issue may in fact be with the compiler.cracker project but I'll leave that to the experts.

This issue looks like some type of circular dependency with project references. The graph is as follow:

  1. Project A -> Project C
  2. Project A -> Project B
  3. Project B -> Project C

Loading the main.fs file in Project A with VS Code and Ionide pegs CPU at 100%. Removing any one of the project dependencies above from the relevant fsproj (A.fsproj or B.fsproj) file and the CPU remains normal. Limiting work to any .fs file(s) in Project B and/or Project C works fine with all project dependencies in place.

@rneatherway

This comment has been minimized.

Copy link
Member

rneatherway commented Apr 23, 2016

Hi @deapsquatter, this looks like a tricky one. Let's try ruling out the project cracker tool first. You can execute it directly like so:

mono ~/.emacs.d/elpa/fsharp-mode-<date>/bin/FSharp.Compiler.Service.ProjectCrackerTool.exe --text <path to>/MyProject.fsproj true

You will have to adjust the paths of course, the above is for a version installed with emacs.

@deapsquatter

This comment has been minimized.

Copy link

deapsquatter commented Apr 23, 2016

Thanks Robin. I actually tried that already. The projectcracker tool completes normally without much CPU usage. 

@rneatherway

This comment has been minimized.

Copy link
Member

rneatherway commented Apr 23, 2016

Hm, I don't see a circular dependency in your example actually.

Can you get a debug log from Ionide? If not, perhaps you could load the project in emacs and try getting one there (https://github.com/fsharp/emacs-fsharp-mode/#fsharp-ac-debug). If we can see the communication with the background process then we should be able to see what command is triggering the bad behaviour.

@deapsquatter

This comment has been minimized.

Copy link

deapsquatter commented Apr 25, 2016

See the output from Ionide below. The following commands are executed the moment I open Program.fs in Project A (Console.fsproj) and result in a pegged CPU.

[Extension Host] {"FileName":"/Users/kevinknoop/Projects/AutoTask/agentNext/console/Console.fsproj"}
[Extension Host] {"Kind":"project","Data":{"Project":"/Users/kevinknoop/Projects/AutoTask/agentNext/console/Console.fsproj","Files":["/Users/kevinknoop/Projects/AutoTask/agentNext/paket-files/sse/deapsquatter/FSharp.SSEClient/src/SSEClient.fs","/Users/kevinknoop/Projects/AutoTask/agentNext/console/AssemblyInfo.fs","/Users/kevinknoop/Projects/AutoTask/agentNext/console/Program.fs"],"Output":"/Users/kevinknoop/Projects/AutoTask/agentNext/console/bin/Debug/AEMAgent.exe","References":["/Users/kevinknoop/Projects/AutoTask/agentNext/agent.mac/bin/Debug/Agent.Mac.dll","/Users/kevinknoop/Projects/AutoTask/agentNext/agent.mac/bin/Debug/Agent.Mac.dll","/Users/kevinknoop/Projects/AutoTask/agentNext/agent/bin/Debug/Agent.dll","/Users/kevinknoop/Projects/AutoTask/agentNext/agent/bin/Debug/Agent.dll","../packages/FSharp.Control.Reactive/lib/net40/FSharp.Control.Reactive.dll","../packages/FSharp.Core/lib/net40/FSharp.Core.dll","../packages/NLog.FSharp/lib/net40/NLog.FSharp.dll","../packages/NLog/lib/net40/NLog.dll","../packages/Newtonsoft.Json/lib/net40/Newtonsoft.Json.dll","../packages/SnmpSharpNet/lib/SnmpSharpNet.dll","/Library/Frameworks/Mono.framework/Versions/4.4.0/lib/mono/4.0-api/System.Core.dll","/Library/Frameworks/Mono.framework/Versions/4.4.0/lib/mono/4.0-api/System.Numerics.dll","../packages/Rx-Core/lib/net40/System.Reactive.Core.dll","../packages/Rx-Interfaces/lib/net40/System.Reactive.Interfaces.dll","../packages/Rx-Linq/lib/net40/System.Reactive.Linq.dll","/Library/Frameworks/Mono.framework/Versions/4.4.0/lib/mono/4.0-api/System.dll","/Users/kevinknoop/Projects/AutoTask/agentNext/util/bin/Debug/Util.dll","/Users/kevinknoop/Projects/AutoTask/agentNext/util/bin/Debug/Util.dll","/Library/Frameworks/Mono.framework/Versions/4.4.0/lib/mono/4.0-api/mscorlib.dll"],"Logs":{"/Users/kevinknoop/Projects/AutoTask/agentNext/agent.mac/../agent/Agent.fsproj":"","/Users/kevinknoop/Projects/AutoTask/agentNext/console/../agent.mac/Agent.Mac.fsproj":"","/Users/kevinknoop/Projects/AutoTask/agentNext/console/../agent/Agent.fsproj":"","/Users/kevinknoop/Projects/AutoTask/agentNext/console/Console.fsproj":""}}}
[Extension Host] {"FileName":"/Users/kevinknoop/Projects/AutoTask/agentNext/console/Program.fs","IsAsync":true,"Lines":["REDACTED CODE","  0","",""]}
[Extension Host] {"Kind":"errors","Data":[]}

@kjnilsson

This comment has been minimized.

Copy link
Contributor

kjnilsson commented Apr 25, 2016

Hi,

I too have seen this behaviour for a project reference graph as described
but have not had time to create a minimal repro. It is not a circular
dependency issue more that a project is referencing the same project as one
of it's dependencies, in the example above both project A and B directly
reference C with A also referencing B directly. I can't quite recall from
my testing but I suspect the issue occurs on the 'project' call.

Cheers
Karl

On Mon, 25 Apr 2016 at 09:25 deapsquatter notifications@github.com wrote:

See the output from Ionide below. The following commands are executed the
moment I open Program.fs in Project A (Console.fsproj) and result in a
pegged CPU.

[Extension Host] {"FileName":"/Users/kevinknoop/Projects/AutoTask/agentNext/console/Console.fsproj"}
[Extension Host] {"Kind":"project","Data":{"Project":"/Users/kevinknoop/Projects/AutoTask/agentNext/console/Console.fsproj","Files":["/Users/kevinknoop/Projects/AutoTask/agentNext/paket-files/sse/deapsquatter/FSharp.SSEClient/src/SSEClient.fs","/Users/kevinknoop/Projects/AutoTask/agentNext/console/AssemblyInfo.fs","/Users/kevinknoop/Projects/AutoTask/agentNext/console/Program.fs"],"Output":"/Users/kevinknoop/Projects/AutoTask/agentNext/console/bin/Debug/AEMAgent.exe","References":["/Users/kevinknoop/Projects/AutoTask/agentNext/agent.mac/bin/Debug/Agent.Mac.dll","/Users/kevinknoop/Projects/AutoTask/agentNext/agent.mac/bin/Debug/Agent.Mac.dll","/Users/kevinknoop/Projects/AutoTask/agentNext/agent/bin/Debug/Agent.dll","/Users/kevinknoop/Projects/AutoTask/agentNext/agent/bin/Debug/Agent.dll","../packages/FSharp.Control.Reactive/lib/net40/FSharp.Control.Reactive.dll","../packages/FSharp.Core/lib/net40/FSharp.Core.dll","../packages/NLog.FSharp/lib/net40/NLog.FSharp.dll","../packages
/NLog/li
b/net40/NLog.dll","../packages/Newtonsoft.Json/lib/net40/Newtonsoft.Json.dll","../packages/SnmpSharpNet/lib/SnmpSharpNet.dll","/Library/Frameworks/Mono.framework/Versions/4.4.0/lib/mono/4.0-api/System.Core.dll","/Library/Frameworks/Mono.framework/Versions/4.4.0/lib/mono/4.0-api/System.Numerics.dll","../packages/Rx-Core/lib/net40/System.Reactive.Core.dll","../packages/Rx-Interfaces/lib/net40/System.Reactive.Interfaces.dll","../packages/Rx-Linq/lib/net40/System.Reactive.Linq.dll","/Library/Frameworks/Mono.framework/Versions/4.4.0/lib/mono/4.0-api/System.dll","/Users/kevinknoop/Projects/AutoTask/agentNext/util/bin/Debug/Util.dll","/Users/kevinknoop/Projects/AutoTask/agentNext/util/bin/Debug/Util.dll","/Library/Frameworks/Mono.framework/Versions/4.4.0/lib/mono/4.0-api/mscorlib.dll"],"Logs":{"/Users/kevinknoop/Projects/AutoTask/agentNext/agent.mac/../agent/Agent.fsproj":"","/Users/kevinknoop/Projects/AutoTask/agentNext/console/../agent.mac/Agent.Mac.fsproj":"","/Users/kevinknoop/
Projects
/AutoTask/agentNext/console/../agent/Agent.fsproj":"","/Users/kevinknoop/Projects/AutoTask/agentNext/console/Console.fsproj":""}}}
[Extension Host] {"FileName":"/Users/kevinknoop/Projects/AutoTask/agentNext/console/Program.fs","IsAsync":true,"Lines":["REDACTED CODE"," 0","",""]}
[Extension Host] {"Kind":"errors","Data":[]}


You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub
#105 (comment)

@deapsquatter

This comment has been minimized.

Copy link

deapsquatter commented Apr 25, 2016

Thanks Karl - apologies for using the term "circular dependency" above. Your description of the problem is more accurate.

@kjnilsson

This comment has been minimized.

Copy link
Contributor

kjnilsson commented Apr 25, 2016

No worries - I really should have raised this myself a few weeks ago but
got snowed under with actual work. :)

I've set up a minimal github repo with the structure but can't test right
now if it actually reproduces the issue or not.

https://github.com/kjnilsson/fsac_issue_105

Karl

On Mon, 25 Apr 2016 at 09:35 deapsquatter notifications@github.com wrote:

Thanks Karl - apologies for using the term "circular dependency" above.
Your description of the problem is more accurate.


You are receiving this because you commented.

Reply to this email directly or view it on GitHub
#105 (comment)

@deapsquatter

This comment has been minimized.

Copy link

deapsquatter commented Apr 25, 2016

@kjnilsson I've just tested your repo above and I'm seeing the exact same issue. Pegged CPU after opening Library1.fs in A.fsproj.

@kjnilsson

This comment has been minimized.

Copy link
Contributor

kjnilsson commented Apr 25, 2016

Great! thanks

On Mon, 25 Apr 2016 at 10:03 deapsquatter notifications@github.com wrote:

@kjnilsson https://github.com/kjnilsson I've just tested your repo
above and I'm seeing the exact same issue. Pegged CPU after opening
Library1.fs in A.fsproj.


You are receiving this because you were mentioned.

Reply to this email directly or view it on GitHub
#105 (comment)

@rneatherway

This comment has been minimized.

Copy link
Member

rneatherway commented Apr 25, 2016

I've also just tested it in Emacs with fsautocomplete 28.0 and everything is working fine here, no pegged CPU. I am running on Linux by the way.

@deapsquatter

This comment has been minimized.

Copy link

deapsquatter commented Apr 25, 2016

@rneatherway What version of Mono you on? Here is mine for the record:

Mono JIT compiler version 4.4.0 (mono-4.4.0-branch/a3fabf1 Fri Apr  8 13:48:29 EDT 2016)
Copyright (C) 2002-2014 Novell, Inc, Xamarin Inc and Contributors. www.mono-project.com
    TLS:           normal
    SIGSEGV:       altstack
    Notification:  kqueue
    Architecture:  x86
    Disabled:      none
    Misc:          softdebug
    LLVM:          yes(3.6.0svn-mono-master/a173357)
    GC:            sgen
@rneatherway

This comment has been minimized.

Copy link
Member

rneatherway commented Apr 25, 2016

$ mono --version
Mono JIT compiler version 4.2.2 (Stable 4.2.2.30/996df3c Mon Feb 15 17:30:30 UTC 2016)
Copyright (C) 2002-2014 Novell, Inc, Xamarin Inc and Contributors. www.mono-project.com
    TLS:           __thread
    SIGSEGV:       altstack
    Notifications: epoll
    Architecture:  amd64
    Disabled:      none
    Misc:          softdebug 
    LLVM:          supported, not enabled.
    GC:            sgen
@deapsquatter

This comment has been minimized.

Copy link

deapsquatter commented Apr 25, 2016

Thanks - I may try going back to that version just to test. Do you know if Emacs issues the same command sequence to fsautocomplete as above? Looks like `project' and then 'errors'.

@kjnilsson

This comment has been minimized.

Copy link
Contributor

kjnilsson commented Apr 25, 2016

which version of fsautocomplete is ionide using?

@rneatherway

This comment has been minimized.

Copy link
Member

rneatherway commented Apr 25, 2016

It looks like this:

1461578647.580155: project "/home/robin/dev/other/fsac_issue_105/A/A.fsproj"
1461578648.2307925: {"Kind":"project","Data":{"Project":"/home/robin/dev/other/fsac_issue_105/A/A.fsproj","Files":["/ho ...
1461578648.2310934: Received 'project' message of length 65
1461578648.5963056: Parsing "/home/robin/dev/other/fsac_issue_105/A/Library1.fs"
1461578649.5252402: {"Kind":"info","Data":"Background parsing started"}
1461578649.5253167: Received 'info' message of length 65
1461578649.5253382: {"Kind":"errors","Data":[]}
1461578649.5253701: Received 'errors' message of length 65
@rneatherway

This comment has been minimized.

Copy link
Member

rneatherway commented Apr 25, 2016

The errors message comes as an asynchronous response to the parse command.

@deapsquatter

This comment has been minimized.

Copy link

deapsquatter commented Apr 25, 2016

Maybe @Krzysztof-Cieslak can chime in here on the version. Although looks like it may in fact be a fork https://github.com/ionide/FsAutoComplete

@kjnilsson

This comment has been minimized.

Copy link
Contributor

kjnilsson commented Apr 25, 2016

just tested it on latest fsac master on a windows machine and don't get the
issue - I will do the same test on my mac when I get an opportunity. Could
be that the latest fsac/compiler tools don't have the issue.

On Mon, 25 Apr 2016 at 11:09 deapsquatter notifications@github.com wrote:

Maybe @Krzysztof-Cieslak https://github.com/Krzysztof-Cieslak can chime
in here on the version. Although looks like it may in fact be a fork
https://github.com/ionide/FsAutoComplete


You are receiving this because you were mentioned.

Reply to this email directly or view it on GitHub
#105 (comment)

@deapsquatter

This comment has been minimized.

Copy link

deapsquatter commented Apr 25, 2016

I replaced all files in the bin folder used by Ionide for fsautocomplete with fsautocomplete.suave.zip version 0.28 downloaded here. Same issue. Maybe an OS X issue?

@kjnilsson

This comment has been minimized.

Copy link
Contributor

kjnilsson commented Apr 25, 2016

I seem to have some memory of it happening on window as well. Mind, since
then I have upgraded both mono and .net. - just tried it against fsac
0.26.1 and no repro there either.

On Mon, 25 Apr 2016 at 11:26 deapsquatter notifications@github.com wrote:

I replaced all files in the bin folder used by Ionide for fsautocomplete
with fsautocomplete.suave.zip version 0.28 downloaded here. Same issue.
Maybe an OS X issue?


You are receiving this because you were mentioned.

Reply to this email directly or view it on GitHub
#105 (comment)

@deapsquatter

This comment has been minimized.

Copy link

deapsquatter commented Apr 25, 2016

Just tested your minimum repo with VS Code and Ionide on Windows. Works perfectly - no pegging of the CPU ¯_(ツ)_/¯

@kjnilsson

This comment has been minimized.

Copy link
Contributor

kjnilsson commented Apr 26, 2016

I get cpu pegging on my mac with the following:

oryx:fsac_issue_105 karlnilsson$ mono ../fsharp-vim/ftplugin/bin/fsautocomplete.exe --version
FSharp.AutoComplete 0.9.1
oryx:fsac_issue_105 karlnilsson$ mono --version
Mono JIT compiler version 4.2.1 (explicit/6dd2d0d Fri Nov 6 12:25:19 EST 2015)
Copyright (C) 2002-2014 Novell, Inc, Xamarin Inc and Contributors. www.mono-project.com
TLS: normal
SIGSEGV: altstack
Notification: kqueue
Architecture: x86
Disabled: none
Misc: softdebug
LLVM: yes(3.6.0svn-mono-(detached/a173357)
GC: sgen

@kjnilsson

This comment has been minimized.

Copy link
Contributor

kjnilsson commented Apr 26, 2016

sorry that should be: FsAutoComplete 0.27.0

@rneatherway

This comment has been minimized.

Copy link
Member

rneatherway commented Apr 26, 2016

Latest is 0.28.0, so I would double-check with that. I can try on my Mac later. I think this is 99% likely to be an FCS issue to be honest.

@rneatherway

This comment has been minimized.

Copy link
Member

rneatherway commented Apr 30, 2016

I just tried on OSX, with Mono 4.2.1 and then updated to 4.2.3, both worked fine here.

@Banashek

This comment has been minimized.

Copy link

Banashek commented Aug 22, 2016

OSX with mono 4.2.3 here, still experiencing the issue when using latest vim-fsharp with fsautocomplete 0.27.0

@Banashek

This comment has been minimized.

Copy link

Banashek commented Sep 3, 2016

Anyone have any updates or workaround for this? I've been ignoring my macbook air heating up on my lap and contsantly killing mono-sgen, but it's starting to bring my productivity down. If there are any tests I can do other than checking the versions installed, please let me know.

@blumu

This comment has been minimized.

Copy link

blumu commented Sep 3, 2016

I'm hitting a similar issue on VSCode + Ionide running on Windows (not using mono) where the CPU usage goes up to 25%. The process explorer reveals that the issue comes from the project cracker tool FsAutoComplete.Suave.exe
image

@rneatherway

This comment has been minimized.

Copy link
Member

rneatherway commented Sep 4, 2016

I would love to get this sorted, but have never been able to reproduce locally. If any of you can attach the profiler (probably easiest using the VS sampling profiler: https://msdn.microsoft.com/en-us/library/ms182384.aspx) then that might help. I strongly suspect it is something in FCS, but we need to figure out exactly what is triggering it.

PS Welcome to a fellow Ong student @blumu!

@Banashek

This comment has been minimized.

Copy link

Banashek commented Sep 14, 2016

So I have no problems with other files, but it seems like every suave project I work on has this problem. I also see FsAutoComplete.Suave.exe in @blumu 's pic.

Is there any information that I can collect on my mac to help out?

@rneatherway

This comment has been minimized.

Copy link
Member

rneatherway commented Sep 14, 2016

I think there is a mono profiler as well, you could try using that.

@deapsquatter

This comment has been minimized.

Copy link

deapsquatter commented Oct 6, 2016

Added a video of my experience with ionide. The video shows extremely long processing times for new code. Adding a simple function can take minutes to clear. VS Code was started fresh for the video. See mono-sgen CPU utilization in task window.
Youtube - ionide performance issue HD

@deapsquatter

This comment has been minimized.

Copy link

deapsquatter commented Oct 6, 2016

I managed to profile FsAutoComplete.Suave.exe using the mono profiler mono-profiler-output.txt. I profiled a session lasting about 2 minutes where an edit to a .fs file in VS Code on Mac OS sent my CPU into a spin. Hoping someone can spot something in this profiler output. Documentation for Mono Profiler.

@dsyme

This comment has been minimized.

Copy link
Contributor

dsyme commented Oct 6, 2016

Interesting log. Random snippet:

Allocation summary
     Bytes      Count  Average Type name
 231136872     125742     1838 System.Int32[]
 201498224    2403076       83 System.String
 111148000     114194      973 System.Byte[]
  50129216    3133076       16 System.UInt16
  37496000    2343500       16 Microsoft.FSharp.Collections.FSharpList<Microsoft.FSharp.Compiler.Tast.TType>
  30773632     692647       44 System.String[]
  28537176    1189049       24 System.Tuple<Microsoft.FSharp.Compiler.AbstractIL.IL.ILScopeRef,Microsoft.FSharp.Collections.FSharpList<Microsoft.FSharp.Compiler.AbstractIL.IL.ILTypeDef>,Microsoft.FSharp.Compiler.AbstractIL.IL.ILTypeDef>
  28480304    1780019       16 System.Tuple<Microsoft.FSharp.Compiler.Tast.EntityRef,Microsoft.FSharp.Collections.FSharpList<Microsoft.FSharp.Compiler.Tast.TType>>
  25769216     805288       32 Microsoft.FSharp.Collections.MapTree.MapNode<System.String,Microsoft.FSharp.Compiler.NameResolution.Item>
  23322048     212003      110 System.Char[]
  22909728     238643       96 Microsoft.FSharp.Compiler.LexFilter.TokenTup
  22720000    1420000       16 System.Reflection.BindingFlags
  20056320     313380       64 Microsoft.FSharp.Compiler.Infos.itys@137-3
  19489536     812064       24 Microsoft.FSharp.Compiler.Tast.TType.TType_app
  16978064    1061129       16 Microsoft.FSharp.Core.FSharpOption<Microsoft.FSharp.Compiler.Tast.Val>
  16328400     408210       40 Microsoft.FSharp.Compiler.PostTypeCheckSemanticChecks.CheckTypesDeep@246
  16023744    1001484       16 System.Tuple<System.Int32,System.Int32>
  14524544     226946       64 System.Text.RegularExpressions.Regex
  13836288     432384       32 Microsoft.FSharp.Compiler.AbstractIL.IL.ILTypeRef
  12314336     769646       16 Microsoft.FSharp.Compiler.Tastops.TypeDefMetadata.ILTypeMetadata
  11872128     742008       16 System.Tuple<System.Int32,System.Tuple<System.Int32,System.Int32>>
  11619040     290476       40 System.Tuple<System.Int32,System.Int32,System.Int32,ProviderImplementation.AssemblyReader.TaggedIndex<ProviderImplementation.AssemblyReader.TypeDefOrRefOrSpecTag>,System.Int32,System.Int32>
  11418912     713682       16 Microsoft.FSharp.Collections.FSharpList<System.Tuple<Microsoft.FSharp.Compiler.Tast.Typar,Microsoft.FSharp.Compiler.Tast.TType>>
  11415872     713492       16 System.Tuple<Microsoft.FSharp.Compiler.Tast.Typar,Microsoft.FSharp.Compiler.Tast.TType>
  11235584     702224       16 Microsoft.FSharp.Core.FSharpOption<Microsoft.FSharp.Compiler.Tast.TType>
  11175936     698496       16 System.Reflection.MemberTypes
  10755192     448133       24 System.Tuple<Microsoft.FSharp.Collections.FSharpSet<System.Int64>,Microsoft.FSharp.Compiler.Tastops.TyconRefMultiMap<Microsoft.FSharp.Compiler.Tast.TType>,System.Boolean>
  10721856     335058       32 Microsoft.FSharp.Collections.MapTree.MapNode<System.String,Microsoft.FSharp.Collections.FSharpList<Microsoft.FSharp.Compiler.Tast.EntityRef>>
  10051872     418828       24 Microsoft.FSharp.Compiler.Tastops.Remap
  10040680      67157      149 System.Reflection.MemberInfo[]
   9662352     402598       24 Internal.Utilities.Collections.Tagged.SetTree<Microsoft.FSharp.Compiler.Tast.Typar>
   9515088     198231       48 Microsoft.FSharp.Compiler.Tast.TyparData
   9344416     584026       16 System.Tuple<Microsoft.FSharp.Collections.FSharpList<Microsoft.FSharp.Compiler.Tast.Typar>,Microsoft.FSharp.Compiler.Tast.TType>
   9243520     231088       40 Microsoft.FSharp.Compiler.ConstraintSolver.SolveTypEqualsTypKeepAbbrevs@774
   8910360     123755       72 System.Reflection.AssemblyName
   8616384     269262       32 Microsoft.FSharp.Collections.MapTree.MapNode<Microsoft.FSharp.Compiler.PrettyNaming.NameArityPair,Microsoft.FSharp.Compiler.Tast.EntityRef>
   8266720     258335       32 Microsoft.FSharp.Collections.MapTree.MapNode<System.Int64,Microsoft.FSharp.Collections.FSharpList<Microsoft.FSharp.Compiler.Tast.TType>>
   8230592     257206       32 Microsoft.FSharp.Collections.SetTree.SetNode<System.Int64>
   8078496     504906       16 Microsoft.FSharp.Collections.FSharpList<System.String>
@dsyme

This comment has been minimized.

Copy link
Contributor

dsyme commented Oct 6, 2016

The number of thread pool workers looks very suspicious - I don't know the async architecture, but it may be that asyncs are flooding the thread pool queue through lots of (uncancelled or uncancellable) requests. If FsAutoComplete supports async requests that represents a major risk. You have to make sure that requests for information (where the request is in the work queue and the information is no longer logically needed by the UI) are cancelled before they hit the front of the work queue, so you don't just grind the process to a halt.


Thread summary
    Thread: 0xc07f0000, name: "Threadpool worker"
    Thread: 0xc06ee000, name: "Threadpool worker"
    Thread: 0xc05ec000, name: "Threadpool worker"
    Thread: 0xc04ea000, name: "Threadpool worker"
    Thread: 0xc03e8000, name: "Threadpool worker"
    Thread: 0xc02e6000, name: "Threadpool worker"
    Thread: 0xc01e4000, name: "Threadpool worker"
    Thread: 0xbbe55000, name: "Threadpool worker"
    Thread: 0xc00e2000, name: "Threadpool worker"
    Thread: 0xbbf57000, name: "Threadpool worker"
    Thread: 0xbbd53000, name: "Threadpool worker"
    Thread: 0xbbc51000, name: "Threadpool worker"
    Thread: 0xbbb4f000, name: "Threadpool worker"
    Thread: 0xbba4d000, name: "Threadpool worker"
    Thread: 0xbb94b000, name: "Threadpool worker"
    Thread: 0xbb849000, name: "Threadpool worker"
    Thread: 0xbb747000, name: "Threadpool worker"
    Thread: 0xbb645000, name: "Threadpool worker"
    Thread: 0xbb543000, name: "Threadpool worker"
    Thread: 0xbb33f000, name: "Threadpool worker"
    Thread: 0xbb441000, name: "Threadpool worker"
    Thread: 0xbb23d000, name: "Threadpool worker"
    Thread: 0xbb13b000, name: "Threadpool worker"
    Thread: 0xbb039000, name: "Threadpool worker"
    Thread: 0xbaf37000, name: "Threadpool worker"
    Thread: 0xbae35000, name: "Threadpool worker"
    Thread: 0xbac31000, name: "Threadpool worker"
    Thread: 0xbab2f000, name: "Threadpool worker"
    Thread: 0xbaa2d000, name: "Threadpool worker"
    Thread: 0xbad33000, name: "Threadpool worker"
    Thread: 0xba92b000, name: "Threadpool worker"
    Thread: 0xba829000, name: "Threadpool worker"
    Thread: 0xba727000, name: "Threadpool worker"
    Thread: 0xba625000, name: "Threadpool worker"
    Thread: 0xba523000, name: "Threadpool worker"
    Thread: 0xba421000, name: "Threadpool worker"
    Thread: 0xba31f000, name: "Threadpool worker"
    Thread: 0xba21d000, name: "Threadpool worker"
    Thread: 0xba11b000, name: "Threadpool worker"
    Thread: 0xba019000, name: "Threadpool worker"
    Thread: 0xb9f17000, name: "Threadpool worker"
    Thread: 0xb9e15000, name: "Threadpool worker"
    Thread: 0xb9d13000, name: "Threadpool worker"
    Thread: 0xb9c11000, name: "Threadpool worker"
    Thread: 0xb9b0f000, name: "Threadpool worker"
    Thread: 0xb9a0d000, name: "Threadpool worker"
    Thread: 0xb990b000, name: "Threadpool worker"
    Thread: 0xb9809000, name: "Threadpool worker"
    Thread: 0xb9707000, name: "Threadpool worker"
    Thread: 0xb9605000, name: "Threadpool worker"
    Thread: 0xb9503000, name: "Threadpool worker"
    Thread: 0xb9401000, name: "Threadpool worker"
    Thread: 0xb92ff000, name: "Threadpool worker"
    Thread: 0xb90fb000, name: "Threadpool worker"
    Thread: 0xb8ff9000, name: "Threadpool worker"
    Thread: 0xb91fd000, name: "Threadpool worker"
    Thread: 0xb8ef7000, name: "Threadpool worker"
    Thread: 0xb8df5000, name: "Threadpool worker"
    Thread: 0xb8cf3000, name: "Threadpool worker"
    Thread: 0xb8bf1000, name: "Threadpool worker"
    Thread: 0xb8aef000, name: "Threadpool worker"
    Thread: 0xb89ed000, name: "Threadpool worker"
    Thread: 0xb88eb000, name: "Threadpool worker"
    Thread: 0xb87e9000, name: "Threadpool worker"
    Thread: 0xb86e7000, name: "Threadpool worker"
    Thread: 0xb85e5000, name: "Threadpool worker"
    Thread: 0xb84e3000, name: "Threadpool worker"
    Thread: 0xb83e1000, name: "Threadpool worker"
    Thread: 0xb82df000, name: "Threadpool worker"
    Thread: 0xb81dd000, name: "Threadpool worker"
    Thread: 0xb80db000, name: "Threadpool worker"
    Thread: 0xb7fd9000, name: "Threadpool worker"
    Thread: 0xb7ed7000, name: "Threadpool worker"
    Thread: 0xb7dd5000, name: "Threadpool worker"
    Thread: 0xb7cd3000, name: "Threadpool worker"
    Thread: 0xb7bd1000, name: "Threadpool worker"
    Thread: 0xb7acf000, name: "Threadpool worker"
    Thread: 0xb78cb000, name: "Threadpool worker"
    Thread: 0xb77c9000, name: "Threadpool worker"
    Thread: 0xb79cd000, name: "Threadpool worker"
    Thread: 0xb75c5000, name: "Threadpool worker"
    Thread: 0xb76c7000, name: "Threadpool worker"
    Thread: 0xb74c3000, name: "Threadpool worker"
    Thread: 0xb73c1000, name: "Threadpool worker"
    Thread: 0xb72bf000, name: "Threadpool worker"
    Thread: 0xb71bd000, name: "Threadpool worker"
    Thread: 0xb70bb000, name: "Threadpool worker"
    Thread: 0xb6eb7000, name: "Threadpool worker"
    Thread: 0xb6db5000, name: "Threadpool worker"
    Thread: 0xb6bb1000, name: "Threadpool worker"
    Thread: 0xb6fb9000, name: "Threadpool worker"
    Thread: 0xb6cb3000, name: "Threadpool worker"
    Thread: 0xb69ad000, name: "Threadpool worker"
    Thread: 0xb6aaf000, name: "Threadpool worker"
    Thread: 0xb68ab000, name: "Threadpool worker"
    Thread: 0xb67a9000, name: "Threadpool worker"
    Thread: 0xb66a7000, name: "Threadpool worker"
    Thread: 0xb65a5000, name: "Threadpool worker"
    Thread: 0xb64a3000, name: "Threadpool worker"
    Thread: 0xb63a1000, name: "Threadpool worker"
    Thread: 0xb629f000, name: "Threadpool worker"
    Thread: 0xb619d000, name: "Threadpool worker"
    Thread: 0xb609b000, name: "Threadpool worker"
    Thread: 0xb5f99000, name: "Threadpool worker"
    Thread: 0xb5e97000, name: "Threadpool worker"
    Thread: 0xb5d95000, name: "Threadpool worker"
    Thread: 0xb5c93000, name: "Threadpool worker"
    Thread: 0xb5b91000, name: "Threadpool worker"
    Thread: 0xb5a8f000, name: "Threadpool worker"
    Thread: 0xb598d000, name: "Threadpool worker"
    Thread: 0xb588b000, name: "Threadpool worker"
    Thread: 0xb5789000, name: "Threadpool worker"
    Thread: 0xb5687000, name: "Threadpool worker"
    Thread: 0xb5585000, name: "Threadpool worker"
    Thread: 0xb5483000, name: "Threadpool worker"
    Thread: 0xb5381000, name: "Threadpool worker"
    Thread: 0xb517d000, name: "Threadpool worker"
    Thread: 0xb527f000, name: "Threadpool worker"
    Thread: 0xb507b000, name: "Threadpool worker"
    Thread: 0xb4f79000, name: "Threadpool worker"
    Thread: 0xb4e77000, name: "Threadpool worker"
    Thread: 0xb4d75000, name: "Threadpool worker"
    Thread: 0xb4c73000, name: "Threadpool worker"
    Thread: 0xb4b71000, name: "Threadpool worker"
    Thread: 0xb4a6f000, name: "Threadpool worker"
    Thread: 0xb496d000, name: "Threadpool worker"
    Thread: 0xb486b000, name: "Threadpool worker"
    Thread: 0xb4769000, name: "Threadpool worker"
    Thread: 0xb4667000, name: "Threadpool worker"
    Thread: 0xb4565000, name: "Threadpool worker"
    Thread: 0xb4463000, name: "Threadpool worker"
    Thread: 0xb4361000, name: "Threadpool worker"
    Thread: 0xb425f000, name: "Threadpool worker"
    Thread: 0xb415d000, name: "Threadpool worker"
    Thread: 0xb405b000, name: "Threadpool worker"
    Thread: 0xb3f59000, name: "Threadpool worker"
    Thread: 0xb3e57000, name: "Threadpool worker"
    Thread: 0xb3d55000, name: "Threadpool worker"
    Thread: 0xb3c53000, name: "Threadpool worker"
    Thread: 0xb3b51000, name: "Threadpool worker"
    Thread: 0xb3a4f000, name: "Threadpool worker"
    Thread: 0xb394d000, name: "Threadpool worker"
    Thread: 0xb384b000, name: "Threadpool worker"
    Thread: 0xb3749000, name: "Threadpool worker"
    Thread: 0xb3647000, name: "Threadpool worker"
    Thread: 0xb3545000, name: "Threadpool worker"
    Thread: 0xb3443000, name: "Threadpool worker"
    Thread: 0xb3341000, name: "Threadpool worker"
    Thread: 0xb323f000, name: "Threadpool worker"
    Thread: 0xb313d000, name: "Threadpool worker"
    Thread: 0xb303b000, name: "Threadpool worker"
    Thread: 0xb2f39000, name: "Threadpool worker"
    Thread: 0xb2e37000, name: "Threadpool worker"
    Thread: 0xb2d35000, name: "Threadpool worker"
    Thread: 0xb2c33000, name: "Threadpool worker"
    Thread: 0xb2b31000, name: "Threadpool worker"
    Thread: 0xb2a2f000, name: "Threadpool worker"
    Thread: 0xb292d000, name: "Threadpool worker"
    Thread: 0xb282b000, name: "Threadpool worker"
    Thread: 0xb2729000, name: "Threadpool worker"
    Thread: 0xb2627000, name: "Threadpool worker"
    Thread: 0xb2525000, name: "Threadpool worker"
    Thread: 0xb2423000, name: "Threadpool worker"
    Thread: 0xb2321000, name: "Threadpool worker"
    Thread: 0xb221f000, name: "Threadpool worker"
    Thread: 0xb211d000, name: "Threadpool worker"
    Thread: 0xb201b000, name: "Threadpool worker"
    Thread: 0xb1f19000, name: "Threadpool worker"
    Thread: 0xb1e17000, name: "Threadpool worker"
    Thread: 0xb1d15000, name: "Threadpool worker"
    Thread: 0xb1c13000, name: "Threadpool worker"
    Thread: 0xb1b11000, name: "Threadpool worker"
    Thread: 0xb1a0f000, name: "Threadpool worker"
    Thread: 0xb190d000, name: "Threadpool worker"
    Thread: 0xb180b000, name: "Threadpool worker"
    Thread: 0xb1709000, name: "Threadpool worker"
    Thread: 0xb1607000, name: "Threadpool worker"
    Thread: 0xb1505000, name: "Threadpool worker"
    Thread: 0xb1403000, name: "Threadpool worker"
    Thread: 0xb1301000, name: "Threadpool worker"
    Thread: 0xb11ff000, name: "Threadpool worker"
    Thread: 0xb01a5000, name: ""
    Thread: 0xb107b000, name: "Threadpool worker"
    Thread: 0xb0f79000, name: "Threadpool worker"
    Thread: 0xb0e77000, name: "Threadpool worker"
    Thread: 0xb0d75000, name: ""
    Thread: 0xb0c73000, name: ""
    Thread: 0xb0b71000, name: ""
    Thread: 0xb0a6f000, name: ""
    Thread: 0xb096d000, name: "Threadpool worker"
    Thread: 0xb086b000, name: ""
    Thread: 0xb0441000, name: ""
    Thread: 0xb0183000, name: "Finalizer"
    Thread: 0xb041d000, name: ""
    Thread: 0xb0849000, name: "Threadpool worker"
    Thread: 0xb0645000, name: "Threadpool worker"
    Thread: 0xb0747000, name: "Threadpool worker"
    Thread: 0xb0543000, name: "Threadpool worker"
    Thread: 0xa2f33000, name: "Main"
@rneatherway

This comment has been minimized.

Copy link
Member

rneatherway commented Oct 10, 2016

@dsyme good observation, that clearly looks bad. There was a refactoring and now all the commands are handled in async blocks, but I can't see why the number of active threads would be growing so much, unless the editor is really sending such a large number of requests. Is it possible to correlate this high CPU activity with requests in the vscode log?

@Krzysztof-Cieslak how often does your vscode integration request a parse?

@dsyme

This comment has been minimized.

Copy link
Contributor

dsyme commented Oct 11, 2016

@rneatherway I took a quick look at the code and it seems that you use RunImmediately from the .exe command line tool. But the Suave access point may do everything async. It feels like Suave requests will need to reply with a numeric token that can then be used for a later cancellation.

Perhaps you were previously relying on HTTP/TCP web request throttling (with basically one-by-one synchronous processing of requests) to control the number of active requests.

@kjnilsson

This comment has been minimized.

Copy link
Contributor

kjnilsson commented Oct 11, 2016

Just a note to say I've had the same issues in the vim plugin that doesn't
use the http api. Instead it appears related to the project referencing
graph. I did some profiling in the past. Will see if I can still reproduce.
On Tue, 11 Oct 2016 at 09:54, Don Syme notifications@github.com wrote:

@rneatherway https://github.com/rneatherway I took a quick look at the
code and it seems that you use RunImmediately from the .exe command line
tool. But the Suave access point may do everything async. It feels like
Suave requests will need to reply with a numeric token that can then be
used for a later cancellation.

Perhaps you were previously relying on HTTP/TCP web request throttling
(with basically one-by-one synchronous processing of requests) to control
the number of active requests.


You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
#105 (comment),
or mute the thread
https://github.com/notifications/unsubscribe-auth/ABIDlDyWXwcwamCZsDOB2qr0dWuAcbnqks5qy06_gaJpZM4IMfB8
.

@Krzysztof-Cieslak

This comment has been minimized.

Copy link
Collaborator

Krzysztof-Cieslak commented Oct 11, 2016

I think we can have 2 separate issues - project cracker (?) behavior with graph dependency of projects ( described in 1st post of this thread), and - Ionide flooding FSAC.Suave with too many requests (as described by @dsyme ).

@rneatherway

This comment has been minimized.

Copy link
Member

rneatherway commented Oct 11, 2016

I agree, we should have two separate issues. I've opened #128 to cover the async flooding issue, so let's discuss that one over there. I definitely like the idea of keeping cancellation tokens. How about using them to cancel requests if the same command is issued for the same file?

@rneatherway rneatherway changed the title 100% CPU usage - Reproducible 100% CPU usage - Reproducible (caused by complex dependency graph passed to project cracker) Oct 11, 2016

@rneatherway

This comment has been minimized.

Copy link
Member

rneatherway commented Oct 11, 2016

@kjnilsson that would be great if you can reproduce I will then try with vim-fsharp and the same project as well.

@blumu

This comment has been minimized.

Copy link

blumu commented Oct 12, 2016

I'm not sure if it helps but here is a perf trace that I captured some time ago showing ProjectCrackerTool running hot when using VSCode+Ionide.
image

ProjectCrackerTools Perf trace - Report160905.zip

@kjnilsson

This comment has been minimized.

Copy link
Contributor

kjnilsson commented Nov 3, 2016

FWIW - I just tried it with the test project I previously used to reproduce and was no longer able to (fsac 0.30).

@Disco-Dave

This comment has been minimized.

Copy link

Disco-Dave commented Jul 13, 2017

Hey I'm experiencing similar issues. I'm using mono version 5.0.0 and linux kernel 4.11.9-1. I experience this primarily with the fsharp/vim-fsharp plugin. Ionide seems to works fine.

Here is a picture of htop showing fsautocomplete going crazy

Please let me know of any additional information I can provide to help :)

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