Wednesday, September 24, 2008

Monitoring for Blocked Processes On SQL 2005 - Extended Version

To help better clarify how to do an end to end monitoring of blocked processes on SQL Server 2005 I am going to expand upon my previous blog posting.  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 it is the lowest value you can set.  Once this has been done, a single event 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:



begin tran
update
temp1
set rowid = rowid + 1


This will leave an open blocking transaction against the temp1 table in tempdb.  Now open another (my this is a lot of windows isn't it) query window and run the following script:



select * from temp1


Let it sit for about 10-20 seconds, and then kill the execution and close the query window.  Then rollback the transaction in the update query window and close that window as well (see I am cleaning up as we go).  The run the following query to clean up the rest of the example:



drop table temp1
--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="160986">
<
blocked-process>
<
process id="process929d38" taskpriority="0" logused="0" waitresource="RID: 2:1:480:0" waittime="17953" ownerId="123106201" transactionname="SELECT" lasttranstarted="2008-09-24T16:39:38.620" XDES="0x9bc3920" lockMode="S" schedulerid="2" kpid="2064" status="suspended" spid="145" sbid="0" ecid="0" priority="0" transcount="0" lastbatchstarted="2008-09-24T16:39:38.620" lastbatchcompleted="2008-09-24T16:39:10.667" clientapp="Microsoft SQL Server Management Studio - Query" hostname="SQLDEMO" hostpid="4944" loginname="SQLDEMO\DemoUser" isolationlevel="read committed (2)" xactid="123106201" currentdb="2" lockTimeout="4294967295" clientoption1="671090784" clientoption2="390200">
<
executionStack>
<
frame line="1" sqlhandle="0x0200000088baad31046d031f04c8e7293882ce42521d893f" />
</
executionStack>
<
inputbuf>
select * from temp1 </inputbuf>
</
process>
</
blocked-process>
<
blocking-process>
<
process status="sleeping" spid="78" sbid="0" ecid="0" priority="0" transcount="1" lastbatchstarted="2008-09-24T16:39:37.060" lastbatchcompleted="2008-09-24T16:39:47.057" clientapp="Microsoft SQL Server Management Studio - Query" hostname="SQLDEMO" hostpid="4944" loginname="SQLDEMO\DemoUser" isolationlevel="read committed (2)" xactid="123105638" currentdb="2" lockTimeout="4294967295" clientoption1="671090784" clientoption2="390200">
<
executionStack />
<
inputbuf>
begin tran
update temp1
set rowid = rowid + 1

waitfor delay '00:00:10' </inputbuf>
</
process>
</
blocking-process>
</
blocked-process-report>


From this, you can see what is blocked as well as what is blocking.  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.

No comments:

Post a Comment