Capturing Query Wait Stats With sp_HumanEvents
Video Summary
In this video, I delve into using `sp_whoisactive` to track wait stats through a unique approach by leveraging the `SP_HumanEvents` stored procedure in a different way than usual. Instead of setting up a permanent extended event session, I demonstrate how to sample wait stats for a specific duration on the server. This method is particularly useful for quick diagnostics and performance analysis without the overhead of maintaining an ongoing session. I also take this opportunity to pay tribute to Eric EJ, highlighting his contributions to the SQL Server community, including his work with SQL Query Stress and Entity Framework improvements. The video covers various aspects of `SP_HumanEvents`, such as its output format, how it creates views for easier querying, and practical insights into interpreting wait statistics by database and query level.
Full Transcript
Erik Darling here with Darling Data. Limited. I don’t have the gall to call myself unlimited because I have some very strict limitations on things. California wine, most beer, pork chops, what else? I don’t know, some other stuff. Anyway, now that we’ve been on a dinner date together, let’s talk about how we can use SP underscore human events to track wait stats. We’re going to use the store procedure in a little bit different of a way than we have in the past few videos where we set up a more permanent extended event session and sort of looked at the data that comes into there from different things happening. This time we’re going to use it to sample the wait stats for a duration of time on the server. And since I was, so there’s a little bit of a funny, just sort of bit of coincidence in this video is a while back, the lovely, wonderful, talented Eric EJ on Twitter, who took over maintaining SQL query stress from Adam mechanic when Adam, Adam sort of open source that thing, had posted a blog post about inserts. Well, it wasn’t his post. Somebody reposted it.
Someone else wrote it and did all this stuff. But a post was about inserts and goods and integers. And there was a lot of talk about index fragmentation. And I’ve been I’ve been working up some demos to show that it’s not the index fragmentation that is a problem. And this is a sort of a precursor to those demos. This is just a test sort of proc that I have to do a bunch of singleton inserts with different data types as the clustered primary key of the table. So let’s all give a round of applause to Eric EJ. He spelled also for two reasons. One, spells his name correctly. It’s Eric with a K. And two, for doing a lot of great community work. I mean, aside from SQL query stress, he does a lot of stuff with entity framework and whatnot, trying to make that better for, well, I guess for all sorts of database folks. But you know, I mostly work with the SQL Server folks who end up using entity framework. So round of applause there. We appreciate you, Eric EJ. You are, you are, you are, you you are truly an MVP in my heart, not just a Microsoft. Anyway, let’s look at this. And let’s actually kick this off running. And while that kicks off running, we’re going to start this. And this is just going to do a bunch of inserts. And it’s going to take around a minute. Now, well, that runs. I’m going to go tell you about a couple things with SP underscore human events. One is that, when you run it for a sample like this, there are a bunch of sort of analysis queries that it spits out at the end. If you use SP human events to make more permanent extended event sessions and do stuff with that, it will also create a bunch of views. This is all in the lovely documentation on GitHub. You can take a look at that if you’re, if you’re interested in more information there. But it will also create a bunch of views that mimic the output of the session data that you see when the store procedure finishes running for a duration of time. I do that because I don’t want you to have to figure out how to query things on your own to get sort of, you know, commensurate results in different ways that you might use the store procedure.
You know, I create the thing, I wrote the thing, and I want you to be able to use the thing however you feel, however you feel comfortable and try to try to give you as many ways to make it as easy as possible to get in and access things. So when you sample weight stats and you have the extended event run, it runs for however long you put in the second sample there for, and then it kills and drops the extended event session at the end. Good, good, good.
Now, let’s look at what the results give us back. We have total weights for everything across all of the time that the session ran for, right? So this is total weights.
There, well, look at, there’s a column called total weights. So we see how many instances of the weight occurred, the duration of time that accumulated for the weights, the signal duration, and then the average milliseconds per weight. So we know, we can get a feeling for a few different things here.
One is how many times the weight happened, right? Is it a lot or is it little? How much total time that weight was responsible for in the window of time that we measured? And how long, on average, that weight lasted when it occurred, right?
Like, we don’t want, like, if a weight happened, like, two or three times, or there was a long, like, say it was a lock weight or something like that, we would want to know how long queries were waiting on locks on average during that time to figure out if we have a locking problem. If the average milliseconds per weight for the locks was fairly low, then we know that it’s probably not a locking issue.
I mean, it’s something we could dig into, but it’s probably not going to be the first thing that I look at. The second one we have down here is total weights by database. So if you have, I mean, a lot, most everyone has multiple databases on their server, so you can figure out which databases had the most weights happen.
Sometimes there is a null in the database name. That’s not my fault. That’s not me not being able to resolve a database name or something. That’s in the extended event data.
That’s me pulling directly from the XML. So if database name in there is null, then there’s really nothing I can do about that for you. So whatever.
Sorry about that. Maybe you could file a bug report with Microsoft. Maybe you’ll have better luck filing bug reports with Microsoft than I do. But you’ll get just about the same information here.
Total weights, duration, signal duration, and average milliseconds per weight. That doesn’t change a whole lot from the total weights here because I don’t have a bunch of very active databases. So everything’s going to look pretty much down here like it does up here.
But then the part that I like the most, the part that I think is the coolest, is this bottom section, which is total weights by query in database. So this is where what I do.
So what I do when I can do it is find query plans and statement text for the queries that ran and accrued the weights that happened during the window of time that you measure. So again, the total weights and stuff in here isn’t going to look terribly different from what it looks like up here just because there’s not a lot of activity on my server, just me pounding away with these inserts.
So this is all going to be the same query text and plan. It is a little bit repetitive. I try to get the SQL handles in the extended event and then go to the plan cache to look for those SQL handles in the plan cache so that I can figure out the text and the query plan for them.
So I get that additional information from the plan cache. If you’re measuring something on site like this, like for a duration of time, there’s a pretty good chance that the plans will still be in the cache by the time this thing finishes running. But I can make no guarantees that it absolutely will be.
So if we look at the statement text here, this is SP human events doing a whole thing. We don’t really need to look at that. It’s quite a bit of code in there.
We have the statement text of what ran. So this is the insert that was happening. This is all the singleton insert stuff that was going on. This is the very unimpressive query plan for all the inserts that were happening.
We don’t need to save that. But then, you know, we can see in here, let’s just go for these last bottom three rows because those are the ones that we have the weights for. We can see that these queries hit some write log weights.
The average duration was pretty quick there. We were able to push those writes through pretty quick. We hit some page latch and page latch EX weights.
Those are also fairly quick here. We did accumulate a bit of time on them, but we also did a lot of them. For this run that I did here of the insert test, we did 4,000 iterations with 100 threads running for a total of 400,000 iterations there.
So 400,000 executions of those queries produced fairly minimal weights. So our insert test, I think, was, you know, pretty efficient, right? We were able to bang a lot of inserts into that table in about a minute.
400,000 inserts a minute, pretty good, right? I wish I did that kind of business. Maybe someday, maybe someday. Although I’m not sure that there are 400,000 SQL Server customers per minute that I could get contracts signed for.
I’d be very busy. I’d probably at that point be the CEO of a large corporation with many minions doing all sorts of my biddings. Ah, man.
Got to get some more minions. Anyway, this is one way to use SP underscore human events to track weight stats. Again, you can also create a persistent extended event session to grab them. And SP human events will create views for you when you do that to grab the results that look like this as much as possible.
You know, the plan cache is a volatile place. And I can’t guarantee that the plans and everything will always be in there for you to have attached to the weights that happened. But there’s not really much I can do about to fix that.
I did think about involving query store here. But, you know, in this day and age, I still don’t run into a lot of folks who have query store turned on. And there would also be some additional complications in the code to, you know, make sure that the database has query store to go look in query store for the SQL handle.
It still might not even be in there depending on query store settings. So, you know, it’s a lot of complication for what is potentially very little reward. But maybe sometime down the line if, you know, Microsoft ever decides to have query store replace the plan cache and it is, you know, on by default for everyone in the world, which it is in SQL Server 2022.
But, you know, hard time running into a lot of people with that in production just yet. Maybe then it will be worth the code review. But, gosh, I hope I’m doing something else by then.
I hope I’m retired by the time that happens. So, anyway, that’s about all I had to say here. So, thanks for watching.
Like and subscribe if that’s the kind of thing you’re into. If not, then, I don’t know, just keep hitting F5 until a new video shows up, I guess. That’s a good use of your time.
All right. DBA is a switch from hitting F5 and SSMS on SP who is active to hitting F5 on my YouTube video playlist to see if a new video showed up. But maybe you could write some sort of program that just hits when you hit F5 in one place, it hits F5 everywhere.
It just refreshes everything. Wouldn’t that be nice? Like, yeah.
Anyway. There I go again. Anyway. Yeah. Thanks for watching. Like and subscribe. And I will be recording more videos about how I use other SQL Server community tools after this. I’m going to go through a few more of mine.
SP Quickie Store and SP Pressure Detector. And then I’ll do who is active and probably the Blitz scripts as well. Because there are a couple of few of those that just do not get enough love, affection, and attention. Anyway.
That’s enough for now. Goodbye. Have a nice day. It’s not. It’s still not Friday. I’m told. Which is very depressing. All right. Well. That’s enough for me.
That’s enough of me. Thank you.
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.