Fsharp: Endless type checking

[vasily-kirichenko]

Current master.

1. Open VFT solution, wait as much time as you like (minutes).
2. devenv.exe looks like this

The memory is slowly increasing from 900MB to 2GB and more. The CPU is constantly at about 20% (8 logical processors).

[vasily-kirichenko]

I think it's serious.

[smoothdeveloper]

A side note, I remember the type checker uses exception for control flow, in my experience in VB codebase where exception handling was used in loop (instead of a check on a collection...) the performance was terrible.

Can that design choice (throwing exception in type checker) lead to poor performance compared to a more functional way (returning result type)?

[dsyme]

@smoothdeveloper that's not the intrinsic problem here. Exceptions are used for some error reporting but not otherwise.

@vasily-kirichenko VFT is an odd solution because there is a problem with any transitive references to FSharp.Core causing some fundamental error. That will cause bizillions of cascading errors. We should first check we can edit a solution containing just the FSharp.Core project, then look at FSharp.sln (no visual tools)

[dsyme]

@vasily-kirichenko BTW this "slowly drifting up to 2GB" is I think very common for devenv.exe and other .NET processes if there is memory allocation and Gen2 collections going on with required memory in the 800M+ range. Only count it as a leak if you see the allocated bytes after full collection rising without bound. But it can be hard to analyze the heaps of such large beasts....

[vasily-kirichenko]

This is reproduced on RC4 as well.

[majocha]

Here's for comparison, both solutions all projects loaded and left alone for about half an hour running on i7.

A lot of activity. This is running current master, just without the latest commit.

[vasily-kirichenko]

I've added logging around TypeCheckOneFile, when it really type check a file, see https://github.com/Microsoft/visualfsharp/compare/master...vasily-kirichenko:check-one-file-log?expand=1

1. Open FindUsagesService.fs
2. Open service.fs
3. Leave VS alone for 20 _minutes_

This is the log content https://gist.github.com/vasily-kirichenko/c76dd4b59f06c4fcfef6689f302e2642

[majocha]

Running in circles, for sure. But does it happen on other solutions?

[vasily-kirichenko]

For example, it's checked TypeChecker.fs 12 times:

Line 252: 08-Feb-17 21:27:53 <-- TypeCheckOneFile (E:\github\visualfsharp\src\fsharp\TypeChecker.fs), 00:00:04.2926146 elapsed
    Line 590: 08-Feb-17 21:29:04 <-- TypeCheckOneFile (E:\github\visualfsharp\src\fsharp\TypeChecker.fs), 00:00:04.2839543 elapsed
    Line 930: 08-Feb-17 21:30:20 <-- TypeCheckOneFile (E:\github\visualfsharp\src\fsharp\TypeChecker.fs), 00:00:04.4184696 elapsed
    Line 1344: 08-Feb-17 21:31:39 <-- TypeCheckOneFile (E:\github\visualfsharp\src\fsharp\TypeChecker.fs), 00:00:04.2922142 elapsed
    Line 1830: 08-Feb-17 21:33:05 <-- TypeCheckOneFile (E:\github\visualfsharp\src\fsharp\TypeChecker.fs), 00:00:04.3164001 elapsed
    Line 2190: 08-Feb-17 21:34:18 <-- TypeCheckOneFile (E:\github\visualfsharp\src\fsharp\TypeChecker.fs), 00:00:04.2753174 elapsed
    Line 2716: 08-Feb-17 21:35:46 <-- TypeCheckOneFile (E:\github\visualfsharp\src\fsharp\TypeChecker.fs), 00:00:04.3090406 elapsed
    Line 3350: 08-Feb-17 21:38:14 <-- TypeCheckOneFile (E:\github\visualfsharp\src\fsharp\TypeChecker.fs), 00:00:04.1252736 elapsed
    Line 3738: 08-Feb-17 21:39:49 <-- TypeCheckOneFile (E:\github\visualfsharp\src\fsharp\TypeChecker.fs), 00:00:04.1866246 elapsed
    Line 4414: 08-Feb-17 21:41:53 <-- TypeCheckOneFile (E:\github\visualfsharp\src\fsharp\TypeChecker.fs), 00:00:04.1556217 elapsed
    Line 5046: 08-Feb-17 21:43:54 <-- TypeCheckOneFile (E:\github\visualfsharp\src\fsharp\TypeChecker.fs), 00:00:04.1862514 elapsed
    Line 6396: 08-Feb-17 21:49:20 <-- TypeCheckOneFile (E:\github\visualfsharp\src\fsharp\TypeChecker.fs), 00:00:04.1839732 elapsed

It took 4 seconds to do it _each_ time. I think something very wrong with the caches.

Interesting that reshapedreflection.fs has checked 52 times for the same time.

Looks like all the files were trying to type check at the same time with eventually, so the difference between small and large ones.

@dsyme

[smoothdeveloper]

I'm facing persistent CPU usage by devenv on mixed solutions involving F# projects or scripts.

This is an issue on machines with hyperthreading disabled and only a pair of cores, this happens in VS2015 as well AFAIK.

[vasily-kirichenko]

