The question came up at SQL Rally, “Can you use Extended Events to monitor for query timeouts?”
My immediate response was yes… and then I stood there trying to think of exactly how I’d do it. Nothing came quickly to mind. So, I promised to track down the answer and post it to the blog.
My first thought is to use the Causality Tracking feature to find all the places where you have a sql_batch_starting without a sql_batch_completed (or the same thing with rpc calls). And you know what, that would work. But, before I got too deep in trying to write the query that would find all the mismatched attach_activity_id values that have a sequence of 1, but not one of 2, I did some additional reading. Seems there’s another little trick that works even better (sort of). It’s to set up an Event Pairing Target.
This is pretty slick. Here’s the code I used to set up for “timeouts” in SQL Server Management Studio:
CREATE EVENT SESSION [Timeouts] ON SERVER
ADD EVENT sqlserver.sql_batch_completed (
WHERE ([result] <> (2))),
ADD EVENT sqlserver.sql_batch_starting (
ADD TARGET package0.pair_matching (SET begin_event = N'sqlserver.sql_batch_starting',
begin_matching_actions = N'sqlserver.session_id',
begin_matching_columns = N'batch_text',
end_event = N'sqlserver.sql_batch_completed',
end_matching_actions = N'sqlserver.session_id',
end_matching_columns = N'batch_text')
WITH (MAX_MEMORY = 4096 KB,
EVENT_RETENTION_MODE = ALLOW_SINGLE_EVENT_LOSS,
MAX_DISPATCH_LATENCY = 30 SECONDS,
MAX_EVENT_SIZE = 0 KB,
MEMORY_PARTITION_MODE = NONE,
TRACK_CAUSALITY = ON,
STARTUP_STATE = OFF)
A couple of notes. You see the “timeout” in quotes above. That’s because I wasn’t getting a timeout in SSMS, despite setting one. Rather than muck around (I’ll figure that out later), I just set a long running query and then stopped it, but, I put a filter in place to not capture batches that terminated from an Abort command, [result] <> 2. But that did it. As soon as I aborted, I could use the query supplied at the link for Event Pairing Target to immediately see my unmatched pair. That’s quick and easy timeout monitoring using extended events. Output here:
<event name="sql_batch_starting" package="sqlserver" timestamp="2015-03-10T17:25:14.089Z">
<type name="unicode_string" package="package0" />
FROM Production.ProductCostHistory AS pch,
Production.BillOfMaterials AS bom,
Person.ContactType AS ct;</value>
<action name="session_id" package="sqlserver">
<type name="uint16" package="package0" />
<action name="attach_activity_id_xfer" package="package0">
<type name="activity_id_xfer" package="package0" />
<action name="attach_activity_id" package="package0">
<type name="activity_id" package="package0" />
So, here’s the biggest question, would I actually use this in production?
I’m a little nervous about using the batch_text as a matching point. With rpc_completed you could just use session_id and object_name or object_id. That’d be great. So, if I were going to use this in production, I’d probably only monitor for certain databases, putting tighter filtering in place for batch commands. But, other than that, I can query the target and pull out any timeout objects, so this is actually pretty slick and works well.
The only shortcoming I see is that you can’t add two pair matching targets in a session, so you would need one session for batch timeouts and another for rpc timeouts. Not the end of the world, but worth noting.