How to know the SQL statements causing the Deadlock from this XML output?

Question

How to know the SQL statements causing the Deadlock from this XML output?

Mohammed Yousuf

Say Hey Kid

Points: 696
More actions
June 19, 2012 at 4:58 am

#392551

I can figure the stored procedures names using object ID's. But i want to determine the actual SQL statements that are involved. since there are too many lines of code inside SP's.
Note: The SP's are created "WITH ENCRYPTION" option
<deadlock>
<victim-list>
<victimProcess id="processcdeb048" />
</victim-list>
<process-list>
<process id="processcdeb048" taskpriority="0" logused="0" waitresource="OBJECT: 5:1288651934:14 " waittime="4097" ownerId="12406020" transactionname="INSERT EXEC" lasttranstarted="2012-06-19T13:33:47.680" XDES="0x2db8e6b60" lockMode="IS" schedulerid="15" kpid="312" status="suspended" spid="114" sbid="0" ecid="0" priority="0" trancount="1" lastbatchstarted="2012-06-19T13:33:47.680" lastbatchcompleted="2012-06-19T13:33:47.680" clientapp=".Net SqlClient Data Provider" hostname="APP02" hostpid="6548" loginname="ppp" isolationlevel="read committed (2)" xactid="12406020" currentdb="5" lockTimeout="4294967295" clientoption1="538968096" clientoption2="128024">
<executionStack>
<frame procname="" line="32" stmtstart="2772" stmtend="6064" sqlhandle="0x03000500d5a6b850a53afc0043a000000100000000000000" />
<frame procname="" line="39" stmtstart="2692" stmtend="3102" sqlhandle="0x030005009577e2790a332101739f00000100000000000000" />
<frame procname="" line="75" stmtstart="5000" stmtend="5536" sqlhandle="0x030005007472ea73a6610c01b29f00000100000000000000" />
<frame procname="" line="57" stmtstart="3550" stmtend="4104" sqlhandle="0x030005002136e5687d2ecc006ea000000100000000000000" />
</executionStack>
<inputbuf>
Proc [Database Id = 5 Object Id = 1759852065] </inputbuf>
</process>
<process id="processc5b6988" taskpriority="-10" logused="24484" waitresource="OBJECT: 5:1320652048:14 " waittime="686" ownerId="12390056" transactionname="user_transaction" lasttranstarted="2012-06-19T13:33:26.567" XDES="0x34792f030" lockMode="Sch-M" schedulerid="13" kpid="2768" status="suspended" spid="112" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2012-06-19T13:33:26.620" lastbatchcompleted="2012-06-19T13:33:26.620" clientapp=".Net SqlClient Data Provider" hostname="APP01" hostpid="17608" loginname="sa" isolationlevel="read committed (2)" xactid="12390056" currentdb="5" lockTimeout="4294967295" clientoption1="538968096" clientoption2="128024">
<executionStack>
<frame procname="" line="1" stmtstart="182" stmtend="418" sqlhandle="0x02000000257f05128745b0e6d8b16a322fb2b916c3f504ea" />
<frame procname="" line="1" sqlhandle="0x0400ff7fbe80662601000000000000000000000000000000" />
<frame procname="" line="29" stmtstart="4034" stmtend="4096" sqlhandle="0x0300050057d57c49ba1af400739f00000100000000000000" />
<frame procname="" line="47" stmtstart="3100" stmtend="3302" sqlhandle="0x030005007b27f310547bdd0074a000000100000000000000" />
</executionStack>
<inputbuf>
Proc [Database Id = 5 Object Id = 284370811] </inputbuf>
</process>
</process-list>
<resource-list>
<objectlock lockPartition="14" objid="1288651934" subresource="FULL" dbid="5" objectname="" id="lock2ed997c00" mode="Sch-M" associatedObjectId="1288651934">
<owner-list>
<owner id="processc5b6988" mode="Sch-M" />
</owner-list>
<waiter-list>
<waiter id="processcdeb048" mode="IS" requestType="wait" />
</waiter-list>
</objectlock>
<objectlock lockPartition="14" objid="1320652048" subresource="FULL" dbid="5" objectname="" id="lock1ada50e80" mode="IS" associatedObjectId="1320652048">
<owner-list>
<owner id="processcdeb048" mode="IS" />
</owner-list>
<waiter-list>
<waiter id="processc5b6988" mode="Sch-M" requestType="wait" />
</waiter-list>
</objectlock>
</resource-list>
</deadlock>

Viewing 13 posts - 1 through 12 (of 12 total)

You must be logged in to reply to this topic. Login to reply

Grant Fritchey SSC Guru Points: 398909 More actions · Answer 1

Try using the OBJECT_ID function with the database and object ID that are part of the input buffer. That should narrow it down.

"The credit belongs to the man who is actually in the arena, whose face is marred by dust and sweat and blood"
- Theodore Roosevelt

Author of:
SQL Server Execution Plans
SQL Server Query Performance Tuning

Mohammed Yousuf Say Hey Kid Points: 696 More actions · Answer 2

I can fetch the Object names.

