none
Deadlock investigation

    Question

  • I have deadlock trace obtained from Trace flag 1204 about nodewise information. Any best way now to go ahead and investigate it further? and find out the actual SQL queries which caused this frequent deadlock?


    Kindly mark the reply as answer if they help

    Tuesday, April 17, 2012 5:22 AM

Answers

  • A quick look at this tells this

    spid 868 - 

    INSERT INTO Table1     
    VALUES(x1,x2,x3,x4,x5)    
    Proc [Database Id = 8 Object Id = 146867640]  - dbo.sp_somesp

    spid 153  - 

    SELECT x,x,x,
    FROM Table1 WITH (UPDLOCK, ROWLOCK)
    WHERE x1= '' and x2 = ''     
    Proc [Database Id = 8 Object Id = 146867640]   -- dbo.sp_somesp

    Spid 153 is the victim 

    the database db1 has a table table1 which has two indexes IX_Ix1 and IX_Ix2 and both the queries need update lock on both the indexes which is causing the problem. It is the same sp run multiple times are at different points of execution and during that time requires almost the same locks.

    It could be a problem of running multiple execution it at same times which is causing the issue,classic deadlock example? I think you should be able to take it forward from now.

    HTH


    Regards, Ashwin Menon My Blog - http:\\sqllearnings.com


    • Edited by Ashwin Menon Tuesday, April 17, 2012 10:38 AM
    • Marked as answer by Sunil Gure Tuesday, April 17, 2012 11:08 AM
    Tuesday, April 17, 2012 10:37 AM
  • Thanks Ashwin. Yup, It is UPDLOCK and ROWLOCK which are causing this issue. Using Lock hints ROWLOCK, UPDLOCK,  that acquire row-level locks may place locks on index keys rather than the actual data rows in some cases where we have non clustered covering index (Kind of X lock). I will remove this and trying tunning the SP.


    Kindly mark the reply as answer if they help

    • Marked as answer by Sunil Gure Tuesday, April 17, 2012 11:08 AM
    Tuesday, April 17, 2012 11:07 AM

