[Performance] Visual Studio locks up after a build if you have diagnostic build turned on

[davkean]

1. File -> New -> Console App (.NET Framework)
2. Add -> New -> Console App (.NET Core)
3. Tools -> Options -> Project and Solutions -> Build And Run -> MSBuild project build output verbosity -> Diagnostic
4. Click OK
5. Right-click on .NET Framework project and choose Rebuild

-- Notice that the build is instant and Visual Studio does not lock up

6. Right-click on .NET Core project and choose Rebuild

-- Notice that builds takes > 10 seconds and locks up Visual Studio during it --

[mavasani]

#1384 (comment) We are spending most time in kernelbase!strlenW

[lifengl]

I looked into the build trace, and it was clearly a performance issue in the output window side.

Name Inc % Inc Exc % Exc Fold When
||+ msenv!CSUIBuilder::OutputStringNoPump 92.8 639,072 0.3 2,356 2,356 __399999599989999999999999999998
|| + msenv!CSUIBuilder::FBufferedOutputString 91.5 630,242 0.1 831 733 __399999599989999999999999999997
|| |+ msenv!CSUIBuilder::WriteBufferedOutputString 91.4 629,382 0.0 35 20 __399999599989999999999999999997
|| ||+ msenv!VsUtil::CString::Append 91.4 629,293 0.0 251 240 __399999599989999999999999999997
|| |||+ msenv!VsUtil::CString::Append 91.3 628,916 0.0 168 128 __399999599989999999999999999997
|| ||||+ kernelbase!lstrlenW 89.3 614,786 89.3 614,786 2,857 __399999599989999999999999999997

Basically, the code breaks down the input string into lines, and append them piece by piece to an internal buffer. Every appending, it will recalculate the length of the string in the buffer, and the length of the new string, although both of them known, and then reallocate the buffer. It is repeated for every line and every call. I think it should change the code to buffer the original strings into a list, and merge them together in one call, so the buffer size can be calculated before hand to prevent all extra allocation/copy and resizing. I will loop the right team. I don't think any change on the CPS side can fix or reduce this problem.

[davkean]

Is the reason we're not seeing this in legacy is because it writes a single chuck whereas we buffer?

[lifengl]

I think the editor team did some work in this area to fix some performance problems, and the change might change how strings are merged, and caused a regression here. Also CPS buffering messages might make it worse, if the output window is slower than the build, the output messages will start to be queued in the internal buffer, and push to the output window more aggressively in a large batch.

[mavasani]

@lifengl Do you have a bug on VSO side for this? Otherwise, I can open one and assign it to you so you can forward it to the correct team.

[lifengl]

Bug 374371

…

Sent from my phone On Feb 7, 2017, at 10:29 AM, Manish Vasani <notifications@github.com<mailto:notifications@github.com>> wrote: @lifengl<https://github.com/lifengl> Do you have a bug on VSO side for this? Otherwise, I can open one and assign it to you so you can forward it to the correct team. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub<#1242 (comment)>, or mute the thread<https://github.com/notifications/unsubscribe-auth/ALGWwtg2Hbtkwe6qe1I_CwXuBDTLIlhTks5raLfKgaJpZM4Lnp4d>.

[davkean]

Fix is here: https://devdiv.visualstudio.com/DevDiv/_git/VS/pullrequest/56690.