Take the 2-minute tour ×
Database Administrators Stack Exchange is a question and answer site for database professionals who wish to improve their database skills and learn from others in the community. It's 100% free, no registration required.

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?
share|improve this question
    
In the Blocked Process report I have identified the lead blocker - the one at the head of the blocking chain. It is a stored proc called TempGetStateItemExclusive3, which typically runs in a fraction of a second, because it is very simple and the tables involved are very small (1500 rows). I can tell you that the lock is a key lock on the primary key on the table [ASPStateTempSessions] I set the threshold at 15 seconds, so blocking must have been occurring for at least this long, so I'm not clear why the wait time for the lead blocker would be so low. –  reticentKoala Jun 28 '13 at 10:03
    
The wait time for the lead blocker is 20631 ms (20.6 seconds). Do you have very high concurrency on this table? Jeremiah Peschka did a webcast on storing session state on SQL Server that might be relevant to your situation. It might also be worth capturing further information about what is happening during the timeouts, as the blocking might just be an effect of some other issue like stuck I/O or 100% CPU usage, etc. –  James Jun 28 '13 at 10:40

1 Answer 1

up vote 2 down vote accepted
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.

share|improve this answer
    
Understood. As I say, tables, indexes and the procedure are all very small - there's not much to optimize or index better. It's true to say we have very high concurrency on the resources in question. Further investigation shows that synchronous mirroring is taking place and that DBMIRROR_EVENTS_QUEUE is highest wait time on the server (aggregate info from OS_wait_stats). I'd love to know why the lead blocker is suspended - I don't think it's necessarily CPU, but I don't think I can tie this to a specific wait type? –  reticentKoala Jun 28 '13 at 11:16
    
You need to look at sys.dm_exec_requests_last_wait_type for the SPID that is the blocker at the moment the blocked report event is produced. If you're daredevil, you can use event notifications for this event and process the event in an activated procedure, which would give you a chance to look for the blocker execution pattern as is blocking. Not trivial, but doable. –  Remus Rusanu Jun 28 '13 at 12:19
    
Other approaches would be to leverage some tools like sp_whoisactive. You are correct in looking at wait times for troubleshooting this, I hope you did read Waits and Queues, but now the discussion diverges from your actual posted question (how to interpret the process blocked event info). –  Remus Rusanu Jun 28 '13 at 12:20

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

Not the answer you're looking for? Browse other questions tagged or ask your own question.