gistfile1.txt

[12:34:33] *** drs1005 would like to add you on Skype

Hi Василий Кириченко, I'd like to add you as a contact.  This is Don Syme ***
[12:35:04] *** Василий Кириченко has shared contact details with drs1005. ***
[15:16:00] drs1005: hey got a moment?
[15:16:41] Василий Кириченко: hi, yep
[15:16:50] drs1005: I'd like to screen share, I'll call then we can do that.
[15:16:55] *** Call to Василий Кириченко ***
[15:17:39] Василий Кириченко: I don't have microphone here at work
[15:17:44] drs1005: ok, I'llscreen share
[15:18:17] drs1005: can you see ok?
[15:19:02] Василий Кириченко: very bad quality
[15:19:12] drs1005: ah ok
[15:19:45] Василий Кириченко: I have headphones :)
[15:19:57] Василий Кириченко: yep
[15:20:17] Василий Кириченко: :(
[15:20:23] Василий Кириченко: bad sound
[15:20:46] drs1005: ok
[15:21:31] drs1005: I'm starting up devenv.exe under the debugger
[15:21:41] Василий Кириченко: ok
[15:21:41] drs1005: with a modified FCS.dll
[15:21:59] drs1005: what I want to show you is the trace of FCS requests that VFPT is making
[15:22:17] drs1005: So I'll open TypeChecker.fs in the devenv.exe being debugged
[15:22:38] drs1005: And then switch back to the devenv.exe that is debugging it and we look at the Output window
[15:22:43] Василий Кириченко: ok
[15:23:32] drs1005: So here's the callstack:
[15:23:41] drs1005: Sorry, here's the trace:
[15:23:43] drs1005: devenv.exe Information: 0 : Reactor: receiving..., remaining 0, mem 28, gc2 4
devenv.exe Information: 0 : Reactor: enqueue GetProjectOptionsFromScript C:\GitHub\dsyme\visualfsharp\src\fsharp\TypeChecker.fs, length 0
devenv.exe Information: 0 : Reactor: --> GetProjectOptionsFromScript C:\GitHub\dsyme\visualfsharp\src\fsharp\TypeChecker.fs, remaining 0, mem 39, gc2 5
devenv.exe Information: 0 : Reactor: enqueue GetProjectOptionsFromScript C:\GitHub\dsyme\visualfsharp\src\fsharp\TypeChecker.fs, length 0
System.Windows.Data Error: 5 : Value produced by BindingExpression is not valid for target property.; Value='<null>' BindingExpression:Path=Content; DataItem='Button' (Name=''); target element is 'Button' (Name=''); target property is 'Name' (type 'String')
System.Windows.Data Error: 5 : Value produced by BindingExpression is not valid for target property.; Value='<null>' BindingExpression:Path=Content; DataItem='Button' (Name=''); target element is 'Button' (Name=''); target property is 'Name' (type 'String')
devenv.exe Information: 0 : Reactor: enqueue GetProjectOptionsFromScript C:\GitHub\dsyme\visualfsharp\src\fsharp\TypeChecker.fs, length 1
devenv.exe Information: 0 : Reactor: <-- GetProjectOptionsFromScript C:\GitHub\dsyme\visualfsharp\src\fsharp\TypeChecker.fs, remaining 2, took 2675.4248ms
devenv.exe Information: 0 : Reactor: receiving..., remaining 2, mem 114, gc2 8
devenv.exe Information: 0 : Reactor: --> GetProjectOptionsFromScript C:\GitHub\dsyme\visualfsharp\src\fsharp\TypeChecker.fs, remaining 1, mem 115, gc2 8
devenv.exe Information: 0 : Reactor: enqueue GetProjectOptionsFromScript C:\GitHub\dsyme\visualfsharp\src\fsharp\TypeChecker.fs, length 2
devenv.exe Information: 0 : Reactor: enqueue ParseFileInProject C:\GitHub\dsyme\visualfsharp\src\fsharp\TypeChecker.fs, length 2
devenv.exe Information: 0 : Reactor: enqueue GetProjectOptionsFromScript C:\GitHub\dsyme\visualfsharp\src\fsharp\TypeChecker.fs, length 2
devenv.exe Information: 0 : Reactor: enqueue GetProjectOptionsFromScript C:\GitHub\dsyme\visualfsharp\src\fsharp\TypeChecker.fs, length 4
devenv.exe Information: 0 : Reactor: <-- GetProjectOptionsFromScript C:\GitHub\dsyme\visualfsharp\src\fsharp\TypeChecker.fs, remaining 5, took 764.6167ms
devenv.exe Information: 0 : Reactor: receiving..., remaining 5, mem 157, gc2 8
devenv.exe Information: 0 : Reactor: --> GetProjectOptionsFromScript C:\GitHub\dsyme\visualfsharp\src\fsharp\TypeChecker.fs, remaining 4, mem 157, gc2 8
devenv.exe Information: 0 : Reactor: enqueue GetProjectOptionsFromScript C:\GitHub\dsyme\visualfsharp\src\fsharp\TypeChecker.fs, length 4
devenv.exe Information: 0 : Reactor: enqueue ParseAndCheckFileInProject C:\GitHub\dsyme\visualfsharp\src\fsharp\TypeChecker.fs, length 5
devenv.exe Information: 0 : Reactor: <-- GetProjectOptionsFromScript C:\GitHub\dsyme\visualfsharp\src\fsharp\TypeChecker.fs, remaining 6, took 5719.8699ms
devenv.exe Information: 0 : Reactor: receiving..., remaining 6, mem 199, gc2 8
devenv.exe Information: 0 : Reactor: --> GetProjectOptionsFromScript C:\GitHub\dsyme\visualfsharp\src\fsharp\TypeChecker.fs, remaining 5, mem 199, gc2 8
devenv.exe Information: 0 : Reactor: enqueue ParseAndCheckFileInProject C:\GitHub\dsyme\visualfsharp\src\fsharp\TypeChecker.fs, length 5
devenv.exe Information: 0 : Reactor: <-- GetProjectOptionsFromScript C:\GitHub\dsyme\visualfsharp\src\fsharp\TypeChecker.fs, remaining 6, took 8519.141ms
devenv.exe Information: 0 : Reactor: receiving..., remaining 6, mem 225, gc2 8
devenv.exe Information: 0 : Reactor: enqueue ParseAndCheckFileInProject C:\GitHub\dsyme\visualfsharp\src\fsharp\TypeChecker.fs, length 6
devenv.exe Information: 0 : Reactor: --> ParseFileInProject C:\GitHub\dsyme\visualfsharp\src\fsharp\TypeChecker.fs, remaining 5, mem 225, gc2 8
[15:24:55] Василий Кириченко: I think I've fixed it?
[15:25:35] drs1005: For example you can see here that there are lots of rquests for GetProjectOptionsFromScript - which you've now fixed
[15:25:54] drs1005: Right, it's more I just want you to see how the trace works
[15:26:14] drs1005: When it says
[15:26:15] drs1005: devenv.exe Information: 0 : Reactor: receiving..., remaining 5, mem 157, gc2 8
[15:26:24] drs1005: it means the FCS queue has 5 entries in it.
[15:26:50] drs1005: In this case these correspond to 5 cursor movements each of which has started an async { ... } to do highlighting
[15:27:17] drs1005: The ParseAndCheckFileInProject for the first has not yet completed, so the others are backing up behind it.
[15:27:40] Василий Кириченко: I see.
[15:28:45] drs1005: That's not a problem in itself, but if the queue became unbounded it would be
[15:28:48] Василий Кириченко: so in your last PR you remove outdated requests and duplicates?
[15:28:53] drs1005: no
[15:30:38] Василий Кириченко: I'm not sure I understand how to get benifit from your PR. Should I provide cancellation token to FCS from my async { }s ?
[15:30:55] drs1005: The PR improves the caching so identical requests still in the cache will be fast (for those calls we cache)
[15:31:35] drs1005: But there's no treatment of out-of-date requests, though if you cancel an async then FCS will throw away the request (if it hasn't started processing it)
[15:31:40] Василий Кириченко: ah! that's good
[15:32:46] Василий Кириченко: I see, great.
[15:32:46] drs1005: So ideally a feature like highlight references only has at most one non-cancelled async in flight.  Cancelled asyncs will still appear in the queue but when FCS comes to process them it will see it's cancelled and skip it
[15:33:10] Василий Кириченко: I do cancellation in the colorizer
[15:33:17] Василий Кириченко: (only in it)
[15:33:19] drs1005: ok, great
[15:33:41] drs1005: The code managing the queue is in FCS Reactor.fs
[15:33:58] Василий Кириченко: yes, I examined the PR.
[15:34:07] drs1005: If the queue is empty for 1 second then the background work will kick in
[15:34:18] drs1005: you can set that parameter on FSHarpChecker
[15:34:51] Василий Кириченко: what is background work?
[15:35:06] Василий Кириченко: startbackgroundcompilation requests?
[15:36:28] drs1005: After the PR, there is now a setting ImplicitlyStartBackgroundWork, which is on by default.  Whenever you do a ParseAndCheckFileInProject,  or similar FileInProject requests, then that project will become the active background-build project
[15:37:16] Василий Кириченко: how to say FCS to stop compiling outdated project?
[15:37:16] drs1005: When the queue is empty (= user really not doing anything) then little slices of the work to parse and check all the files in the project get performed
[15:38:16] drs1005: At each step of the background build FCS checks what needs to be done all over again - looks at the time stamps on DLLs and files etc.  and works out what to do.
[15:38:32] drs1005: So in a sense the background build is never doing out of date stuff
[15:38:57] Василий Кириченко: great. So this line is unnecessary? https://github.com/fsprojects/VisualFSharpPowerTools/blob/master/src/FSharpVSPowerTools.Core/LanguageService.fs#L218
[15:39:37] drs1005: Requests where you pass in the modified source explicitly, like ParseAndChekFileInProject are not part of the background build - they are proper FCS requests that go in the queue.
[15:40:03] drs1005: That line acts like an extra cancellation signal for that operation.
[15:40:33] Василий Кириченко: one question: when I call ParseAndCheckFileInProject for the very first time, what's happening?
[15:41:14] drs1005: If you throw 10 ParseAndCheckFileInProject requests for the same file but with different source, then FCS will do all of them, until it works out it's cancelled through either an async cancellation (before the request gets started), or an IsResultObsolete check
[15:41:31] drs1005: And because FCS only caches one thing per file name, no one of these will be cached.
[15:42:34] drs1005: On the first time:    Assume a project file order .... x.fs, y.fs, z.fs .... , and you ask ParseAndCheckFile(y.fs).
[15:43:57] drs1005: The FCS request goes and forcibly updates the background build through to the check of "x.fs".  If the background build is already up to date then that's great, if not it brings it up to date.  This might also mean checking any referenced projects, so it can take a long time if a small project references a large project (in the same solution)
[15:44:13] Василий Кириченко: OK, I see.
[15:44:33] drs1005: Once the background build is up-to-date, it then checks y,fs but uses the replacement source text you've given it.
[15:44:47] drs1005: It caches the overall results keyed on the project, file name and source text.
[15:46:02] drs1005: This is why it's useful to have the background build up-to-date.
[15:47:11] Василий Кириченко: so if I'm editing a single file it will not recheck every file in the project as them are not changed?
[15:47:35] Василий Кириченко: ah! up to the x.fs. I see now.
[15:47:37] drs1005: Right, if editing y,fs, the background build up to the end of x.fs remains up-to-date.
[15:47:53] drs1005: But of course this all uses memory, especially in large solutions
[15:48:21] Василий Кириченко: so if I'm editing the first file in a project FCS will continuosly recheck all the files.
[15:48:57] drs1005: In the background, yes, after 1second idle time in the queue (after this PR)
[15:49:32] drs1005: I saw cases where FCS was processing background work in preference to the queue, which was very wrong, it's why I rewrote that reactor.fs just now.
[15:49:49] Василий Кириченко: It would by ok if there is no memory leak
[15:51:54] drs1005: If FCS is not processing the queue, then lots of user actions will get no response.  And the queue will get very long.  That's likely to have been a contributing factor to leaks and poor experience in large solutions - I'm not yet certain
[15:52:51] Василий Кириченко: am I right that the leaks are caused by FCS caches and only by them?
[15:55:43] drs1005: It could be (1) there are no real leaks as such - even having an incremental build of one really big project just blows 2GB.
[15:56:03] drs1005: (2) there are actual leaks in FCS, though I don't know of any
[15:56:47] drs1005: (3) the FCS operations queue is getting unbounded because FCS has stopped processing things or is just taking too long (e.g. like it was prioritizing background work instead of processing the queue).
[15:58:57] drs1005: (4) The VFPT code (including inflight asyncs) is hanging on to handles to various FCS objects - ParseFileResults, CheckFileResults, Symbols etc.  Even hanging on to a single symbol can implicitly reference a whole compilation graph.  I've looked at the VFPT code though and you seem to be very clean about this (with the possible exception that you're creating a lot of inflight asyncs which can close over these objects - which is only a problem if those asyncs aren't getting processed fast enough, e.g. by the FCS queue)
[15:59:26] Василий Кириченко: Hmm. I have not thought about the (4)
[15:59:56] drs1005: My guess at the moment is that it's all a combination of (1) and (4).  That is, FCS just uses a lot of memory.  And the requests weren't getting processed promptly due to a mix of reasons.
[16:00:33] Василий Кириченко: so I should not hold anything returned by FCS? No FSharpSymbol / Entity and so on?
[16:01:05] Василий Кириченко: convert these objects as fast as possible into my representation?
[16:02:35] Василий Кириченко: Don, unfortunately I have to go home now.
[16:02:47] Василий Кириченко: Thanks a lot for the explanations!
[16:03:47] Василий Кириченко: it would be great to output the caches state (periodically maybe)
[16:05:33] drs1005: yes I can add that to the trace information
[16:05:47] drs1005: I have to go too - kids are back from school.  Good to chat!
[16:05:52] drs1005: *to