Locking is a familiar concept to anyone working with SQL Server. However, when a process holds locks for a long period of time, other processes can begin to be blocked by the initial process. When a process is blocked it waits on the blocking process to finish before it continues execution. This can result in long running queries and timeouts in the application caused by the blocking. SQL Server 2005 introduced a new feature called the Blocked Process Report that provides detailed output to whenever a blocked process exceeds a set system threshold.

To begin with, it is necessary to configure the blocked process threshold on the SQL Server so that it generates the blocked process report in a trace output:

sp_configure 'show advanced options',1 ; 
GO 
RECONFIGURE; 
GO 
sp_configure 'blocked process threshold',5 ; 
GO 
RECONFIGURE; 
GO

I chose the value 5 because if something is blocked for more than 5 seconds then that is a significant delay in performance and according to the books online, a value of 1-4 can cause the deadlock monitor to run consistently which can also impact performance. Once this has been done, a single event server side trace can be created to run on the server that will log the blocked process reports that get generated. The below script will create this trace:

/****************************************************/
/* Created by: SQL Server Profiler 2005 */
/* Date: 09/24/2008 11:12:03 AM */
/****************************************************/

-- Create a Queue
declare @rc int
declare @TraceID int
declare @maxfilesize bigint
set @maxfilesize = 50 
exec @rc = sp_trace_create @TraceID output, 2, N'c:\BlockedProcessTrace', @maxfilesize, NULL 
if (@rc != 0) goto error
-- Client side File and Table cannot be scripted
-- Set the events
declare @on bit
set @on = 1
exec sp_trace_setevent @TraceID, 137, 15, @on
exec sp_trace_setevent @TraceID, 137, 1, @on
exec sp_trace_setevent @TraceID, 137, 13, @on

-- Set the Filters
declare @intfilter int
declare @bigintfilter bigint
-- Set the trace status to start
exec sp_trace_setstatus @TraceID, 1
-- display trace id for future references
select TraceID=@TraceID
goto finish
error: 
select ErrorCode=@rc
finish: 
go

Make note of the TraceID that is output from running the above script. Also not every SQL Server Service account can write to the root of the C drive. None of my production servers can, but I am building this demo on my laptop where it can. Make sure that a correct path is specified for the trace file. Most servers will output traceid = 2 for this since there is the default trace running in SQL Server 2005. Keep this number because it is needed to stop and delete the trace later on.

Now that the trace is active, to test it and demonstrate the blocked process report output open a new SSMS query window and run the following script:

use tempdb
create table temp1
(rowid int)
insert into temp1 values (1)

Then open another new query window and run the following script to create a stored procedure that will cause blocking to occur for testing:

create procedure blockingprocedure
as
select * from temp1
begin tran
update temp1
set rowid = rowid + 1
waitfor delay '00:00:20'
rollback

This will leave an open blocking transaction against the temp1 table in tempdb. Now two more query windows and paste the following script into each of them:

exec blockingprocedure

Then start the procedure in one window, and switch to the other window and start the procedure there and wait for the second procedure to complete its execution. When it finishes, close both of the query windows. Then open a new query windows and run the following query to clean up the example:

drop table temp1
drop procedure blockingprocedure
--stop the trace
exec sp_trace_setstatus 2, 0
--delete the trace but leaves the file on the drive
exec sp_trace_setstatus 2, 2

Now to look at the output in the trace file run the following query:

select cast(TextData as xml), SPID, EndTime, Duration/1000/1000
from fn_trace_gettable(N'c:\BlockedProcessTrace.trc', default)
where eventclass = 137

By casting the TextData to an xml datatype you can click on it and have it open up formatted in SSMS. The output will be similar to the following:

<blocked-process-report monitorLoop="174307">
<blocked-process>
<process id="process89b108" taskpriority="0" logused="0" waitresource="RID: 2:1:480:0" waittime="8500" ownerId="129710198" transactionname="SELECT" lasttranstarted="2008-09-25T11:09:15" XDES="0x174c2f48" lockMode="S" schedulerid="1" kpid="5296" status="suspended" spid="154" sbid="0" ecid="0" priority="0" transcount="0" lastbatchstarted="2008-09-25T11:09:15" lastbatchcompleted="2008-09-24T17:15:55.560" clientapp="Microsoft SQL Server Management Studio - Query" hostname="PC-JKEHAYIAS" hostpid="4944" loginname="OUTBACKNT\JKehayias" isolationlevel="read committed (2)" xactid="129710198" currentdb="2" lockTimeout="4294967295" clientoption1="671090784" clientoption2="390200">
<executionStack>
<frame line="4" stmtstart="84" stmtend="128" sqlhandle="0x03000200a734c05067acb600229b00000100000000000000" />
<frame line="1" sqlhandle="0x01000200c6cc1328a8dff614000000000000000000000000" />
</executionStack>
<inputbuf>
exec blockingprocedure </inputbuf>
</process>
</blocked-process>
<blocking-process>
<process status="suspended" waittime="10593" spid="145" sbid="0" ecid="0" priority="0" transcount="1" lastbatchstarted="2008-09-25T11:09:12.907" lastbatchcompleted="2008-09-24T16:44:17.137" lastattention="2008-09-24T16:44:17.137" clientapp="Microsoft SQL Server Management Studio - Query" hostname="PC-JKEHAYIAS" hostpid="4944" loginname="OUTBACKNT\JKehayias" isolationlevel="read committed (2)" xactid="129709893" currentdb="2" lockTimeout="4294967295" clientoption1="671090784" clientoption2="390200">
<executionStack>
<frame line="11" stmtstart="236" stmtend="290" sqlhandle="0x03000200a734c05067acb600229b00000100000000000000" />
<frame line="1" sqlhandle="0x01000200c6cc1328a8dff614000000000000000000000000" />
</executionStack>
<inputbuf>
exec blockingprocedure </inputbuf>
</process>
</blocking-process>
</blocked-process-report>

From this, you can see what is blocked as well as what is blocking. However, since both of these show a stored procedure execution, we have to dig further into this. We can do this using the sqlhandle from the first frame node in the execution stack. Copy the sqlhandle value and paste it into the following query:

declare @handle varbinary(64)
set @handle = 0x03000200a734c05067acb600229b00000100000000000000
select text from sys.dm_exec_sql_text(@handle)

Hit Ctrl+T to set the output to text mode and run the query. Then go back to the XML output and look for the line attribute in the frame node that contained the sqlhandle. Then count down the lines of the procedure definition to the line that was blocking and blocked.

For adhoc execution, the sql statement is included in the inputbuf node and the last step is not needed. Begin looking at the blocking process to determine why it is blocking. If you can solve that problem then the issue goes away.

Hope it helps.