All replies

  • What system are you running on? Trace Flag 1222 is the current flag for Deadlocks.

    There is a good blog post that will help you interpret the results from 1204 and 1222 flags:

    http://blogs.msdn.com/b/bartd/archive/2006/09/09/747119.aspx

    Seth

    
    
    

    http://lqqsql.wordpress.com


    • Edited by Seth Lynch Tuesday, April 17, 2012 8:51 AM
    • Proposed as answer by Ashwin Menon Tuesday, April 17, 2012 9:02 AM
    Tuesday, April 17, 2012 8:51 AM
  • The blog which Seth has pointed can be considered the Bible for deadlock detection and resolution if you have output from trace flag 1222

    for specific troubleshooting based on trace flag 1204 , may be these articles can give you a start 

    article1 

    article2

    On a diff note, if you can post the output , we can help you as well.


    Regards, Ashwin Menon My Blog - http:\\sqllearnings.com



    Tuesday, April 17, 2012 9:02 AM
  • 2012-04-16 22:30:04.460 spid6s       Deadlock encountered .... Printing deadlock information
    2012-04-16 22:30:04.460 spid6s       Wait-for graph
    2012-04-16 22:30:04.460 spid6s       NULL
    2012-04-16 22:30:04.460 spid6s       Node:1
    2012-04-16 22:30:04.470 spid6s       KEY: 8:72057594045333504 (39027a05cf3d) CleanCnt:3 Mode:U Flags: 0x0
    2012-04-16 22:30:04.470 spid6s        Grant List 3:
    2012-04-16 22:30:04.470 spid6s          Owner:0x0000000BCA88D100 Mode: U        Flg:0x0 Ref:1 Life:02000000 SPID:153 ECID:0 XactLockInfo: 0x00000007CDF61A58
    2012-04-16 22:30:04.470 spid6s          SPID: 153 ECID: 0 Statement Type: SELECT Line #: 88
    2012-04-16 22:30:04.470 spid6s          Input Buf: RPC Event: Proc [Database Id = 8 Object Id = 146867640]
    2012-04-16 22:30:04.470 spid6s        Requested By:
    2012-04-16 22:30:04.470 spid6s          ResType:LockOwner Stype:'OR'Xdes:0x000000116C1E7A30 Mode: U SPID:868 BatchID:0 ECID:0 TaskProxy:(0x0000000E08ECE598) Value:0xd6e20400 Cost:(0/0)
    2012-04-16 22:30:04.470 spid6s       NULL
    2012-04-16 22:30:04.470 spid6s       Node:2
    2012-04-16 22:30:04.470 spid6s       KEY: 8:347217455677440 (88002022af91) CleanCnt:2 Mode:U Flags: 0x0
    2012-04-16 22:30:04.470 spid6s        Grant List 2:
    2012-04-16 22:30:04.470 spid6s          Owner:0x0000000279ACDA00 Mode: U        Flg:0x0 Ref:0 Life:02000000 SPID:868 ECID:0 XactLockInfo: 0x000000116C1E7A68
    2012-04-16 22:30:04.470 spid6s          SPID: 868 ECID: 0 Statement Type: INSERT Line #: 402
    2012-04-16 22:30:04.470 spid6s          Input Buf: RPC Event: Proc [Database Id = 8 Object Id = 146867640]
    2012-04-16 22:30:04.470 spid6s        Requested By:
    2012-04-16 22:30:04.470 spid6s          ResType:LockOwner Stype:'OR'Xdes:0x00000007CDF61A20 Mode: U SPID:153 BatchID:0 ECID:0 TaskProxy:(0x00000009E4EBE598) Value:0xd34b4f00 Cost:(0/0)
    2012-04-16 22:30:04.470 spid6s       NULL
    2012-04-16 22:30:04.470 spid6s       Victim Resource Owner:
    2012-04-16 22:30:04.470 spid6s        ResType:LockOwner Stype:'OR'Xdes:0x00000007CDF61A20 Mode: U SPID:153 BatchID:0 ECID:0 TaskProxy:(0x00000009E4EBE598) Value:0xd34b4f00 Cost:(0/0)
    2012-04-16 22:30:04.470 spid16s      deadlock-list
    2012-04-16 22:30:04.470 spid16s       deadlock victim=process56e9198
    2012-04-16 22:30:04.470 spid16s        process-list
    2012-04-16 22:30:04.470 spid16s         process id=process3e44718 taskpriority=0 logused=0 waitresource=KEY: 8:72057594045333504 (39027a05cf3d) waittime=4156 ownerId=28012051575 transactionname=InsertDB lasttranstarted=2012-04-16T22:30:00.287 XDES=0x116c1e7a30 lockMode=U schedulerid=23 kpid=1
    2012-04-16 22:30:04.470 spid16s          executionStack
    2012-04-16 22:30:04.470 spid16s           frame procname=db1.dbo.sp_SomeSP line=402 stmtstart=31148 stmtend=32184 sqlhandle=0x03000800b805c108eba1b90035a000000100000000000000
    2012-04-16 22:30:04.470 spid16s      INSERT INTO Table1    
    2012-04-16 22:30:04.470 spid16s      VALUES(x1,x2,x3,x4,x5)   
    2012-04-16 22:30:04.470 spid16s          inputbuf
    2012-04-16 22:30:04.470 spid16s      Proc [Database Id = 8 Object Id = 146867640]   
    2012-04-16 22:30:04.470 spid16s         process id=process56e9198 taskpriority=0 logused=0 waitresource=KEY: 8:347217455677440 (88002022af91) waittime=4156 ownerId=28012051611 transactionname=InsertDB lasttranstarted=2012-04-16T22:30:00.290 XDES=0x7cdf61a20 lockMode=U schedulerid=27 kpid=1212
    2012-04-16 22:30:04.470 spid16s          executionStack
    2012-04-16 22:30:04.470 spid16s           frame procname=db1.dbo.sp_someSP line=88 stmtstart=7114 stmtend=7558 sqlhandle=0x03000800b805c108eba1b90035a000000100000000000000
    2012-04-16 22:30:04.470 spid16s      SELECT x,x,x,
    2012-04-16 22:30:04.470 spid16s      FROM Table1 WITH (UPDLOCK, ROWLOCK)
    2012-04-16 22:30:04.470 spid16s      WHERE x1= '' and x2 = ''    
    2012-04-16 22:30:04.470 spid16s          inputbuf
    2012-04-16 22:30:04.470 spid16s      Proc [Database Id = 8 Object Id = 146867640]   
    2012-04-16 22:30:04.470 spid16s        resource-list
    2012-04-16 22:30:04.470 spid16s         keylock hobtid=72057594045333504 dbid=8 objectname=db1.dbo.Table1 indexname=IX_Ix1 id=lock92f0280 mode=U associatedObjectId=72057594045333504
    2012-04-16 22:30:04.470 spid16s          owner-list
    2012-04-16 22:30:04.470 spid16s           owner id=process56e9198 mode=U
    2012-04-16 22:30:04.470 spid16s          waiter-list
    2012-04-16 22:30:04.470 spid16s           waiter id=process3e44718 mode=U requestType=wait
    2012-04-16 22:30:04.470 spid16s         keylock hobtid=347217455677440 dbid=8 objectname=db1.dbo.Table1 indexname=IX_Ix2 id=lock1e7b74900 mode=U associatedObjectId=347217455677440
    2012-04-16 22:30:04.470 spid16s          owner-list
    2012-04-16 22:30:04.470 spid16s           owner id=process3e44718 mode=U
    2012-04-16 22:30:04.470 spid16s          waiter-list
    2012-04-16 22:30:04.470 spid16s           waiter id=process56e9198 mode=U requestType=wait

    Kindly mark the reply as answer if they help

    Tuesday, April 17, 2012 9:31 AM
  • http://blogs.msdn.com/bartd/archive/2006/09/09/747119.aspx
    http://blogs.msdn.com/bartd/archive/2006/09/25/770928.aspx

    Best Regards, Uri Dimant SQL Server MVP http://dimantdatabasesolutions.blogspot.com/ http://sqlblog.com/blogs/uri_dimant/

    Tuesday, April 17, 2012 9:33 AM
    Answerer
  • A quick look at this tells this

    spid 868 - 

    INSERT INTO Table1     
    VALUES(x1,x2,x3,x4,x5)    
    Proc [Database Id = 8 Object Id = 146867640]  - dbo.sp_somesp

    spid 153  - 

    SELECT x,x,x,
    FROM Table1 WITH (UPDLOCK, ROWLOCK)
    WHERE x1= '' and x2 = ''     
    Proc [Database Id = 8 Object Id = 146867640]   -- dbo.sp_somesp

    Spid 153 is the victim 

    the database db1 has a table table1 which has two indexes IX_Ix1 and IX_Ix2 and both the queries need update lock on both the indexes which is causing the problem. It is the same sp run multiple times are at different points of execution and during that time requires almost the same locks.

    It could be a problem of running multiple execution it at same times which is causing the issue,classic deadlock example? I think you should be able to take it forward from now.

    HTH


    Regards, Ashwin Menon My Blog - http:\\sqllearnings.com


    • Edited by Ashwin Menon Tuesday, April 17, 2012 10:38 AM
    • Marked as answer by Sunil Gure Tuesday, April 17, 2012 11:08 AM
    Tuesday, April 17, 2012 10:37 AM
  • just curious, why are you doing an UPDLOCK and ROWLOCK are you doing an update later with the same rows? 

    I see that both of the select and insert are a part of the same transaction insertdb, so it seems like you will be able to resolve this deadlock by tuning the sp a bit.


    Regards, Ashwin Menon My Blog - http:\\sqllearnings.com

    Tuesday, April 17, 2012 10:43 AM
  • Thanks Ashwin. Yup, It is UPDLOCK and ROWLOCK which are causing this issue. Using Lock hints ROWLOCK, UPDLOCK,  that acquire row-level locks may place locks on index keys rather than the actual data rows in some cases where we have non clustered covering index (Kind of X lock). I will remove this and trying tunning the SP.


    Kindly mark the reply as answer if they help

    • Marked as answer by Sunil Gure Tuesday, April 17, 2012 11:08 AM
    Tuesday, April 17, 2012 11:07 AM