Performance Profiling | .NET Async Tool

On today’s Visual Studio Toolbox, we continue looking at the profiling tools in Visual Studio, and Sagar is going to show us how you profile asynchronous code. [MUSIC] >> Hi, welcome to Visual Studio Toolbox. I’m your host Robert Green. I’m guest hosting today, filling in for Leslie. I’ll be doing this from time to time. It’s great to see you all again. Today, my guest is Sagar Shetty. Hey, Sagar. How are you? >> I’m doing great, Robert. How are you doing? >> Excellent, excellent. We are continuing our deep dive into the profiling tools, and today, you’re going to tell us all about the.

NET Async tool, 00:40 - which gives us the ability to profile asynchronous code. Very exciting. I think that’s interesting because async code works a little bit differently than sync code or regular code or whoever you want to call it. >> Yeah, absolutely. Robert, I thought it would be a good idea to start with establishing a foundation for what even is asynchronous programming. It’s a buzzword you hear a lot of the time, and I think a good way to think about it is to use an analogy. But first a high level of what asynchronous programming is, the basic idea is, you can run multiple tasks simultaneously, and there’s a few caveats here, so long as the task don’t depend on each other, and so long as that the task don’t share the same resources.

01:20 - Let’s use an analogy to help simplify this a bit. I think cooking and baking and like being in the kitchen in general is a very popular analogy for asynchronous work. Because let’s just say we wanted to make some breakfast, and we wanted to say fry some eggs, toast some bread, make some toast, and pour some orange juice. If we go through a “synchronous workflow,” essentially, what that would look like is maybe we take out a frying pan, we fry our eggs, we do nothing but just stare at the eggs while they’re frying. Then once that’s done, we move on to the next task, maybe we throw some bread in a toaster and make some toast, and then we do nothing while that’s toasting.

01:55 - Then once that’s done, we pour a glass of orange juice. Obviously, we know if you have any experience cooking that, you don’t necessarily need to wait on one task to finish before you start another one. Asynchronously, what that might look like is okay, you take out the frying pan, you put the eggs in, and then while that’s frying, you go ahead and put the bread in the toaster, and then while that’s toasting, you just pour a glass of orange juice. Instead of taking 10 minutes, maybe it takes three minutes. The reason why you can do these things asynchronously in that analogy is, one, tasks don’t depend on each other again, that’s point number 1. You don’t need fried eggs to make toast.

02:28 - Two, you’re not sharing the same resources. In the cooking analogy, that would be like, you don’t need a frying pan to toast bread, you need a toaster. They’re using different tools. At a high level, basically, the point is, you don’t want to be sitting around waiting for a task to finish, if you don’t need to wait on them. Computers work the same way. Computers are composed of threads which are the cooks in the kitchen, if you will. The computers that you know, even modern computers, have hundreds of thousands of operations that they need to execute even a second.

02:59 - These are complex mathematical computations. All sorts of database calls, reading and writing TextFiles, setting, appliance, etc, and if we were sitting around doing everything synchronously waiting for one task to finish before starting another one, things would just never get done, right? The big takeaway here is that this asynchronous framework and programming is very much ingrained in ASP.net core and a lot of modern frameworks, and it’s for good reason. Because essentially, what you’re trying to do is increase the throughput of your application, and increase the bandwidth of what you’re capable of. Yeah, that’s asynchronous programming in a nutshell.

03:33 - The Async tool, well, which is one of our many tools in the profiling suite, is a tool targeted towards getting a better understanding of asynchronous tasks. >> Is this a new tool? Has it been around awhile? >> At this point, it’s been around for a few months. We’ll be close to a year now, means how time flies in today’s day and age, but it is a relatively newer tool, and one thing I’ll stress is that it’s still very much a work in progress, and I’ll allude to some things that we’re doing to develop and find it. Yeah. >> Well, it’s always many people’s understanding of asynchronous code in the first place, so I guess that matches. >> Yeah, exactly. >> It’s been asynchronously call a web API, but there’s more you can do with it. >> Yeah, absolutely. C-sharp and.

