Profiling Query Performance In SQL Server With Extended Events The Easy Way

Profiling Query Performance In SQL Server With Extended Events The Easy Way

---

Thanks for watching!

Video Summary

In this video, I delve into using my free, open-source store procedure, SP_human_events, for profiling stored procedures in SQL Server. This tool is incredibly useful when you’re working on performance tuning and need a detailed view of what’s happening within complex or poorly understood stored procedures. By setting up an extended event that captures query-level performance information, we can monitor specific session IDs or individual stored procedures to identify bottlenecks without the overhead of Query Store. I walk through examples of how to set up SP_human_events to capture and analyze execution plans, parameter values, and other critical metrics from a single window in SQL Server Management Studio (SSMS). This approach helps pinpoint exactly where performance issues lie, making it easier to apply targeted optimizations.

Full Transcript

Erik Darling here with Darling Data. And in today’s video, we’re going to talk about how you can use my free, open source, bug-free store procedure, SP underscore human events, to profile store procedures. Now, I use this all the time when I’m working with clients. And the main way that I use it is to set up a new user, an extended event that captures as much performance information as I can about something running from a single window in SQL Server Management Studio. So, this is very useful if you have stored procedures that, you know, either do a lot of tiny little things or are just very long, and you’re not really sure where to start your performance tuning, because you’re not really sure what the worst of the worst of the worst of the worst is. Now, you can get some idea about this stuff from Query Store.

Now, you could also use my other store procedure, SP underscore Quickie Store, to search for a specific store procedure in a database. And you could look at the top 10 queries ordered by average CPU and probably do a pretty good job of figuring out where to start in there. But, you know, with Query Store and, you know, with the unfortunateness that is the plan cache, the thing that you may often run into is that you will see one of these, you know, cached plans, which is the equivalent of an estimated plan, right?

There’s no actual execution runtime statistics stored in them. And it might be a little hard to figure out exactly which part of a BigQuery plan is slower. It might be tough to figure out exactly, like, which part you might want to start focusing on. And this will help you do that. So, over in this window, I have a few different examples of how you can set up SP underscore human events to do that.

So, the top one is the one that we’re going to be using today, because we’re just going to be watching a specific session ID. That’s this window over here. We’re going to use the query event type, because this one will get all the query level performance information that we could possibly care about. So, we’re going to only get queries that run for 500 milliseconds or longer. And this is the session ID that we’re going to focus on, 107.

That should be the one that we’re using in this window, but I’ll double check that before we kick things off. And we want to use this keep alive thing, because what the keep alive thing does is it sets up an extended event that SP human events won’t automatically tear down. So, like, one other way of running SP human events is to give it a number of seconds you want it to run for.

And what it’ll do is it’ll start an extended event session, like, grab whatever event type information you decide you want to capture in here. And then at the end of that sampled seconds period, it will, like, parse out all the information from the event and then kill off the session so that it doesn’t keep running and running. Why the keep alive thing is useful is because you can just right click on it, save, watch live data, and then, like, run your store procedure and watch data as it comes in.

So, there are a couple other examples down here. And these two just show you how to collect stuff from one specific store procedure. Right. So, these are a little bit different because they don’t use session ID. We’re just using object name and we’re going to say we just want to get stuff from this store procedure. And if you’re feeling a little scared of, you know, let’s just say that you’re casting a wide net with what you want to collect, one thing that you can skip over is collecting actual execution plans by using the skip plans parameter.

So, this will get you all sorts of other information, you know, parameter value, statement level, CPU duration, all the other stuff, just without the actual execution plans. So, like, maybe this might just be good enough for you to, like, grab an example query execution of something that ran for a long time, rerun it in SSMS and get query plans from it that way. Or use the other, use the other, use the, use SP human events to focus in on a single session, just like recreating that stuff.

So, I do try to make it easy to, to use all these things. You know, there is a, there is a help parameter that lets you figure out exactly which parameters and which valid, which parameters are available and what valid arguments for them are. So, let’s just double check this. We are indeed using session ID 107 here. So, what we are going to do is we are going to execute this block and I don’t know why there is so much white space over there.

