{"id":234842,"date":"2021-10-11T12:37:44","date_gmt":"2021-10-11T19:37:44","guid":{"rendered":"https:\/\/devblogs.microsoft.com\/visualstudio\/?p=234842"},"modified":"2021-10-11T12:37:44","modified_gmt":"2021-10-11T19:37:44","slug":"case-study-using-visual-studio-profiler-to-reduce-memory-allocations-in-the-windows-terminal-console-host-startup-path","status":"publish","type":"post","link":"https:\/\/devblogs.microsoft.com\/visualstudio\/case-study-using-visual-studio-profiler-to-reduce-memory-allocations-in-the-windows-terminal-console-host-startup-path\/","title":{"rendered":"Case Study: Using Visual Studio Profiler to reduce memory allocations in the Windows Terminal console host startup path"},"content":{"rendered":"

Setting The Stage<\/h2>\n

Around the holidays of 2020 it was a bit quieter, and I decided it might be a great time to go investigate how the Visual Studio profiling tools worked. I have been a long-time user of the Windows Performance Analyzer (WPA)<\/a>, which is a great tool for doing systems-level performance analysis. It is, however, quite complex and difficult to learn, and I’d heard that the Visual Studio Profiler<\/a> had improved a lot since I last looked at it.<\/p>\n

I could have chosen a toy program to look at, but it felt like I’d learn more by approaching a real codebase of significant size. The Windows Terminal<\/a> project was a great one because it is a sizeable C++ codebase with plenty of history and legacy. If I could find anything cool to optimize, it would give me a chance to contribute back as it’s open source. As a bonus, I happened to know from some internal conversations that conhost.exe is launched over 1 billion times a day, so if I found any optimizations they might have a measurable impact on CPU cycles spent across the globe.<\/p>\n

Cloning and getting the first trace<\/h2>\n

I began by forking and cloning the Windows Terminal repo. If you’d like to follow along at home and repeat my steps, you can also clone that repo to the commit I had at the time, 551cc9a9<\/a>. I followed the Windows Terminal repo readme to ensure I had all the right dependencies set up, then opened OpenConsole.sln in Visual Studio 2019.<\/p>\n

Once in Visual Studio, I switched the Solution Configuration to Release since performance investigations should almost always be done on Release builds to see the full effects of any optimizations the toolchain will perform. Then I switched the Solution Platform to x64 since I have a 64-bit machine and figure most people do too by now. Lastly, I changed the Startup Project to Host.EXE which is where OpenConsole.exe builds – this is the open source version of conhost.exe that I wanted to look at.<\/p>\n

\"The<\/a><\/p>\n

I built the solution then launched the Visual Studio Profiler. You can go to Debug > Performance Profiler<\/strong>, but I like to launch it with Alt+F2<\/kbd> as a shortcut. The profiler then prompts you to choose what you want to investigate: CPU, GPU, memory, etc.<\/p>\n

I decided I wanted to look at memory since I have some experience in that area. Memory allocations can have significant CPU costs because the heap must do work to maintain a list of freed allocations, buckets, and various other heap-y details. Usually reducing allocations will noticeably impact CPU time, so it’s a cool way to improve memory and CPU at the same time. I checked the Memory Usage option and clicked Start.<\/p>\n

\"The<\/p>\n

At that point the console app starts up, and I can see a command-line with a blinking cursor as expected. In Visual Studio, I’m offered the option to take a memory snapshot:<\/p>\n

\"The<\/a><\/p>\n

I click this button to snapshot memory that has been allocated up until now in the startup process then click Stop Collection to finish this profiling session and close the app. Note that the first time you do this Visual Studio may process things for several minutes as symbols get loaded and things index, but it’s much faster on future iterations – so be patient the first time. The time to do this has been substantially improved in Visual Studio 2022 as well.<\/p>\n

The exact results you see may vary by machine. On my machine I saw this:<\/p>\n

\"4.74<\/a><\/p>\n

I clicked on the link for “29,461 allocations” and saw this:<\/p>\n

\"A<\/p>\n

That view is not very useful yet, but we can expand the callstack to look for where these come from in our code. Expanding out several nodes in RtlUserThreadStart where the vast majority of the allocations are to look for something interesting, I see this:<\/p>\n

\"An<\/p>\n

Discovering a suspicious allocation<\/h2>\n

What this shows is that we start off with 29,461 total allocations in this trace. 27,077 of these allocations belong to the ConsoleIoThread<\/code> function and the things it calls. Digging in we can see that 18,002 of these come from ROW::ROW<\/code>. Wow, that seems like a large percentage of the total allocations! This is basically a leaf node in the allocation callstack and starting at a leaf node is nice because it should be the thing directly doing the memory allocation, so I’ll start there.<\/p>\n

It seems like a lot of these ROW objects are being allocated, but why? At this point, I started reading a little code near this callstack and found this loop in TextBuffer<\/code> constructor:<\/p>\n

\/\/ initialize ROWs\r\nfor (size_t i = 0; i < static_cast<size_t>(screenBufferSize.Y); ++i)\r\n{\r\n    _storage.emplace_back(static_cast<SHORT>(i), screenBufferSize.X, _currentAttributes, this);\r\n}\r\n<\/pre>\n
The next question is: what is the value of screenBufferSize.Y<\/code>? Debugging through this code will reveal that it is, in fact, 9001 – but where does that come from? It’s from Settings::ApplyDesktopSpecificDefaults<\/code>, where _dwScreenBufferSize.Y = 9001<\/code>, which happens very early in startup and gets used as the default number of rows in the console.<\/p>\n
Ok, cool – so for some reason or other (likely compatibility) the default number of rows of text in the buffer is 9001 – but why do we need to allocate 9001 times to do this? Shouldn’t we be able to just do one allocation of an array of 9001 of these ROW<\/code> objects?<\/p>\n
Looking at TextBuffer.hpp, the ROW<\/code> objects are stored in a std::deque<\/code>:<\/p>\n
std::deque<ROW> _storage;\r\n<\/pre>\n
A std::deque<\/a> will allocate every time an element is inserted into it. By contrast, a std::vector<\/a> internally maintains an array. So in this case when we initially set up the TextBuffer::_storage<\/code>, we insert 9,001 ROW<\/code> objects into it. This results in the ROW<\/code> constructor running 9,001 times as well as 9,001 allocations inside of the std::deque<\/code>.<\/p>\n
This should be an easy fix, right? Can we just swap it out for a std::vector<\/code>? Let’s do that. I changed _storage<\/code> to be a std::vector<\/code> and added #include <vector><\/code> at the top of the file to see where I get.<\/p>\n
The simple fixes usually require a little iteration<\/h2>\n
Of course, it’s not that simple, as I hit some issues with test code. Usually while hacking around and trying to understand something, I find it helpful to unload the tests from the solution to improve build iteration times until something is promising enough to run functional tests on. Performance investigations can have many dead-ends and waiting to run and fix up tests for any changes to data structures can be put off until later. So, for the purposes of this case study, I unloaded all the test projects to improve iteration times – but of course before the final PR was submitted I ran and fixed all the tests.<\/p>\n
With tests unloaded, it’s still not quite as easy as changing a std::deque<\/code> to a std::vector<\/code> – this code was using deque<\/code> as a circular buffer so it’s using pop_front()<\/code> which vector<\/code> does not have. For now, let’s ignore that and hack away just to get some numbers.<\/p>\n
Let’s turn this loop in TextBuffer::ResizeTraditional<\/code>:<\/p>\n
while (&newTopRow != &_storage.front())\r\n{\r\n    _storage.push_back(std::move(_storage.front()));\r\n    _storage.pop_front();\r\n}\r\n<\/pre>\n
Into this loop:<\/p>\n
for (int i = 0; i < TopRowIndex; i++)\r\n{\r\n    _storage.emplace_back(std::move(_storage.front()));\r\n    _storage.erase(_storage.begin());\r\n}\r\n<\/pre>\n
Ok, now everything builds again, and I can re-run numbers to see if this had the expected effect of reducing allocations.<\/p>\n
Small victories can have big impacts<\/h2>\n
On my machine just that one change of a deque<\/code> to a vector<\/code>, I see this:<\/p>\n
\"Total<\/p>\n
Good news! This reduced the allocation count total during startup from 29,461 -> 20,458 (by 9,003!). Wow, this reduced the allocations in the startup path by just over 30% from this small change. How cool! This is what gets me so excited about doing performance work – when it works, the numbers are so compelling and measurable.<\/p>\n
Still, I think I can do better. std::vector<\/code> will start out with some amount of elements in it, then when you push_back<\/code> beyond its capacity it will re-allocate and copy all elements over into a buffer twice as large. So initially we’ll start out with a small array and end up re-allocating it multiple times as it starts up to finish fitting all 9,001 of these. After this is completed, we’ll also have an improperly sized buffer with some “waste” on the end.<\/p>\n
We can fix this simply by telling the vector<\/code> to reserve<\/a> the right amount of elements before inserting all of the ROW<\/code> objects. In the TextBuffer<\/code> constructor, add this as the first line:<\/p>\n
_storage.reserve(static_cast<size_t>(screenBufferSize.Y));\r\n<\/pre>\n
Re-running the trace on my machine shows this:<\/p>\n
\"Total<\/p>\n
I don’t understand why the allocation count didn’t reduce. This should have seen a few allocations reduce since all 9,001 ROW<\/code> objects get reserved right away. But at least it right-sized the allocation and we see a drop in total memory consumption of about 300 KB so now there’s no regression in total memory consumption – in fact it reduced total memory consumption from the starting point by a little bit.<\/p>\n
So far so good! Can we do even better than this? Yes, I think we can. Each of those ROW<\/code> instances shows it is allocating in a std::vector<TextAttributeRun><\/code>, but this is a bit misleading as the ROW<\/code> doesn’t have any std::vector<TextAttributeRun><\/code> members. Each ROW<\/code> instance owns an ATTR_ROW<\/code> and that is what actually owns the std::vector<TextAttributeRun><\/code>. The reason it shows up this way in the profiler UI is because the ATTR_ROW<\/code> constructor is so small it gets inlined into ROW::ROW<\/code> – this is a thing to watch out for in optimized code, sometimes inlining gets callstacks to be a bit confusing.<\/p>\n
If you were to look at this in memory (which a tool like SizeBench<\/a> can help you do), each instance of ROW is laid out like this:<\/p>\n
ROW structure in memory<\/h3>\n\n\n\n\n\n\n\n\n\n
Offset<\/td>\nMember<\/td>\nMember Size in Bytes<\/td>\n<\/tr>\n
0<\/td>\nCharRow _charRow<\/td>\n40<\/td>\n<\/tr>\n
+40<\/td>\nATTR_ROW _attrRow<\/td>\n32<\/td>\n<\/tr>\n
+72<\/td>\nshort _id<\/td>\n2<\/td>\n<\/tr>\n
+74<\/td>\n<alignment padding><\/td>\n6<\/td>\n<\/tr>\n
+80<\/td>\nint64 _rowWidth<\/td>\n8<\/td>\n<\/tr>\n
+88<\/td>\nTextBuffer* _pParent<\/td>\n8<\/td>\n<\/tr>\n<\/tbody>\n<\/table>\n
That ATTR_ROW<\/code> member takes up 32 bytes. Let’s expand that in memory too and it looks like this:<\/p>\n
ATTR_ROW structure in memory<\/h3>\n\n\n\n\n\n
Offset<\/td>\nMember<\/td>\nMember Size in Bytes<\/td>\n<\/tr>\n
0<\/td>\nstd::vector<TextAttributeRun> _list<\/td>\n24<\/td>\n<\/tr>\n
+24<\/td>\nint64 _cchRowWidth<\/td>\n8<\/td>\n<\/tr>\n<\/tbody>\n<\/table>\n
Ah, but that _list<\/code> member, now that’s interesting – that vector is only 24 bytes because internally a vector is storing a pointer off to the allocated array of data it contains. So that vector might be one element long or 1000 elements long, and it’ll remain 24 bytes in the ATTR_ROW<\/code>. That’s unfortunate in our case because most rows of a console have a single TextAttributeRun<\/code> yet we pay to allocate the array elsewhere in memory and then indirectly access via that pointer when we want to get to the elements.<\/p>\n
Paying attention to common patterns and practices<\/h2>\n
There are many codebases that run into situations like this and want a vector<\/code> that can store some number of elements inside of itself and only go out to the heap when they spill over that default amount. This is such a common pattern that the STL<\/a> even has it implemented for a very important type – std::basic_string<\/code>, the underlying type behind std::string<\/code> and std::wstring<\/code>. This so-called “small string optimization” keeps strings up to a certain size directly in the std::[w]string<\/code> without allocating from the heap, only reaching out to the heap for larger strings. Unfortunately std::vector<\/code> has no such optimization, but a number of variations of it exist in many codebases.<\/p>\n
For Windows Terminal, I decided to use the implementation in boost called boost::container::small_vector<\/a>. With a small_vector<\/code>, you can specify the type for it to hold (just like std::vector<\/code>), and you also specify how many elements it should reserve space for. Because I know most ROW<\/code> objects have just a single TextAttributeRun<\/code>, I replaced this line in AttrRow.hpp:<\/p>\n
std::vector<TextAttributeRun> _list;\r\n<\/pre>\n
With this line:<\/p>\n
boost::container::small_vector<TextAttributeRun, 1> _list;\r\n<\/pre>\n
After adjusting some build files to allow the right boost header to be located, I began to hit problems with small_vector<\/code> not being exactly the same as vector<\/code>. Instead of calling push_back<\/code>, I needed to call emplace_back<\/code> in a few places and this was a good time to sprinkle in a bit of noexcept<\/code> because small_vector<\/code> makes more guarantees about when it can and cannot throw compared to vector<\/code>. All the changes in AttrRow.cpp, AttrRow.hpp, AttrRowIterator.cpp and AttrRowIterator.hpp can be seen in the Pull Request for the full change<\/a>.<\/p>\n
Re-building and re-running the trace from there shows these results:<\/p>\n
\"Total<\/p>\n
Nice – another 9,001 allocations knocked out. Now the memory layout of each ROW looks like this:<\/p>\n
ROW structure in memory after using small_vector<\/h3>\n\n\n\n\n\n\n\n\n\n
Offset<\/td>\nMember<\/td>\nMember Size in Bytes<\/td>\n<\/tr>\n
0<\/td>\nCharRow _charRow<\/td>\n40<\/td>\n<\/tr>\n
+40<\/td>\nATTR_ROW _attrRow<\/td>\n56<\/td>\n<\/tr>\n
+96<\/td>\nshort _id<\/td>\n2<\/td>\n<\/tr>\n
+98<\/td>\n<alignment padding><\/td>\n6<\/td>\n<\/tr>\n
+104<\/td>\nint64 _rowWidth<\/td>\n8<\/td>\n<\/tr>\n
+112<\/td>\nTextBuffer* _pParent<\/td>\n8<\/td>\n<\/tr>\n<\/tbody>\n<\/table>\n
That ATTR_ROW<\/code> member now takes up 56 bytes – so what’s it doing with that extra space? Let’s expand that in memory too and it looks like this:<\/p>\n
ATTR_ROW structure in memory after using small_vector<\/h3>\n\n\n\n\n\n
Offset<\/td>\nMember<\/td>\nMember Size in Bytes<\/td>\n<\/tr>\n
0<\/td>\nsmall_vector<TextAttributeRun, 1> _list<\/td>\n48<\/td>\n<\/tr>\n
+48<\/td>\nint64 _cchRowWidth<\/td>\n8<\/td>\n<\/tr>\n<\/tbody>\n<\/table>\n
So, isn’t this worse, since things are bigger? Nope. As seen in the callstack screenshots, the total memory usage of the app during startup went from 4,836,438 to 4,834,754 – it actually went down just a bit. Why’s that? Because now these small_vector<\/code> instances contain space to store a single TextAttributeRun<\/code> internally without needing to allocate – this saves us an allocation (and thus CPU time spent in the heap) while also saving a bit of memory by not needing the vector’s internal pointer and the array it pointed to.<\/p>\n
If a specific ATTR_ROW<\/code> instance needs space for more than one TextAttributeRun<\/code> at runtime, that’s no problem – it will just allocate at that time. For the common case of a single run, this will keep memory constrained and also speed up startup when the buffer is filled with single run ROW<\/code> objects.<\/p>\n
Optimization confusion in callstacks and when to profile in Debug configuration<\/h2>\n
Next up: what are the other 9,001 allocations in the ROW<\/code> constructor? I puzzled about that for a while unsure of what it could be. Due to inlining<\/a>, I couldn’t see what was causing it. Therefore, it was a good time to switch into Debug mode and build and run the trace there in hopes it would show a callstack easier to follow. Doing that shows this:<\/p>\n
\"A<\/p>\n
The exact allocation counts and amount of memory differ substantially here, and this is normal in many codebases. This codebase may have extra debug information stored that is not present in Release builds or things like that. What’s interesting is to see the deeper callstack of things like std::make_unique<TextBuffer...><\/code> that were not present in the Release trace, because that call was completely inlined in a Release build. Likewise, we can now see that the constructor for ROW<\/code> is calling the constructor of CharRow<\/code> which is where there is yet another std::vector<\/code> – this time holding CharRowCell<\/code> instances, and this is the source of our other mysterious 9,001 allocations.<\/p>\n
Rinse and repeat<\/h2>\n
With that discovered, it looked like we could use the same playbook as before and see if std::vector<\/code> could be replaced with a small_vector<\/code>. I switched back to Release builds to have comparable numbers with the earlier traces now that I know where to focus attention. Looking at CharRow<\/code> and that vector of CharRowCell<\/code> suggests another opportunity to change to a boost::container::small_vector<\/code> to place the initial storage into the CharRow<\/code> instance, thus avoiding another allocation per row. So, I changed the _data<\/code> member from this:<\/p>\n
std::vector<value_type> _data;\r\n<\/pre>\n
To this:<\/p>\n
boost::container::small_vector<value_type, 120> _data;\r\n<\/pre>\n
How did I know to pre-size it to 120? Once again, with some debugging this comes back to that same function we saw earlier, Settings::ApplyDesktopSpecificDefaults<\/code>. It sets the default screen width in a variable called _dwScreenBufferSize.X<\/code> to 120, which eventually flows through to the constructors of each ROW<\/code> and then to each CharRow<\/code>. So, by pre-sizing this to 120 elements it avoids allocating for any CharRow<\/code>‘s initial storage of CharRowCell<\/code> objects.<\/p>\n
This again requires a few fixups throughout CharRowCell.hpp and CharRowCell.cpp, which you can see in detail in the Pull Request for the full change<\/a>. Once those changes are made, let’s see what this data structure change did to the trace. As a reminder, this is now back in Release mode so I’ll compare numbers to the last run we did in Release mode (not the previous one showing Debug that helped navigate the callstack):<\/p>\n
\"Total<\/p>\n
Wow! Another large reduction of allocations. So much so that the entire ConsoleIoThread<\/code> isn’t even at the top of allocations under BaseThreadInitThunk<\/code> anymore. The total allocations have now dropped to 2,448, meaning we’ve reduced allocations by almost 92% from where they started (29,461 to 2,448). Total memory consumption has gone from 4,968,062 to 4,906,762, a much more modest reduction of 1.2% but still a reduction. So basically, this is changing the layout of memory to not need as many calls to the heap to be arranged without affecting total memory consumption.<\/p>\n
At this point it looks like the allocation reduction well is drying up, so this case study will stop here. The final Pull Request<\/a> included a few other small changes that helped with memory usage and CPU usage a bit, but those are outside the scope of this case study.<\/p>\n
To ask the right question is already half the solution of a problem<\/h2>\n
I was not familiar with the Windows Terminal codebase when approaching this and was very pleasantly surprised to see how quickly the Visual Studio Profiling tools helped me find interesting questions to ask and interesting code to dig into. It can be easy to get lost in large swaths of code, but great tools like this help to focus attention on things that really matter, and we can see that just a few relatively tactical changes to a large codebase can result in substantial savings. Even in code that is decades old, there’s bound to be something cool to find!<\/p>\n
If this were a cheesy 80s cartoon ending, I would say “Now you know, and knowing is half the battle!” and we’d all chuckle as the outro music played \ud83d\ude01<\/p>\n
But seriously, I want to extend my thanks to the Windows Terminal team for asking good questions during the Pull Request process and helping shepherd my change in to ultimately being accepted. You can see the results of this change in Windows Terminal 1.6 and later, and the changes also flowed back into the Windows 11 version of conhost.exe.<\/p>\n
Hopefully this provides some ideas on strategies for reducing memory allocations in your codebase and shows how to use the very nice Visual Studio memory profiling tools to zero in on interesting problems.<\/p>\n
Happy Profiling,<\/p>\n
Austin<\/p>\n
If you give this tool a try and have any feedback for us, please fill out this survey, we\u2019d love to hear from you.<\/p>\n","protected":false},"excerpt":{"rendered":"
Setting The Stage Around the holidays of 2020 it was a bit quieter, and I decided it might be a great time to go investigate how the Visual Studio profiling tools worked. I have been a long-time user of the Windows Performance Analyzer (WPA), which is a great tool for doing systems-level performance analysis. It […]<\/p>\n","protected":false},"author":70643,"featured_media":228872,"comment_status":"open","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"_acf_changed":false,"footnotes":""},"categories":[155],"tags":[],"class_list":["post-234842","post","type-post","status-publish","format-standard","has-post-thumbnail","hentry","category-visual-studio"],"acf":[],"blog_post_summary":"
Setting The Stage Around the holidays of 2020 it was a bit quieter, and I decided it might be a great time to go investigate how the Visual Studio profiling tools worked. I have been a long-time user of the Windows Performance Analyzer (WPA), which is a great tool for doing systems-level performance analysis. It […]<\/p>\n","_links":{"self":[{"href":"https:\/\/devblogs.microsoft.com\/visualstudio\/wp-json\/wp\/v2\/posts\/234842","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/devblogs.microsoft.com\/visualstudio\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/devblogs.microsoft.com\/visualstudio\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/visualstudio\/wp-json\/wp\/v2\/users\/70643"}],"replies":[{"embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/visualstudio\/wp-json\/wp\/v2\/comments?post=234842"}],"version-history":[{"count":0,"href":"https:\/\/devblogs.microsoft.com\/visualstudio\/wp-json\/wp\/v2\/posts\/234842\/revisions"}],"wp:featuredmedia":[{"embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/visualstudio\/wp-json\/wp\/v2\/media\/228872"}],"wp:attachment":[{"href":"https:\/\/devblogs.microsoft.com\/visualstudio\/wp-json\/wp\/v2\/media?parent=234842"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/visualstudio\/wp-json\/wp\/v2\/categories?post=234842"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/visualstudio\/wp-json\/wp\/v2\/tags?post=234842"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}