Sql-server – Diagnosing Blocking issues using Blocked Process report

lockingprofilersessionsql server

I have an application that is going down as a result of timeouts. During these times we see a massive spike in response times from the database that holds ASP session state.

In an effort to to diagnose the issue I have used SP_CONFIGURE'blocked process threshold',15 and ran a trace to catch any events that are fired. During the next incident the trace capture some blocking events in the Session State database.

I've identified the lead blocker and can see that it's suspended and waiting.

<blocked-process-report>
    <blocked-process>
        <process id="process53fb4c8" 
                 taskpriority="0" logused="0" 
                 waitresource="KEY: 10:72057594039238656 (594b17b7493c)" waittime="20631"
                 ownerId="9710782702" transactionname="UPDATE" 
                 lasttranstarted="2013-06-27T17:29:38.130" XDES="0xc429df950" lockMode="U" 
                 schedulerid="14" kpid="6912" status="suspended" spid="359" sbid="0" ecid="0" 
                 priority="0" trancount="2" lastbatchstarted="2013-06-27T17:29:38.130"
                 lastbatchcompleted="2013-06-27T17:29:38.107" 
                 clientapp=".Net SqlClient Data Provider" hostname="WEB03" hostpid="7520" 
                 loginname="State" isolationlevel="read committed (2)" xactid="9710782702" 
                 currentdb="10" lockTimeout="4294967295" 
                 clientoption1="536870944" clientoption2="128056">
            <executionStack>
                <frame line="18" stmtstart="1114" stmtend="4494" 
                       sqlhandle="0x03000a00210f020741a1be0058a000000100000000000000"/>
            </executionStack>
            <inputbuf>
                Proc [Database Id = 10 Object Id = 117575457]
            </inputbuf>
        </process>
    </blocked-process>
    <blocking-process>
        <process status="suspended" waittime="1046" spid="217" sbid="0" ecid="0" 
                 priority="0" trancount="1" lastbatchstarted="2013-06-27T17:29:29.113" 
                 lastbatchcompleted="2013-06-27T17:29:29.010" 
                 clientapp=".Net SqlClient Data Provider" hostname="WEB02" hostpid="6236" 
                 loginname="CState" isolationlevel="read committed (2)" xactid="9710776428" 
                 currentdb="10" lockTimeout="4294967295" clientoption1="536870944" 
                 clientoption2="128056">
            <executionStack>
                <frame line="18" stmtstart="1114" stmtend="4494" 
                       sqlhandle="0x03000a00210f020741a1be0058a000000100000000000000"/>
            </executionStack>
            <inputbuf>
                Proc [Database Id = 10 Object Id = 117575457]
            </inputbuf>
        </process>
    </blocking-process>
</blocked-process-report>

My questions are

  1. What the unit of time is for waittime="1046"?
  2. What resource is the wait on?
  3. Where to go from here?

Best Answer

waitresource="KEY: 10:72057594039238656 (594b17b7493c)" waittime="20631"
             ownerId="9710782702" transactionname="UPDATE"

The blocked process is waiting on a KEY (therefore on a row), for 20631 ms (~20s).

The blocking transaction is still executing a statement, likely the UPDATE that causes the blocking. It is not blocked, if it would be blocked then it wouldn't be the tip of the wait chain. Is executing, right now is suspended (not blocked!) meaning it just yielded CPU.

Looks like you have a long running UPDATE statement, most likely it has a missing index and triggers a table scan which blocks all readers. Use sys.dm_exec_sql_text on the handle 0x03000a00210f020741a1be0058a000000100000000000000 to retrieve the exact statement being executed.

BTW your blocked process is exactly the same UPDATE (same handle, same proc, same offsets) which is not surprising at all. Looks like your stored proc with object id 117575457 contains an UPDATE that is not optimized.

Related Question