Running in circles, for sure. But does it happen on other solutions?

For sure. It's not even a caches bug, because I did not even touch the computer all that time...

[vasily-kirichenko]

@smoothdeveloper I've _never_ seen such behavior in [VS 2012..2017RC3]. Never. It's a new bug.

[vasily-kirichenko]

Oh, it's not endless actually. Turns out, it stopped checking after ~23 minutes. I've made a change in service.fs and it started doing the same thing again... Interesting.

[vasily-kirichenko]

Maybe it's all our features (coloring, ref highlighing, analyzers, etc) are calling ParseAndCheckFile simultaneously (they are), but results are not cached? Looks like the most good theory so far.

[majocha]

I don't think so, You can freely close all documents after you jump start the FSharpChecker and it will be the same.

[majocha]

The current logic in LanguageService.fs is that after you open one document in solution it queues all the loaded projects with InvalidateConfiguration and starts churning, no matter what you do next.

[vasily-kirichenko]

No, a project is not checked until you open a file that belongs to it.

[vasily-kirichenko]

BTW, memory stays at around 1.5-1.6GB (current master)

[vasily-kirichenko]

Hm. I'm sure I added rechecking the cache here https://github.com/Microsoft/visualfsharp/blob/master/src/fsharp/vs/service.fs#L2448, maybe it was deleted in some merge. I'll revert it back and will see if the bug gone.

[majocha]

@vasily-kirichenko

No, a project is not checked until you open a file that belongs to it.

I believe this commit e110833748a18fb603ab22b99b8bd3fac83f7871 changed the behavior somehow. Now it starts checking when you open a file, but at the same time hits the line
checkerProvider.Checker.InvalidateConfiguration(options)
like hundred times before VS even displays anything.
I don't know if it's of importance. I have to do more reading.

[vasily-kirichenko]

@majocha No. In that commit we just register all projects in a solution in Roslyn workspace. It has no relation to FSharpChecker, which actually doing all the work.

[vasily-kirichenko]

Ahhh, I was wrong, the check in cache is correct...

[vasily-kirichenko]

May the small size of parseAndCheckFileInProjectCache (5) be the cause?

[vasily-kirichenko]

Yes, the problem is that parseAndCheckFileInProjectCache has size 5, but by the time a feature comes to get cached results, _170_ other files have been cached, so the cache does not make sense at all for projects including more that 5 files.

[vasily-kirichenko]

Oookey. Found it. FSharpDocumentDiagnosticAnalyzer is called _for every file in project_, all the time: when you open a file, when you change anything in any file - it starts to call AnalyzeSyntaxAsync and AnalyzeSemanticsAsync for each file in project . For each file. As a result, reactor always has work to do and parseAndCheckFileInProjectCache is always contains irrelevant data (it's intended to cache currently edited files, not every file in project).

@Pilchie @CyrusNajmabadi Is this behavior new in RC4? If so, why? Can it be because we don't provide a ProjectDiagnosticAnalyzer (we've turned it off because we cannot provide dirty buffers content to FSharpChecker to check whole project properly)?

[vasily-kirichenko]

@Pilchie @CyrusNajmabadi Looks like it's here: http://source.roslyn.io/#Microsoft.CodeAnalysis.Features/Diagnostics/EngineV2/DiagnosticIncrementalAnalyzer.Executor.cs,289
Or maybe not. The code is ~8 months old.

[vasily-kirichenko]

Caching diagnostics on FSharp.Editor side does not seem to work, see https://github.com/Microsoft/visualfsharp/compare/master...vasily-kirichenko:check-one-file-log?expand=1#diff-51659ac3fb6ea23a9800081048eb18b4R121 because errors depend on whole project state (you can change a file and will get errors in other files, down the project file list).

So I think, if Roslyn isn't gonna fix this, we should add a dedicated diagnostics cache in services.fs, which should be filled in CheckFileInProject and by the background compiler.

[vasily-kirichenko]

Hmm. I'm not sure we can create such a cache :(

[vasily-kirichenko]

This is called "closed files diagnostics" and it's off by default for C# and on for all other languages, see http://source.roslyn.io/#Microsoft.CodeAnalysis.Features/Shared/Options/ServiceFeatureOnOffOptions.cs,10 I'm gonna try to turn it off via options.

[vasily-kirichenko]

Fixed in https://github.com/Microsoft/visualfsharp/pull/2395

[forki]

Awesome

Am 09.02.2017 11:54 vorm. schrieb "Vasily Kirichenko" <
[email protected]>:

Fixed in #2395 https://github.com/Microsoft/visualfsharp/pull/2395

—
You are receiving this because you are subscribed to this thread.
Reply to this email directly, view it on GitHub
https://github.com/Microsoft/visualfsharp/issues/2389#issuecomment-278609454,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AADgNBGz1ToOduAyUcKkE1eCJf6LSjQ6ks5ravB2gaJpZM4L63e2
.

[vasily-kirichenko]

@gmpl please try this version with RC4, it does not block on completion at all and use stale results for everything if it cannot get fresh ones in 1 second. It should work very smoothly.