That is quite strange looking. And then we are going to go into management and extended events and we should probably refresh this. And now we have this keeper underscore human events query, right? So, it is prefixed with keeper because it is going to stay alive.

And of course, human events because it is SP human events. And then we have underscore query because we are capturing query events. Now, you probably don’t want to have multiples of these running on the same server because, you know, stuff might get a little wonky.

But then what we are going to do is just right click on this and select watch live data. So, we will do that. Now we have this wonderful video, window here where nothing is happening yet.

But if we come over to this window and we execute our stored procedure, we don’t have to have query plans turned on here. We are just going to run this. And as this thing executes, we are going to watch this window.

Because eventually, something will show up in here. Like this is still running. So, we don’t have any, nothing has come in yet. So, some query is running for a good long time. Laptop is starting to make some noise.

And now we have a couple rows in here. And now we have a couple more rows in here. Now, if you are feeling real scared of like, you know, maybe SQL Server, like over collecting your right over to observer overhead, you can stop the extended event from collecting data once it is finished.

But here we have a timestamp, which is oh so very useful. And then we have some of the events that fired in here. So, here’s a query plan for a slow thing.

And you can see the full query plan here. And we can zoom in and, you know, see, oh wow, this took a real long time. It took 12 seconds to insert into this table variable.

Table variables, boo, hiss. And, you know, we had a, this thing took 7 seconds to do a seek. And this thing took 4 seconds to do a scan. And oh boy, the whole thing is just a mess.

Now, if it were me doing my professional query tuning song and dance with this, I would, first thing that I would probably point out is that, you know, you’re inserting into a table variable. And table variables have all sorts of downsides in SQL Server.

Like, you’re not allowed to generate a parallel execution plan when you insert into a table variable. Or when you modify a table variable generally. And if you’re on SQL Server 2022 or various Azure nonsenses, you’ll get this warning.

If you’re on older versions of SQL Server, you’ll just say non-parallel plan reason. Could not generate valid parallel plan. And then we would talk about how table variables don’t get column level statistics, histograms associated with them.

And, you know, they’re a little bit of a black box to SQL Server. And, like, even in newer versions and with recompile hints, we can get, like, the table cardinality. Like, the number of rows that are actually in the table variable.

You still don’t have any, like, good histogram statistic information about the values in the columns like you get with temp tables. So, we’ve got some information here. And one thing that you can do, which I usually end up doing, especially for the longer stored procedures, where there’s a whole lot more stuff in them, is I’ll usually start right-clicking here and hitting Show Column in Table, so that I can see stuff like CPU time and I can see stuff like granted memory and I can see, you know what, this, the post execution plan one isn’t my, doesn’t have all my favorite stuff.

But you can also grab the statement text. You can grab the overall duration. Like, you can grab all sorts of, like, good information about what’s going on in here.

And like I said before, like, if you, even if you skip getting execution plans, there are a couple of the events that show, that are used as part of the event session definition that will show you the parameter values that got passed into the store procedure. So, this can all be very useful stuff to compare.

Now, the, what’s frustrating is that the CPU and duration is in microseconds and my brain does not compute or comprehend microseconds very well. So, like, I just, like, whenever I’m looking at this stuff, I always have to make mental notes. Like, like, go, like, look at the, look at the actual, like, look at the actual execution plan.

This was 12.135 seconds. And so, I know that any numbers that are about this length are going to be, like, over 10 seconds, right? Like, like, like, just, that starts at the 12 and there’s 1, 2, 3, 4, like, 7, 8, 57 digits afterwards.

And I know in my head that this is what, you know, took the bulk of the execution time in here because the full statement took about 15 and a half seconds. So, you know, this is where, like, the query tuning magic sort of kicks in. And let’s kill this thing off.

Let’s say, stop that and, you know, come back over here. Now, this is a lot, again, this is a lot more valuable when you have store procedures that do a lot of different things. Maybe even call sub-store procedures. You know, there’s a lot of, like, tiny little statements in them.

