Thursday 1 March 2012

Finding recent SQL deadlocks


Identifying deadlocks is often a pain, and previously required various trace flags turning on that then filled up your SQL event log with errors about deadlocks.
Great if you have time to go through the error log - not so helpful if you just want a quick overview of when deadlocks happened, and what objects were involved.

The trace flag method also wasn't much use when someone asked about a deadlock that had just happened, and the trace flags weren't already running, and your time-machine is at the menders.

Dashing to the rescue in SQL 2008 R2, is "Extended Events".
This works a bit like an in built profiler trace for certain events.  And as luck would have it, SQL has a system event session that already captures deadlock information for you without you needing to even turn anything on.
Also, as the data is stored in XML, you can read the data directly into a useful format

I wasn't very familiar with the SQL XML parsing, and I've seen various complicated ways of retrieving the useful data.
However I  found that some of the methods really hammered server cpu, so I played around until I found a relatively straightforward and low impact way of reading the XML.

DECLARE @XMLData XML

SELECT TOP 1 @XMLData = CAST(target_data  AS XML)
FROM sys.dm_xe_session_targets st
JOIN sys.dm_xe_sessions s ON s.address = st.event_session_address
WHERE name = 'system_health'

SELECT  col.value('(./@timestamp)', 'DATETIME') AS Deadlock_TimeStamp , 
col.value('(data/value)[1]', 'VARCHAR(MAX)') AS DeadLock_XML
FROM @XMLData.nodes ('//event') AS X(Col)
WHERE col.value('(data/value)[1]', 'VARCHAR(MAX)') LIKE '<deadlock%'

OK, so the deadlock info is still XML, but we immediately have the date/time of deadlocks, and the details of each event.

Diving further into XML coding, I found I could still pull out some more useful info without needing to manually start looking anything up yet.
For example, run the previous select into a temp table, such as #DATA, and you can now run this:

SELECT Deadlock_TimeStamp , 
spid, 
DB_NAME(Currentdb) AS DBName,
inputbuf,
CASE WHEN InputBuf LIKE '%Object Id%' 
THEN OBJECT_NAME(SUBSTRING(InputBuf, CHARINDEX('Object Id', InputBuf) + 12, LEN(InputBuf) - CHARINDEX('Object Id', InputBuf) - 12 ), currentdb)
ELSE '' END AS ObjectName,
hostname,
waitresource
FROM 
(
SELECT Deadlock_TimeStamp,
a.value('/process[1]/@spid', 'INT') AS spid, 
a.value('/process[1]/@waitresource', 'VARCHAR(100)') AS waitresource,
a.value('/process[1]/@hostname', 'VARCHAR(100)') AS hostname,
a.value('/process[1]/@currentdb', 'INT') AS currentdb,
inputbuf
FROM 
(SELECT data.block.query('.') AS a, Block.value('inputbuf[1]', 'varchar(MAX)') AS inputbuf, d.Deadlock_TimeStamp
FROM 
#DATA d
CROSS APPLY DeadLock_XML.nodes ('//process-list/process')  AS Data (Block)
) x
) y

Now for each deadlock we know the database, what was running (the inputbuf field) or the object being referenced, and the waitresource details.

I've done a couple of posts on how to identify what the waitresource field refers to, so you could go further and automate that as well if you want, but for now this gives a quick overview of what was going on in the deadlocks.

Wrap all this up in a proc, add a data parameter or two, and you have a quick way of returning details on yesterdays deadlocks the next time your time machine is broken!

Word of warning - the data in sys.dm_xe_session_targets is purged when the session event is restarted, or the ring_buffer is full - if you want to keep a history of deadlocks I'd recommend you write the information into a table on a regular basis.

I would also highly recommend the Extended Events SSMS Addin available here: Extended Events Addin - it makes creating event sessions much more straightforward.

1 comment:

Anonymous said...

thanks I was looking for something like this...

Post a Comment