Extended Events: Queries and Waits

Wouldn’t it be great to be able to put together queries and waits at the same time?

You all capture query metrics using some method. Most of us query sys.dm_os_wait_stats or sys.dm_db_wait_stats. Combining them is hard.

You could query the wait stats. Store the results in a table variable. Run the query in question. Then query the wait stats again into a different table variable. Join the two table variables together to find the differences. Ta-da, you have query waits.

Well. Probably. If you’re the only one running queries on the system. Also, you’re not seeing system waits or other noise caused by activity on the system.

Or, we could put Extended Events to work.

Queries and Waits

Just like Profiler/Trace, you can capture stored procedures, batches, and individual statements within each. However, unlike Profiler, we can also capture waits as events. Further, through the use of Causality Tracking, we can put it all together so that you can be sure that the query and only it’s associated waits are on display. Here’s an example session:

CREATE EVENT SESSION QueryWaits
ON SERVER
    ADD EVENT sqlos.wait_completed
    (WHERE (sqlserver.database_name = N'Adventureworks')),
    ADD EVENT sqlos.wait_info_external
    (WHERE (sqlserver.database_name = N'Adventureworks')),
    ADD EVENT sqlserver.rpc_completed
    (WHERE (sqlserver.database_name = N'Adventureworks')),
    ADD EVENT sqlserver.sql_batch_completed
    (WHERE (sqlserver.database_name = N'Adventureworks'))
    ADD TARGET package0.event_file
    (SET filename = N'QueryWaits')
WITH
(
    TRACK_CAUSALITY = ON
);
GO

In addition to the standard events for queries, I’ve added sqlos.wait_completed and sqlos.wait_info_external. These two events give me the internal and external waits for SQL Server and the underlying OS.

So now, I can run a query, and using the ability of the Live Data window to group information, I can group the information by the Causality Tracking GUID:

And that my friends is only the waits associated with the one query. TA-DA indeed!

Now, we could get into filtering this stuff too. Toss the ones that have little to no duration, ensure that I only capture for a specific query or procedure, all would be helpful. However, this is how you can easily identify just the waits associated with a single query, and only that query.

You Can’t Do That in Profiler

Trace events simply don’t capture waits. Done. If you want to see individual waits in action, you must go to Extended Events. There is no other viable option. Once you’re there, then you get all kinds of functionality. With Causality Tracking enabled we can associate waits to queries. I’m certain I don’t have to explain why that might be useful.

---

Want to learn how to use Extended Events more effectively? I’m going to keep posting to the blog, but I have another opportunity for you. Next week, April 1-3, Redgate Streamed, an all new community event, will be taking place. I’m teaching a class just on Extended Events. I’ll show as many of the different ways I use this tool as I can squeeze into an hour. Please stop by. The event is completely free.

Also, just register for the event, even if you don’t want to attend. Why? Because Redgate is donating money to the WHO Covid-19 fund. We’ll add to our donation for every registration we get for this event. You heard right. The registrations are on top of the donation we’re already making.

Also, also, if you want a little bit of fun in these less than cheery times, the DBAle podcast is hosting a virtual pub quiz. Go sign up and have some fun.