NET definitely has quite a lot 04:20 - of support for asynchronous. I mean, like I said, it’s very much baked into the.NET framework. We have the Async and Await keywords, but like you suggested, Robert, it is more than that. It’s not just using a few key words here and there. Hopefully, our profiling tool, the Async tool, will help you detect and optimize issues with your asynchronous code. >> Let’s see how it works. >> Yeah, so let’s just jump straight into VS. I have a Web Application here, shout out to our colleague Mark Downie on the Production Diagnostics Team. Hopefully, we’ll be seeing him in a future episode. But yeah, we have a basic ASP.net core web application. Essentially, what’s happening here is I’ll go ahead and launch the profiler summary page, so that as everyone’s probably MRIs by now, it’s the Alt F2 shortcut. We have our summary page. I have the Async tool selected. I also have the CPU usage still selected. We’ve mentioned this in the past, but one concept within the profiler is this idea that you can use multiple tools simultaneously.

05:17 - Hopefully, by the end of the demo, I can at least allude to early showcase a reason why you’d want these two tools in particular paired together. We’re going to go ahead and start this. This is going to start, this is going to launch the web application. I’m going to go ahead and record a CPU profile. This is also collecting the CPU data, that Esther Borne talked about in an earlier episode. In fact, let me grab a URL real quick. This is essentially I’m going to generate a payload within this application.

05:47 - This app is not necessarily meant to be this crazy end-to-end experience, it’s more just to operate with a few interesting asynchronous functions, which we’ll see in a second here, and just give us some data to highlight some of the insights that the Async tool provides. I’m just going to expand this, I’ll show you what this is doing in a second, but essentially, it’s just triggering reading from a text file. Then we’re going to stop collection here. This is going to load. I’ve actually prepared a dataset ahead of time, but that was kind of the workflow, what you do to start this up. Now, let’s dig into the Async tool in particular. We’re looking at the support, Robert, we’ve got a couple of columns here, and I want to start at the far left with the name column.

06:26 - We talked about at the heart of asynchronous work, our different tasks operating simultaneously. In a lot of other profiling tools, we have this idea of a call stack, or a function calling another function, calling another function. In the Async tool, we have this name column, and each of these nodes corresponds to a particular task. You can think of these as task chains, if you will, task calling other tasks, calling other tasks. The tasks are generally generated using the Async and Await keywords in C# and.NET.

07:00 - We’ve got different tasks chains here, different tasks that are happening. In addition, some tasks happen multiple times, so we have an account that’s keeping track of how many times we saw that task occurring and executing. In addition to that, we have some timestamps, so we have the Start Time. This Start Time corresponds to the first time we see the very first instance of this particular task occurring. The End Time corresponds to when we see the end of the last instance.

07:28 - There are four versions of this particular task. This is the end of when the last one ended. This Total Time is not necessarily always the total time elapsed over the course of all four, but just the average time for each given one. We’ve got a few high level metrics here. In general, what’s I think interesting with the Async tool and the kind of metrics you want to code in on our Counts and then Total Time because we want to see essentially tasks that are really holding up our thread pool and not allowing us to progress further, so either tasks that are happening a lot or tasks that are taking a long time. If we start to dig in to some of these task chains here, this one looks interesting because it happens 22 times, and in general, it seems to be taking a bit longer. Let’s look into this.

This was also 08:12 - the same payload I was generating using the sync over Async result task. This is the top-level node, and now I want to dig into this a little bit more. First of all, I saw that that task is top-level mode. It was, in general, taking more than a lot of other tasks, but when I go into it and see the task it’s calling, we see some more interesting information. For example, this Task.Delay is taking way longer than all these other tasks, and so this is something that we would look at, and I’m going to go to the code in a second so we can see exactly where this is in the code.

08:44 - But this is something we can look to potentially optimize because this is taking way longer than other tasks, and the odds are, and in this case it is, it’s holding up the thread pool a bit, and so this task is getting into it. >> Again, this is the average over the 20 or so times it ran, or the total limit of 20? >> This is the average. >> Can you tell the individual ones, maybe one of the 20 took way longer, but all the other ones worked well? >> Perfect, Sagar. I really appreciate that. [OVERLAPPING] We did it. As you dig into the nodes, you can go into more and more details view. In this case, we’ll keep going into Task.Delay, and just as you suggest, Robert, we can go into individual instances. Two things I’ll call out here.

09:27 - One is we have a bucket, so there’s 22 of them, 17 of them are classified as within normal variance, so they were kind of close to the average. Then we have some outliers. These outliers might be really interesting. If there was one particular example that really stood out, we’d want to look into this a bit more. Of course, we can also see just our normal variances as well, and for each of these individual instances, we can also get all the start time, the end time, and then its total time. >> [inaudible] lines and one of them was horrible, and the other 21 were fine, It’s just an anomaly, something to look out for. >> Yeah, absolutely.