But I want to determine the actual SQL statements SELECT/INSERT/DELETE/UPDATE that are involved in deadlock.

The objects point to SP's and they have many lines of codes

The SP's are created "WITH ENCRYPTION" option. Will this suppress any information in the result?

Grant Fritchey SSC Guru Points: 398909 More actions · Answer 3

Ah, you know, I'm not sure. It might.

You're using traceflag 1222 to capture this?

"The credit belongs to the man who is actually in the arena, whose face is marred by dust and sweat and blood"
- Theodore Roosevelt

Author of:
SQL Server Execution Plans
SQL Server Query Performance Tuning

Mohammed Yousuf Say Hey Kid Points: 696 More actions · Answer 4

I am using the query below to fetch this information

SELECT CAST(event_data.value('(event/data/value)[1]',

'varchar(max)') AS XML) AS DeadlockGraph

FROM ( SELECT XEvent.query('.') AS event_data

FROM ( -- Cast the target_data to XML

SELECT CAST(target_data AS XML) AS TargetData

FROM sys.dm_xe_session_targets st

JOIN sys.dm_xe_sessions s

ON s.address = st.event_session_address

WHERE name = 'system_health'

AND target_name = 'ring_buffer'

) AS Data -- Split out the Event Nodes

CROSS APPLY TargetData.nodes('RingBufferTarget/

event[@name="xml_deadlock_report"]')

AS XEventData ( XEvent )

) AS tab ( event_data )

The SQL Server version is

Microsoft SQL Server 2008 R2 (SP1) - 10.50.2500.0 - Enterprise Edition

Grant Fritchey SSC Guru Points: 398909 More actions · Answer 5

Oh, you're pulling it from the extended event data. That's great. Well done. Still, doesn't change things. I'm not sure how encryption affects it. I'm going to try to set up some tests & get back to you.

"The credit belongs to the man who is actually in the arena, whose face is marred by dust and sweat and blood"
- Theodore Roosevelt

Author of:
SQL Server Execution Plans
SQL Server Query Performance Tuning

Grant Fritchey SSC Guru Points: 398909 More actions · Answer 6

Hmmm... A couple of points. I encrypted a proc and made a deadlock occur with it. I did get back the statement information as part of the XML deadlock graph from the extended events:

<deadlock>

<victim-list>

<victimProcess id="process472310928" />

</victim-list>

<process-list>

<executionStack>

<frame procname="adhoc" line="1" stmtstart="64" sqlhandle="0x02000000d0c7f31a30fb1ad425c34357fe8ef6326793e7aa0000000000000000000000000000000000000000">

UPDATE [Purchasing].[PurchaseOrderDetail] set [OrderQty] = @1 WHERE [ProductID]=@2 AND [PurchaseOrderID]=@3 </frame>

<frame procname="adhoc" line="1" sqlhandle="0x02000000b3eb2f2775cd4b2ff5256510f0ca8f71762f6d740000000000000000000000000000000000000000">

UPDATE Purchasing.PurchaseOrderDetail

SET OrderQty = 4

WHERE ProductID = 448

AND PurchaseOrderID = 1255; </frame>

</executionStack>

<inputbuf>

UPDATE Purchasing.PurchaseOrderDetail

SET OrderQty = 4

WHERE ProductID = 448

AND PurchaseOrderID = 1255; </inputbuf>

</process>

<executionStack>

<frame procname="AdventureWorks2012.Purchasing.uPurchaseOrderDetail" line="39" stmtstart="2732" stmtend="3864" sqlhandle="0x0300090004cc856a0d55da0014a0000000000000000000000000000000000000000000000000000000000000">

UPDATE [Purchasing].[PurchaseOrderHeader]

SET [Purchasing].[PurchaseOrderHeader].[SubTotal] =

(SELECT SUM([Purchasing].[PurchaseOrderDetail].[LineTotal])

FROM [Purchasing].[PurchaseOrderDetail]

WHERE [Purchasing].[PurchaseOrderHeader].[PurchaseOrderID]

= [Purchasing].[PurchaseOrderDetail].[PurchaseOrderID])

WHERE [Purchasing].[PurchaseOrderHeader].[PurchaseOrderID]

IN (SELECT inserted.[PurchaseOrderID] FROM inserted); </frame>

<frame procname="AdventureWorks2012.dbo.DL2e" line="5" stmtstart="126" sqlhandle="0x03000900d7ef9050a0f3af0075a0000001000000000000000000000000000000000000000000000000000000">

unknown </frame>

<frame procname="adhoc" line="1" sqlhandle="0x01000900fe00e208603d10350400000000000000000000000000000000000000000000000000000000000000">

EXEC dl2e </frame>

</executionStack>

<inputbuf>

EXEC dl2e </inputbuf>

</process>

</process-list>

<resource-list>

<keylock hobtid="72057594046840832" dbid="9" objectname="AdventureWorks2012.Purchasing.PurchaseOrderDetail" indexname="1" id="lock46b6dab00" mode="X" associatedObjectId="72057594046840832">

<owner-list>

<owner id="process47b01dc38" mode="X" />

</owner-list>

<waiter-list>

<waiter id="process472310928" mode="U" requestType="wait" />

</waiter-list>

</keylock>

<keylock hobtid="72057594046906368" dbid="9" objectname="AdventureWorks2012.Purchasing.PurchaseOrderHeader" indexname="1" id="lock46746c300" mode="X" associatedObjectId="72057594046906368">

<owner-list>

<owner id="process472310928" mode="X" />

</owner-list>

<waiter-list>

<waiter id="process47b01dc38" mode="U" requestType="wait" />

</waiter-list>

</keylock>

</resource-list>

</deadlock>

I'm not sure why you're not seeing it. I've absolutely verified that I'm looking at an encrypted proc.

"The credit belongs to the man who is actually in the arena, whose face is marred by dust and sweat and blood"
- Theodore Roosevelt

Author of:
SQL Server Execution Plans
SQL Server Query Performance Tuning

Mohammed Yousuf Say Hey Kid Points: 696 More actions · Answer 7

Have you used the query (posted in previous comments) to fetch deadlock victims?

Or

SQL Profiler Event "Deadlock Graph"

Or

Something else

Grant Fritchey SSC Guru Points: 398909 More actions · Answer 8

It's xml_deadlock_report event, which is the deadlock graph.

"The credit belongs to the man who is actually in the arena, whose face is marred by dust and sweat and blood"
- Theodore Roosevelt

Author of:
SQL Server Execution Plans
SQL Server Query Performance Tuning

Daxesh Patel Hall of Fame Points: 3208 More actions · Answer 9

Mohammed Yousuf (6/19/2012)
I can fetch the Object names.
But I want to determine the actual SQL statements SELECT/INSERT/DELETE/UPDATE that are involved in deadlock.
The objects point to SP's and they have many lines of codes
The SP's are created "WITH ENCRYPTION" option. Will this suppress any information in the result?

I think once you have sqlhandle, you should be able to find out sql statement

select * from sys.dm_exec_sql_text(sqlhandle)

Sqlish Ten Centuries Points: 1085 More actions · Answer 10

Mohammed,

Was wondering if you managed to find a solution to this.

Grant,

I had the same issue on my shiny new extended events deadlock capture automation I have been working on ...

I am definitely looking at the system_health extended events xml_deadlock_report event for the deadlock graph and this is what I see...

I am not sure if this is the same bug that was fixed in CU1 for SQL 2008.

I ran into this issue on SQL Server 2008 R2 SP1 + CU6 this afternoon. Any help or pointers would be much appreciated.

<victim-list>

</victim-list>

<process-list>

</executionStack>

Proc [Database Id = 6 Object Id = 1756897676] </inputbuf>

</process>

</executionStack>

Proc [Database Id = 6 Object Id = 1756897676] </inputbuf>

</process>

</process-list>

<resource-list>

<owner-list>

</owner-list>

<waiter-list>

</waiter-list>

</keylock>

<owner-list>

</owner-list>

<waiter-list>

</waiter-list>

</keylock>

</resource-list>

</deadlock>

=======================================================================================

Visit my technical reference; you might find some of your issues already documented.

Grant Fritchey SSC Guru Points: 398909 More actions · Answer 11

I'm not sure. I'm not seeing the issue, so I don't have any advice.

The one thing I can tell you is that you have the sql handle, so you can get the query out of the cache (unless it's aged out by the time you look it up) using DMO queries.

"The credit belongs to the man who is actually in the arena, whose face is marred by dust and sweat and blood"
- Theodore Roosevelt

Author of:
SQL Server Execution Plans
SQL Server Query Performance Tuning

rufeizhao SSC Rookie Points: 27 More actions · Answer 12

<executionStack>
<frame procname="" line="200" stmtstart="12978" stmtend="14164" sqlhandle="0x030006008c21b868976a890024a000000100000000000000" />
</executionStack>

The most useful part is the line attribute and sqlhandle attribute.

By using the following dmv query, you can get the whole sql text, most likely the stored procedure.

SELECT * FROM sys.dm_exec_sql_text(0x030006008c21b868976a890024a000000100000000000000)

To find out the exact line which is being blocked, you can open the stored procedure in SMSS, right click the stored procedure, and select script to new query window, from that windows, you can use the line number to locate the SQL statement which is blocked.

Note that the DMV query is time aware, you should execute the query as soon as possible after you suffer a timeout/blocking. Otherwise you got nothing.

Note that a typical output of the create stored proc looks like:

SET QUOTED_IDENTIFIER ON

GO

CREATE PROC [dbo].[test_proc] AS

BEGIN

--SET LOCK_TIMEOUT 5000

SELECT COUNT(*) FROM dbo.XXX

DECLARE @x INT = 3

UPDATE test_timeout SET age = age + @x

--SET LOCK_TIMEOUT 5000

end

GO

You should skip the prolog lines, count the "CREATE PROC..." as line 2.

I test and verified it on SQL Server 2008 R2.

The statstart and statend attribute looks useful, but I haven't found a practical way to utilize them.