And the reason why this is so useful is because if you have store procedures that do, like, a bajillion things, right? Like, a lot of, like, you know, declaring variables, assigning variables things. And you turn on actual execution plans in SSMS, you’re going to flood that thing and have just a bad old time scrolling through a billion tiny little different execution plans trying to figure out where in the batch the slow stuff happened.

So, you know, just to do a little query tuning song and dance stuff. Let’s say, you know, we looked at all this stuff and we said, ah, table variables. And we shook our fists and we got, you know, gathered up the angry villagers, rounded up a constabulary.

We did everything we could. We, you know, united our forces. And we were like, you know what?

We’re going to do the query tuning professional thing. And we’re going to replace at signs with pound signs or hash signs depending on where in the world you live. And let’s just say that we wanted to change this query to use temp tables instead of table variables.

And just to make life a little bit easier because there’s only two statements in this one. Let’s run this. And now we’ll see that this didn’t take 15 seconds.

We had two quick. We have our queries now that finish very quickly. This one takes 2.2 seconds. Yay. And this one takes 352 milliseconds.

So, you know, the temp table wins again. The old temp table versus table variable foot race. And just to preemptively answer any questions, no, a CTE wouldn’t be better here. You stop it.

Stop it with the CTE. They’re not, they’re not your friend. So, again, this is how you can use SP human events to monitor. You could even say, you could use it to profile the activity of a single spid.

And that’s what we did here. And we got valuable information and insight into what our query was doing, why it was taking a long time. And then we knew exactly what to do to fix it.

So, if you find yourself in your job as a, whatever you do, having to tune SQL Server queries, this is a great way to capture the performance details of store procedures that do a whole lot of different crazy things so that you can figure out exactly where you should start tuning them. Granted, on this one, I started with a very low query duration. That’s a very low ceiling for me.

If I’m looking at something for the first time, I’ll probably set this higher, like one second or five seconds or ten seconds, depending on, you know, like what I know about the store procedure. Generally, if someone tells me that something runs for a half hour and I see there’s like, you know, like, get some information about it and I see that like the worst running queries run for like over a minute, I might even set that query duration thing to like 30 seconds so that I focus on the big stuff first. And I don’t get like all squirrel brained about, oh, this thing takes like five seconds.

I should also fix that even though I know that like getting like improving something that runs for like 30 seconds by, you know, five seconds or like 30 minutes by five seconds isn’t going to make anyone happy. I want to focus on the big stuff first. So this is a few different ways you can do that.

You can get this again for totally free from my GitHub repo. The link to the GitHub repo will be in the in the video description. And you can you can you can start your fun there.

So that’s that’s good, too. All sorts of interesting stuff in there. And you can use SP human events for several different different things that you might care about in SQL Server, Blank, Compiles, Recompiles, things like that.

So there’s all sorts of good stuff you can do in there. And yeah, this is the most common way I use it. I hope I hope you I hope I hope you find it as useful as I have found it. So thank you for watching.

I hope you enjoyed yourselves. I hope you learned something. I hope that you’ll go use this store procedure that was a quite a monumental chunk of effort to get get working and correct and all that other good stuff. God, extended events are hard.

That’s why I made this thing. But anyway, if you like this video, there are you have options for showing me your your mass approval. There’s a thumbs up button, which is good.

There’s a comment area where you can leave nice comments, no mean comments. Please, I’m a fragile human being. And if you like this sort of stuff generally, subscribe to the channel. I want to say that at this point, if you subscribe to my channel, you will be one of nearly 3,448 people who have also subscribed.

So the next person will be 3,448. Imagine that. Quite a quite an island of misfit toys.

Mass dear. Anyway, thank you for watching. It’s hot under these lights. And I’m going to go drink some water or I fall over. Thank you.

We’ll catch it. Now not to close the house or I go dorm if you have to. Guess what just?

Going Further

---

If this is the kind of SQL Server stuff you love learning about, you’ll love my training. I’m offering a 25% discount to my blog readers if you click from here. I’m also available for consulting if you just don’t have time for that, and need to solve database performance problems quickly. You can also get a quick, low cost health check with no phone time required.