Capturing Query Performance Data With sp_HumanEvents
Video Summary
In this video, I delve into using SP_HumanEvents to capture extended event information in SQL Server, specifically focusing on query performance data. I walk through setting up an extended event to track queries that run for over five seconds and demonstrate how to filter these events based on session IDs or specific stored procedures. The goal is to help you identify and tune problematic queries without overwhelming your system with unnecessary details. I also discuss the limitations of SP_HumanEvents, such as the lack of filtering in the actual execution plan view within SSMS, and highlight its usefulness for performance troubleshooting by providing detailed query plans post-execution.
Full Transcript
Erik Darling here with Darling Data. And this is going to be another video where I talk about how to capture different extended event information using SP underscore human events. I want to get a cool echo going, but I don’t quite have those audio engineering skills. So in the last video I talked a little bit about what SP human events is. is four, which is basically to make capturing performance related human events stuff easier. So that focuses on things like query performance, weight stats, blocking, compiles and recompiles, right? All sort of good things to be able to capture for your workload. I apologize for the fuzz over here. For some reason, my setup is acting a little weird today and I can’t quite figure out why the lights are being awkward on me. So anyway, there are all sorts of different ways to capture query performance data, including actual execution plans. So again, don’t run this thing for too, too long. Or if you’re going to run it for a while, make sure it’s in like a development, on a development server or stuff like that. But yeah, there are all sorts of different ways to do it. So for example, this execution would track query performance, it would capture any query that runs for over five seconds, and it would run for 20 seconds. If you’re on a really busy server, and you don’t want to capture absolutely everything, you could do that same setup, but also add this sample divisor here, which sort of acts like a little bit of a fizzbuzz thing. So you would only capture queries for with spids that are divisible by being modulo 5 equals zero. Another thing that you can do is if you’re interested in particularly interested in a single store procedure, you can do this, and you can track any execution of a particular store procedure. Now, what I find myself doing most often is sitting on a dev server, like doing client work, I find myself most often sitting on a dev server, with you know, just an SSMS tab open. And I want to find a particular I want to monitor my session and my session only.
for long running queries from, you know, whatever, right. So I find myself doing this is particularly useful for long store procedures where a lot of tiny little noisy things happen. And like, if you collect the actual execution plan for everything, that that sort of procedure executes, you’re gonna like crash SSMS, right? It’s like, it’s cool that you can turn on actual execution plans for a whole store procedure. But like, there’s no way to filter that like, it would be great if you could, like, when you clicked on, collect actual execution plan, there was like one of those little arrow drop downs, where you could like filter that stuff out and be like, look, I don’t care about things that run in like under five seconds, just show me the bad stuff, right? Because a lot of store procedures do a lot of tiny little work. If there’s like loops and stuff like that, you end up capturing just a bunch of nonsense that you’re never going to care about. And then you end up sifting through it all trying to figure out what you what’s good and what’s not. Um, uh, see, uh, the, well, God, I wish I wish it was still the SQL century plan explorer, not say the name of the company who owns plan explorer now.
Uh, but, uh, that does make, uh, you know, dealing with a long, big long store procedure execution plans easier, it breaks it down statement by statement. So it’s a bit easier to navigate in there. But, um, you know, uh, there’s also no filtering in there. So you can be a lot of scrolling through stuff looking for things that have high CPU and duration. Uh, there are a number of downsides to the product at this point. Um, uh, they haven’t yet added, uh, the per operator timing that SSMS shows you.
So it’s a little bit more work to, uh, get anything useful out of it. Now, um, I had this query run over here, uh, ran for about 13 seconds. Uh, let’s see if I can see if I can do this zoom it justice here. Uh, which way am I going this way? Oh, a little bit. There we go. You can see the 13 seconds right there.
You can also see exactly what time it is. So that’s a little freaky. But anyway, uh, this window did not capture an actual execution plan. Uh, just pretend this is a big store procedure. All right. Do me, do me a favor and go along with my fantasy where this is a big long store procedure, but this is the only query in it that stinks. If we, uh, come over to, uh, this window, which is where, uh, I have, uh, pulled up the data that my extended event collected. That’s this one here.
I turned it off just so I don’t forget to turn it off later and, you know, bog my own server down. Uh, but it was capturing from, uh, I’m looking at live data from this extended event. Uh, this is what, um, I had, what columns I’ve decided to show, uh, from the actual, from the extended event.
Uh, you get the query, uh, post execution plan, the SQL statement, timestamp, uh, duration, CPU time, uh, granted memory. It’s, it’s a little tough with extended events because not every event captures all of the same query metrics, which is a little, a little disappointing. Like, you know, you capture memory grants with this one, but not with this one.
Uh, also all the times, like you are in like microseconds. So like you have to do a lot of math in your head, you know, KB to GB is not like exactly my strongest suit as far as, you know, um, figuring out, um, uh, you know, like doing that conversion mentally. So anyway, uh, you get the point.
So there are, there are two things here. Uh, there’s the statement that finished, um, if this were coming from a store procedure, you’d have a lot of other information in here. But again, I mostly use this just to monitor a single speed for whatever it’s getting up to and like filtering that date, that data down to, uh, execution times that I care about. Right.
So like, you know, you might start at like, you know, 20 seconds or 10 seconds and then, you know, tune those queries, then move down to like five seconds or two seconds and tune those queries if you can. Uh, so all that. But the cool thing is for the, uh, post execution plan event, uh, you get a little tab over here for the query plan. And if you click on that, you’ll see what the query did, right?
Uh, we had a whole bunch of, uh, crazy stuff going on. So this, uh, just, uh, this just about confirms what SSMS told us. It ran for just a hair under 14 seconds.
And if we look through the query plan, we can see which operators, uh, had the most execution time associated with them. Uh, we have, uh, well, about a second and a half there. Uh, that adds up to a six seconds there for five seconds there.
Uh, we hit 13 seconds at this point and then another second over here. So, uh, that, that, that tells us, you know, which areas you might want to focus on. Maybe there’s some indexes we could add.
Maybe we could write the query a little bit better. Um, you know, things like that. Uh, this isn’t a query tuning video. This is just teaching you how to capture crappy queries. So you can tune them or you can pay me to tune them.
I do do that for a living. I’m told. Occasionally, I guess. So, uh, this is all the, the, the stuff that, uh, you can find from the actual execution plan. Again, newer versions of SQL Server, newer versions of SSMS.
Really handy to have these operator times in there. Uh, there are some weird caveats to the operator times thing. Uh, one of them specifically is, and this is probably a pretty good, um, probably a pretty good place to, uh, explain it a little bit. Um, each, so all of these operators in the, this section of the query plan, except for the nested loops join executed in batch mode.
So all of these three operators here, the timing that you see associated with them are individual. If this were a row mode plan, timing would be cumulative going from right to left. You would see, um, uh, all of, like, you would, like, uh, for a row mode operator, it collects, it, like, accumulates all of the time that its child operators used.
That’s a little more obvious when you get to the nested loops join that, that doesn’t support batch mode. I wish it did. Batch mode nested loops would be amazing.
But, um, this one does not support, uh, batch mode. So this runs in row mode. So this nested loops join does effectively add up all the operator times from the clustered index scan here, the clustered index scan here, and the hash match aggregate with the little spilly doodad here.
So, uh, this is usually how I use SPHumanEvents to, uh, help me with my performance troubleshooting. I find it very useful. Um, I use it quite a bit.
I hope you do, too. Um, there will be links in the video notes to the GitHub repo and all that good stuff. The readme over there has a whole bunch of information about how to execute it, how to use it, all that other stuff. But, you know, if you do use it, you hit any problems, you have any questions, anything like that, feel free to also use the GitHub repo to report those things, ask those questions, and all that good stuff.
Uh, thank you for watching. I’m going to be recording some, uh, other videos about how to use SPHumanEvents. So, uh, hope you, hope you tune into those, hope you watch those, hope you like those, and, um, I will, we’ll see you in that next video.
Like and subscribe and all that, right? Click the little bell for me. Thanks for watching.
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.