10:05 - Another thing I’ll say, and this is I want to emphasize going back something I said earlier, this tool is still very much a work in progress and something that you’re going to see in the next couple of versions 69 specifically is what we’re kind of aiming for for a few updates is the idea. In previous episodes, we’ve kind of talked about the swimlane up here and you can kind of time filter, and as [inaudible] mentioned in a previous episode, if you’re running multiple tools. We do have the CPUs, each tool up here. If you’re time filtering that similarly, and it will filter down the time for across all the tools you ran. In particular, Robert, like let’s say you were interested in this particular task delay because it took a lot of time, right now, you’d have to manually find these timestamps and filter that down. In the future in the 69, when you right-click, this button is not shown here yet, but we will have a time filter by this specific range.

10:55 - For this specific tasks, so then you can be able to then go to say, the CPU usage tool and do a deeper dive of, hey, okay, so this one task instance was a bit off, what was going on in the call stack here and what functions are being called, what hot paths were being triggered here, right? You can do that deeper dive because the async tool is a little bit more surface level, but the CPU async tool is more than heavy hitters. That’s how our tools are playing together a bit. All right, so last thing I want to talk about here is ultimately going back to code, right? We talked a lot about with a lot of different profiling tools that at the end of the day, we want to optimize performance and we want to bring you, the user back to your own source code that you can actually manipulate and change to help optimize performance. Just wanted to show that here. With the async tool, we’ve been going through this view. We’ve seen that this task, deleted task is a bit problematic.

11:43 - It’s taking a lot longer, and other tasks, symbols are not being my best friend today. Normally, you’d be able to go to source file. I have the code up, so I’ll just navigate to the function manually going through some of the code here. This was the URL that generated that payload from before and essentially be coming into this particular method, sync over async results, and essentially what’s happening every time this is hit is we’re reading from a text file and there is a read text async method here, and I want to go into that because that will be particularly interesting. Now, once we go into this particular asynchronous task, we see that here is the task delay within that asynchronous task, and to be honest, Robert, like this Task.

Delay is a placeholder you can imagine, 12:26 - this just as easily could have been some call to a rest API or database. It’s very realistic that some other call could have been here that would take it three seconds or whatever however long. It’s important to note that in this case, this Task.Delay is holding up everything else. This is written in a synchronous nature. What you would want here is another awaits even if you had your rest API call or whatever. It’s not holding up everything. In this case we can delete it or if it was some call you actually didn’t need, make sure it’s written in an asynchronous way.

12:56 - But yeah, that’s how you go back to source and can play around the async tool. Not necessarily for the deep dives per se, but much more by giving you the high level insights to further investigate into your code and point out problematic asynchronous tasks. >> Awesome. >> Yeah. >> Where do you see this tool going in the future? >> Yeah, we we definitely have a lot of plans for it. A lot of designs in the works. Like I said, there’s some usability things coming into play with being able to filter down by specific task time ranges, you don’t have to manually just like guess in the swim lane where a specific millisecond is. Additionally, I don’t know if it fully showed up in VS today, but a lot of the tasks names end with like DLLs and things that are not particularly readable.

13:47 - A lot of that comes from a lack of symbol support. We’re working on that, so ready to run symbols and other symbols are going to be more and more supported. That also is in the 69 time range I alluded to earlier, so some increased readability in terms of tasks, and then big picture, we really just want to help visualize these tasks, right? It’s tricky because a lot of these tasks are overlapping and running simultaneously. Right now, we have this tree grid view, which is pretty popular in the profiler, but I don’t have any finalized designs to share today, but let’s just say we’re really interested in making that visual experience a lot more intuitive and accessible. That’s where we see the async tool going, at least in the short term, but also like [inaudible] said, like a database, for example, would love to hear feedback because this is a tool that we still very much wants to polish, and really all of our tools, we’d love to hear feedback as we’re very much in a polish mode and want to really refine it, and yeah, if you want to learn more about any of these tools, we’ll make sure the docs that are linked, I think you should be seeing now is the main homepage.

14:48 - But yeah, at that homepage, you’ll see individual toolbox, async tool B among them. Yeah, feel free to give us feedback on the docks stream, would love to hear. >> Very cool, very cool. Thanks for showing this to us this awesome stuff. It’s a very handy tool to have as are all of these profiling tools. Thank you. >> Yeah, thanks for having me, Robert. Fun is always. >> All right. We’ll see you next time on Visual Studio Toolbox and happy profiling. >> Happy profiling. [MUSIC] .