June 5, 2014 at 10:01 am
I've done a search of the forum for articles on this subject and in one about 2 or 3 years ago, Gail Shaw commented on a similar situation in this forum by saying she didn't understand how this could occur. I've also read an earlier article by her entitled "SQL Server Deadlocks By Example". Great article - I highly recommend it - but it doesn't give me any clues as to how I should approach this situation. So I'm posting to the forum in the hope that in the intervening years someone has come up with additional methods to investigate this particular type of deadlock.
In my situation, there are two different stored procedures that want to insert/update the same table. The table has a unique clustered index.
Here is the resource section of the Deadlock graph from the SQL Server error log -
waiter id=processd99288 mode=U requestType=wait
waiter-list
owner id=processd98e08 mode=X
owner-list
keylock hobtid=72057594061717504 dbid=12 objectname=ETLAdmin.audit.CDCCaptureLog indexname=CDCCaptureTableNameIdx id=lock3bf0bee00 mode=X associatedObjectId=72057594061717504
waiter id=processd98e08 mode=U requestType=wait
waiter-list
owner id=processd99288 mode=X
owner-list
keylock hobtid=72057594061717504 dbid=12 objectname=ETLAdmin.audit.CDCCaptureLog indexname=CDCCaptureTableNameIdx id=lock801ca780 mode=X associatedObjectId=72057594061717504
resource-list
Any suggestions? Or do I need to post the rest of the deadlock graph?
June 5, 2014 at 10:30 am
Is this of any help?
http://sqlperformance.com/2013/11/t-sql-queries/single-tx-deadlock
Jason...AKA CirqueDeSQLeil
_______________________________________________
I have given a name to my pain...MCM SQL Server, MVP
SQL RNNR
Posting Performance Based Questions - Gail Shaw[/url]
Learn Extended Events
June 6, 2014 at 6:06 am
I don't know if this fits your situation. I had a very small table, with 2 rows. Two different processes constantly update their respective record.., but would deadlock.
I added a char(8000) field as [Comment] to the table. No more Deadlocks.
The issue was that the table was so small, it fits onto a single page. The Page Lock prevented the second process from getting a lock..
Just something to consider..
June 6, 2014 at 7:42 am
Well, the deadlocks by example article is only 6 months old, so not all that many intervening years. 🙂
It's not a single transaction deadlock, there are two processes, so two different sessions are involved, they're just on the same resource.
Could you post the entire deadlock graph please?
Gail Shaw
Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability
June 9, 2014 at 2:55 pm
Gail, you're right. I went back to take a look and I 'exagerrated' a little when I said two years!:-)
Here's the entire deadlock graph -
<?xml version="1.0" encoding="utf-8" ?>
- <deadlock-list>
- <deadlock victim="process4ccbb88">
- <process-list>
- <process id="process4ccbb88" taskpriority="0" logused="448" waitresource="KEY: 12:72057594061979648 (27035a9f1f43)" waittime="4188" ownerId="1243251370" transactionname="user_transaction" lasttranstarted="2014-06-08T15:25:22.097" XDES="0x3923d1a10" lockMode="U" schedulerid="7" kpid="4632" status="suspended" spid="94" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2014-06-08T15:25:22" lastbatchcompleted="2014-06-08T15:25:22" clientapp="Microsoft SQL Server" hostname="SEADWSQL02" hostpid="208216" loginname="CHNW\pdipis1" isolationlevel="read committed (2)" xactid="1243251370" currentdb="12" lockTimeout="4294967295" clientoption1="673185824" clientoption2="128056">
- <executionStack>
<frame procname="ETLAdmin.audit.CDCCaptureLog_OnCount" line="24" stmtstart="1222" stmtend="3166" sqlhandle="0x03000c003f438008ea92ec0039a300000100000000000000">UPDATE [audit].[CDCCaptureLog] SET CapturedStartChangeSeq = isnull(@CapturedStartChangeSeq, CapturedStartChangeSeq) ,CapturedStartTime = isnull(@CapturedStartTime, CapturedStartTime) ,CapturedEndChangeSeq = isnull(@CapturedEndChangeSeq, CapturedEndChangeSeq) ,CapturedEndTime = isnull(@CapturedEndTime, CapturedEndTime) ,InsertAllCount = isnull(@InsertAllCount, InsertAllCount) ,UpdateAllCount = isnull(@UpdateAllCount, UpdateAllCount) ,DeleteAllCount = isnull(@DeleteAllCount, DeleteAllCount) ,InsertNetCount = isnull(@InsertNetCount, InsertNetCount) ,UpdateNetCount = isnull(@UpdateNetCount, UpdateNetCount) ,DeleteNetCount = isnull(@DeleteNetCount, DeleteNetCount) ,SourceCount = isnull(@SourceCount, SourceCount) ,TargetCount = isnull(@TargetCount, TargetCount) WHERE CDCCaptureLogID = @CDCCaptureLogID</frame>
<frame procname="STG_Xcelys.xcelys.uspLoad_BATCH_STATUS_Full" line="157" stmtstart="10380" stmtend="11596" sqlhandle="0x03001b00a329877a4f53a8003ba300000100000000000000">EXEC ETLAdmin.audit.CDCCaptureLog_OnCount @CDCCaptureLogID = @CDCCaptureLogID ,@CapturedStartChangeSeq = @CapturedStartChangeSeq ,@CapturedEndChangeSeq = @CapturedEndChangeSeq ,@CapturedStartTime = @CapturedStartTime ,@CapturedEndTime = @CapturedEndTime ,@InsertAllCount = @TargetCount ,@UpdateAllCount = 0 ,@DeleteAllCount = 0 ,@InsertNetCount = @TargetCount ,@UpdateNetCount = 0 ,@DeleteNetCount = 0 ,@SourceCount = @SourceCount ,@TargetCount = @TargetCount ------------------------------------------ -- Log Event End ------------------------------------------</frame>
<frame procname="STG_Xcelys.xcelys.uspLoad_BATCH_STATUS_Delta" line="89" stmtstart="6702" stmtend="6812" sqlhandle="0x03001b0061c877208e58a8003ba300000100000000000000">EXEC [xcelys].[uspLoad_BATCH_STATUS_Full] @ETL_JOB_ID</frame>
<frame procname="STG_Xcelys.xcelys.uspDelta_Load_All" line="42" stmtstart="2420" stmtend="2466" sqlhandle="0x03001b007f8aad396f51a8003ba300000100000000000000">EXEC @sql @ETL_JOB_ID</frame>
<frame procname="adhoc" line="1" sqlhandle="0x01001b00b19e7d1190fc71e1030000000000000000000000">EXEC xcelys.uspDelta_Load_All BATCH_STATUS, 3854</frame>
</executionStack>
<inputbuf>EXEC xcelys.uspDelta_Load_All BATCH_STATUS, 3854</inputbuf>
</process>
- <process id="process4ba1dc8" taskpriority="0" logused="452" waitresource="KEY: 12:72057594061979648 (fe01d0410b01)" waittime="4187" ownerId="1243251369" transactionname="user_transaction" lasttranstarted="2014-06-08T15:25:22.097" XDES="0x510989640" lockMode="U" schedulerid="6" kpid="4876" status="suspended" spid="89" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2014-06-08T15:25:21.920" lastbatchcompleted="2014-06-08T15:25:21.920" clientapp="Microsoft SQL Server" hostname="SEADWSQL02" hostpid="208216" loginname="CHNW\pdipis1" isolationlevel="read committed (2)" xactid="1243251369" currentdb="12" lockTimeout="4294967295" clientoption1="673185824" clientoption2="128056">
- <executionStack>
<frame procname="ETLAdmin.audit.CDCCaptureLog_OnEnd" line="9" stmtstart="272" stmtend="840" sqlhandle="0x03000c0078677409ec92ec0039a300000100000000000000">UPDATE [audit].[CDCCaptureLog] SET EndTime = getdate() ,Status = CASE WHEN Status = 0 THEN 1 --Complete ELSE Status END --CASE WHERE CDCCaptureLogID = @CDCCaptureLogID</frame>
<frame procname="STG_Xcelys.xcelys.uspLoad_company_master_Full" line="251" stmtstart="15216" stmtend="15384" sqlhandle="0x03001b0047ac4e41d651a8003ba300000100000000000000">EXEC ETLAdmin.audit.CDCCaptureLog_OnEnd @CDCCaptureLogID = @CDCCaptureLogID</frame>
<frame procname="STG_Xcelys.xcelys.uspLoad_company_master_Delta" line="89" stmtstart="6718" stmtend="6832" sqlhandle="0x03001b004bfdc7573c5aa8003ba300000100000000000000">EXEC [xcelys].[uspLoad_company_master_Full] @ETL_JOB_ID</frame>
<frame procname="STG_Xcelys.xcelys.uspDelta_Load_All" line="42" stmtstart="2420" stmtend="2466" sqlhandle="0x03001b007f8aad396f51a8003ba300000100000000000000">EXEC @sql @ETL_JOB_ID</frame>
<frame procname="adhoc" line="1" sqlhandle="0x01001b00634c8206c0dedf58070000000000000000000000">EXEC xcelys.uspDelta_Load_All COMPANY_MASTER, 3854</frame>
</executionStack>
<inputbuf>EXEC xcelys.uspDelta_Load_All COMPANY_MASTER, 3854</inputbuf>
</process>
</process-list>
- <resource-list>
- <keylock hobtid="72057594061979648" dbid="12" objectname="ETLAdmin.audit.CDCCaptureLog" indexname="CDCCaptureTableNameIdx" id="lock39f60b880" mode="X" associatedObjectId="72057594061979648">
- <owner-list>
<owner id="process4ba1dc8" mode="X" />
</owner-list>
- <waiter-list>
<waiter id="process4ccbb88" mode="U" requestType="wait" />
</waiter-list>
</keylock>
- <keylock hobtid="72057594061979648" dbid="12" objectname="ETLAdmin.audit.CDCCaptureLog" indexname="CDCCaptureTableNameIdx" id="lock2f826d380" mode="X" associatedObjectId="72057594061979648">
- <owner-list>
<owner id="process4ccbb88" mode="X" />
</owner-list>
- <waiter-list>
<waiter id="process4ba1dc8" mode="U" requestType="wait" />
</waiter-list>
</keylock>
</resource-list>
</deadlock>
</deadlock-list>
June 9, 2014 at 2:57 pm
SQLRNNR, thanks for the link. However, the deadlock I'm dealing with definitely has two users - two different stored procedures are accessing the same table. I just can't find the two resources that are causing the deadlock. Each process access the index in the same table - which looks like one resource to me.
Thanks for the link.
Willem
June 9, 2014 at 3:04 pm
Melliot,
The table that seems to be the center of my deadlock is 350 KB, definitely bigger than a page. Your response brings up a point I've never had to think about - how to deal with a table that small. At any rate, that isn't my issue as far as I can tell.
I've posted the entire deadlock graph, per Gail's request.
Thanks for responding.
Willem
June 9, 2014 at 3:06 pm
It's the same index, but different rows of that index (see the different values for ID in the keylock). It's not the same resource
Key lock is a lock on a single row, so process 1 locks row 1, process 2 locks row 2, then the two processes want locks on the rows the other has locked. Doesn't matter that it's the same index, it's two different parts of the index.
You may be able to alleviate this with a pagelock hint. Also check the indexes see whether page lock is enabled on them. Check the execution plans, make sure that the row estimations are correct and see how many rows they affect.
Can you post the execution plans of
UPDATE [audit].[CDCCaptureLog] SET EndTime = getdate() ,
Status = CASE
WHEN Status = 0
THEN 1 --Complete
ELSE Status END
--CASE
WHERE CDCCaptureLogID = @CDCCaptureLogID
and
UPDATE [audit].[CDCCaptureLog] SET CapturedStartChangeSeq = isnull(@CapturedStartChangeSeq, CapturedStartChangeSeq) ,CapturedStartTime = isnull(@CapturedStartTime, CapturedStartTime) ,CapturedEndChangeSeq = isnull(@CapturedEndChangeSeq, CapturedEndChangeSeq) ,CapturedEndTime = isnull(@CapturedEndTime, CapturedEndTime) ,InsertAllCount = isnull(@InsertAllCount, InsertAllCount) ,UpdateAllCount = isnull(@UpdateAllCount, UpdateAllCount) ,DeleteAllCount = isnull(@DeleteAllCount, DeleteAllCount) ,InsertNetCount = isnull(@InsertNetCount, InsertNetCount) ,UpdateNetCount = isnull(@UpdateNetCount, UpdateNetCount) ,DeleteNetCount = isnull(@DeleteNetCount, DeleteNetCount) ,SourceCount = isnull(@SourceCount, SourceCount) ,TargetCount = isnull(@TargetCount, TargetCount) WHERE CDCCaptureLogID = @CDCCaptureLogID
and list all the indexes on audit.CDCCaptureLog please.
Gail Shaw
Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability
June 9, 2014 at 3:30 pm
Gail, there is only one index on the table and it's a unique clustered index on two columns - one column is an identity column and the other is a sysname column.
I generated an estimated execution plan for each query and as far as I can tell, they are identical. How would you like me to add the two plans to this thread - in XML format and paste it into a response?
Willem
June 10, 2014 at 2:24 am
Not estimated. Actual plans. Save as .sqlplan files and attach them
Gail Shaw
Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability
June 10, 2014 at 12:25 pm
Gail, I've attached the two actual execution plans. This is the first time I've attached something and I think I did it right. Let me know if I didn't!
Willem
June 10, 2014 at 12:53 pm
Looks fine, I'll check them tomorrow.
Can you post the definition of the index please (the create index statement)
Gail Shaw
Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability
June 10, 2014 at 1:01 pm
Gail, here's the index definition - pretty straightforward.
Willem
June 10, 2014 at 1:26 pm
Ha! That's what I suspected.
That index doesn't support those queries. They filter on the second column of the index only, meaning they have to scan the index. Hence they will be reading and locking a lot more of the table than necessary.
Try creating a second index on CDCCaptureLogID, see how that changes the execution plans.
Gail Shaw
Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability
Viewing 14 posts - 1 through 14 (of 14 total)
You must be logged in to reply to this topic. Login to reply