deadlock graph

  • In all the examples that I've seen retrieving deadlock graphs with SQL Profiler, traces or extended events, the text of the sql statement that is running is inserted into the graph after the sqlhandle. We are not seeing this in any of our output. Looking at recent graphs, sometimes I can query the statement using the sqlhandle but other times there are no rows returned from sys.dm_exec_sql_text. Is there some setting or startup parameter that would resolve the handles to the query in the graph?

    Thanks in advance

  • Post an example graph.

    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

    We walk in the dark places no others will enter
    We stand on the bridge and no one may pass
  • <deadlock-list>

    <deadlock><victim-list>

    <victimProcess id="process1dd8ca988"/>

    </victim-list><process-list>

    <process id="process1dd8ca988" taskpriority="0" logused="1232" waitresource="PAGE: 74:1:1342349" waittime="3429" ownerId="47421880450" transactionname="implicit_transaction" lasttranstarted="2011-07-05T18:51:31.940" XDES="0xdee77200" lockMode="IX" schedulerid="24" kpid="6340" status="suspended" spid="96" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2011-07-05T18:51:33.230" lastbatchcompleted="2011-07-05T18:51:33.230" clientapp="TestSystem" hostname="TEST-02" hostpid="123" loginname="TestSystemUser" isolationlevel="read committed (2)" xactid="47421880450" currentdb="74" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128058">

    <executionStack>

    <frame procname="" line="1" stmtstart="1284" sqlhandle="0x030002002c97695ef9e52c01179f00000100000000000000">

    </frame>

    </executionStack>

    <inputbuf>

    Proc [Database Id = 2 Object Id = 1583978284] </inputbuf>

    </process>

    <process id="process1efb169288" taskpriority="0" logused="1340" waitresource="PAGE: 74:1:1342351" waittime="775" ownerId="47421831322" transactionname="implicit_transaction" lasttranstarted="2011-07-05T18:51:18.200" XDES="0x2a7add970" lockMode="S" schedulerid="15" kpid="8464" status="suspended" spid="115" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2011-07-05T18:51:18.210" lastbatchcompleted="2011-07-05T18:51:18.210" clientapp="TestWeb" hostname="TEST-04" hostpid="123" loginname="TestWebUser" isolationlevel="read committed (2)" xactid="47421831322" currentdb="74" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128058">

    <executionStack>

    <frame procname="" line="1" stmtstart="76" sqlhandle="0x03000200c1b20e2bc5b83601179f00000100000000000000">

    </frame>

    </executionStack>

    <inputbuf>

    Proc [Database Id = 2 Object Id = 722383553] </inputbuf>

    </process>

    </process-list>

    <resource-list>

    <pagelock fileid="1" pageid="1342349" dbid="74" objectname="" id="lock134eef5380" mode="SIX" associatedObjectId="72057594807779328">

    <owner-list>

    <owner id="process1efb169288" mode="SIX"/>

    </owner-list>

    <waiter-list>

    <waiter id="process1dd8ca988" mode="IX" requestType="convert"/>

    </waiter-list>

    </pagelock>

    <pagelock fileid="1" pageid="1342351" dbid="74" objectname="" id="lock1153b95200" mode="IX" associatedObjectId="72057594807779328">

    <owner-list>

    <owner id="process1dd8ca988" mode="IX"/>

    </owner-list>

    <waiter-list>

    <waiter id="process1efb169288" mode="S" requestType="wait"/>

    </waiter-list>

    </pagelock>

    </resource-list>

    </deadlock>

    </deadlock-list>

  • Are you using temporary procedures? The proc references DB 2 - TempDB. Real procedures shouldn't be in there.

    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

    We walk in the dark places no others will enter
    We stand on the bridge and no one may pass
  • As a matter of fact, just yesterday we discovered that our jdbc driver is creating temporary procedures for each statement. We are actually going to test changing the parameter that controls that. We're not sure why it was turned on. I can look for a graph where at least one side is not a temporary procedure.

  • I'm guessing that's it. It's clearly noting the proc as an object in TempDB. Probably some complex reason why they can't get the text from a temporary proc.

    If you've got one with permanent objects that shows the same behaviour I'd like to see it.

    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

    We walk in the dark places no others will enter
    We stand on the bridge and no one may pass
  • Looking further, I see that <inputbuf> is nearly always "Proc [Database Id = 2..." on that server, even if the stored procedure that's running is in a different database.

    On a different server, where the 'create temporary stored procedure' parameter is turned off, I see this in one graph:

    <process id="process42869d4c8" taskpriority="0" logused="10000" waittime="7672" schedulerid="2" kpid="364" status="suspended" spid="86" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2011-07-05T00:24:39.897" lastbatchcompleted="2011-07-05T00:24:39.887" clientapp="jTDS" hostname="TEST-APP" hostpid="123" loginname="TestSystemUser" isolationlevel="read committed (2)" xactid="438942039" currentdb="13" lockTimeout="4294967295" clientoption1="673185824" clientoption2="128058">

    <executionStack>

    <frame procname="" line="239" stmtstart="16530" stmtend="17452" sqlhandle="0x03000d004468463f0a65c1000a9f00000100000000000000">

    </frame>

    <frame procname="" line="1" stmtstart="50" sqlhandle="0x01000b00eed4473590b38e40030000000000000000000000">

    </frame>

    </executionStack>

    <inputbuf>

    (@P0 bigint,@P1 datetime)EXEC Test_db1.dbo.sp_CreateDynamic @P0, @P1 </inputbuf>

    </process>

    <inputbuf> has a value, but the current sql statement still isn't after the sqlhandle. I'm guessing this is because of the parameters in front of the statement. In this case, I can pull up that statement using the sqlhandle and offsets.

    So I hope that the change to that setting will at least give us the full transaction in inputbuf. Please let me know if you have any other suggestions.

    Thank you.

  • Can you post the entire of that 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

    We walk in the dark places no others will enter
    We stand on the bridge and no one may pass
  • <deadlock-list>

    <victim-list/>

    </victim-list><process-list>

    <process id="process2efdc8" taskpriority="0" logused="10000" waittime="4993" schedulerid="1" kpid="3668" status="suspended" spid="86" sbid="0" ecid="12" priority="0" trancount="0" lastbatchstarted="2011-07-05T00:24:39.897" lastbatchcompleted="2011-07-05T00:24:39.887" clientapp="jTDS" hostname="TEST-APP" hostpid="123" isolationlevel="read committed (2)" xactid="438942039" currentdb="13" lockTimeout="4294967295" clientoption1="673185824" clientoption2="128058">

    <executionStack>

    <frame procname="" line="239" stmtstart="16530" stmtend="17452" sqlhandle="0x03000d004468463f0a65c1000a9f00000100000000000000">

    </frame>

    <frame procname="" line="1" stmtstart="50" sqlhandle="0x01000b00eed4473590b38e40030000000000000000000000">

    </frame>

    </executionStack>

    <inputbuf>

    </inputbuf>

    </process>

    <process id="process8c9dc8" taskpriority="0" logused="10000" waittime="7658" schedulerid="2" kpid="3896" status="suspended" spid="86" sbid="0" ecid="3" priority="0" trancount="0" lastbatchstarted="2011-07-05T00:24:39.897" lastbatchcompleted="2011-07-05T00:24:39.887" clientapp="jTDS" hostname="TEST-APP" hostpid="123" isolationlevel="read committed (2)" xactid="438942039" currentdb="13" lockTimeout="4294967295" clientoption1="673185824" clientoption2="128058">

    <executionStack>

    <frame procname="" line="239" stmtstart="16530" stmtend="17452" sqlhandle="0x03000d004468463f0a65c1000a9f00000100000000000000">

    </frame>

    <frame procname="" line="1" stmtstart="50" sqlhandle="0x01000b00eed4473590b38e40030000000000000000000000">

    </frame>

    </executionStack>

    <inputbuf>

    </inputbuf>

    </process>

    <process id="process42869d4c8" taskpriority="0" logused="10000" waittime="7672" schedulerid="2" kpid="364" status="suspended" spid="86" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2011-07-05T00:24:39.897" lastbatchcompleted="2011-07-05T00:24:39.887" clientapp="jTDS" hostname="TEST-APP" hostpid="123" loginname="TestSystemUser" isolationlevel="read committed (2)" xactid="438942039" currentdb="13" lockTimeout="4294967295" clientoption1="673185824" clientoption2="128058">

    <executionStack>

    <frame procname="" line="239" stmtstart="16530" stmtend="17452" sqlhandle="0x03000d004468463f0a65c1000a9f00000100000000000000">

    </frame>

    <frame procname="" line="1" stmtstart="50" sqlhandle="0x01000b00eed4473590b38e40030000000000000000000000">

    </frame>

    </executionStack>

    <inputbuf>

    (@P0 bigint, @P1 datetime)EXEC Test_db1.dbo.sp_CreateDynamic @P0, @P1 </inputbuf>

    </process>

    <process id="process2ef288" taskpriority="0" logused="10000" waittime="7404" schedulerid="1" kpid="3724" status="suspended" spid="86" sbid="0" ecid="4" priority="0" trancount="0" lastbatchstarted="2011-07-05T00:24:39.897" lastbatchcompleted="2011-07-05T00:24:39.887" clientapp="jTDS" hostname="TEST-APP" hostpid="123" isolationlevel="read committed (2)" xactid="438942039" currentdb="13" lockTimeout="4294967295" clientoption1="673185824" clientoption2="128058">

    <executionStack>

    <frame procname="" line="239" stmtstart="16530" stmtend="17452" sqlhandle="0x03000d004468463f0a65c1000a9f00000100000000000000">

    </frame>

    <frame procname="" line="1" stmtstart="50" sqlhandle="0x01000b00eed4473590b38e40030000000000000000000000">

    </frame>

    </executionStack>

    <inputbuf>

    </inputbuf>

    </process>

    </process-list>

    <resource-list>

    <exchangeEvent id="Pipeb3502c70" WaitType="e_waitPipeNewRow" nodeId="12">

    <owner-list>

    <owner id="process8c9dc8"/>

    </owner-list>

    <waiter-list>

    <waiter id="process2efdc8"/>

    </waiter-list>

    </exchangeEvent>

    <exchangeEvent id="Pipebabbc280" WaitType="e_waitPipeNewRow" nodeId="8">

    <owner-list>

    <owner id="process42869d4c8"/>

    </owner-list>

    <waiter-list>

    <waiter id="process8c9dc8"/>

    </waiter-list>

    </exchangeEvent>

    <exchangeEvent id="Pipebabbcf70" WaitType="e_waitPipeGetRow" nodeId="8">

    <owner-list>

    <owner id="process2ef288"/>

    </owner-list>

    <waiter-list>

    <waiter id="process42869d4c8"/>

    </waiter-list>

    </exchangeEvent>

    <exchangeEvent id="Pipec0545a30" WaitType="e_waitPipeGetRow" nodeId="12">

    <owner-list>

    <owner id="process2efdc8"/>

    </owner-list>

    <waiter-list>

    <waiter id="process2ef288"/>

    </waiter-list>

    </exchangeEvent>

    </resource-list>

    </deadlock>

    </deadlock-list>

  • That's a intra-query parallelism deadlock. If you look, all the processes have the same SPID. That's actually a bug, they shouldn't occur.

    The lack of query text is most likely a side effect of that. It's not a true lock-related deadlock.

    To fix that, add the MAXDOP hint to that query, MAXDOP 1, and maybe consider logging a case with CSS, those are bugs that should be submitted. Can't guarantee that they will be able to get you a fix though.

    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

    We walk in the dark places no others will enter
    We stand on the bridge and no one may pass
  • Which jdbc driver are you using? And can you post the code for the temporary stored proc?

    (@P0 bigint, @P1 datetime)EXEC Test_db1.dbo.sp_CreateDynamic @P0, @P1

    </curious>

    There are no special teachers of virtue, because virtue is taught by the whole community.
    --Plato

  • This one isn't a temp stored procedure, it's a 3000 line stored procedure in one of our databases.

    We are using jtDS 1.2.2, the parameter in question is prepareSQL. One server is set to create temporary stored procedures.

  • 3000 lines? Eeep.

    What's the following fragment of that proc?

    line="239" stmtstart="16530" stmtend="17452"

    (stmtstart and stmtend are character offsets. So looking for about 1000 characters starting 16530 characters into the proc)

    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

    We walk in the dark places no others will enter
    We stand on the bridge and no one may pass
  • opc.three (7/6/2011)


    Which jdbc driver are you using? And can you post the code for the temporary stored proc?

    (@P0 bigint, @P1 datetime)EXEC Test_db1.dbo.sp_CreateDynamic @P0, @P1

    </curious>

    You can attach as a file.

Viewing 14 posts - 1 through 14 (of 14 total)

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