Blocked Process Report & Event Class – Underappreciated Features of SQL Server


This is in continuation to my series on “Underappreciated features of SQL Server”, which is based on the editorial with the same name by Andy Warren on SQLServerCentral.com. The editorial is available here.

Locking & Blocking are not new to anyone who has worked on a production SQL Server based system with as little as 200 concurrent users. Locking is essential to maintain a database’s consistency. However, whenever a process holds a lock for more than a required amount of time, it starts interfering with the normal operation of other processes on the server. This manifests into long-running queries and application timeouts.

The conventional way of identifying blocking is by the use of TRACE flags 1204 and 1222. Microsoft SQL Server 2005 makes this a little bit easier by introducing a new feature called the Blocked Process Report which can help administrators monitor their servers for blocking whenever the blocking exceeds a given threshold.

Blocking Processes

Explaining blocking processes and deadlocks is beyond the scope of this article. If you need help in clearing the concept, please refer the MSDN resource here. Also, please do not proceed ahead without clarity on these concepts – it will do more harm than good.

A deadlock occurs when two or more tasks permanently block each other by each task having a lock on a resource which the other tasks are trying to lock. A blocking situation is when the blocking is not permanent, but serve enough to impact the performance of the other tasks.

Using the AdventureWorks database, running the following batch in two separate query windows simultaneously will result in a blocking situation. You will notice that the “second” query waits for the first and then executes only after the “first” finishes. Give it a try.

BEGIN TRANSACTION BlockedProcessReport
    PRINT 'Entering Transaction at:' + CONVERT(VARCHAR(20),GETDATE(),114);
    
    UPDATE HumanResources.Employee SET CurrentFlag = 0
    --Introduce a 20 second delay
    WAITFOR DELAY '00:00:20'

    PRINT 'Leaving Transaction at: ' + CONVERT(VARCHAR(20),GETDATE(),114);
ROLLBACK TRANSACTION BlockedProcessReport

Here are the results from my execution:

--Window 01
Entering Transaction at:08:54:45:793

(290 row(s) affected)
Leaving Transaction at: 08:55:05:803

--Window 02
Entering Transaction at:08:54:47:517

(290 row(s) affected)
Leaving Transaction at: 08:55:25:903

Clearly, the process running in window #2 was blocked by the process running in window #1. The most common symptom that such an issue is occurring would be users calling up the support staff screaming about a poorly performing system. Let’s see how we can now identify blocked queries using the features new to Microsoft SQL Server 2005.

Preparing the environment

Before we go any further, let’s ensure that the blocking process thresholds are low enough for us to easily trigger the recognition of transactions as blocking transactions.

CAUTION!!! Please do not adjust these settings on your production and Quality Assurance environments without recommendation from a senior database administrator, or from Microsoft.

--Set the visibility of advanced options to ON
sp_configure 'show advanced options',1;
GO
--Use RECONFIGURE hint to prevent a restart of the SQL Server for changes to take effect
RECONFIGURE;
GO
--Fetch the value of the Blocked Process threshold
--By default, this value is 0, i.e. no Blocked Process reports are generated
sp_configure 'blocked process threshold';
GO
--Set the blocked process threshold value to 5 seconds
sp_configure 'blocked process threshold',5;
GO
--Use RECONFIGURE hint to prevent a restart of the SQL Server for changes to take effect
RECONFIGURE;
GO

Using the default health reports shipped with SQL Server Management Studio

For those administrators who do not want to go get their hands greasy just yet, Microsoft SQL Server comes with a couple of useful reports out-of-the-box. One such report is the Blocked Process report. You can access this from the Object Explorer by right-clicking on the instance name –> Reports –> Standard Reports –> Activity – All Blocking Transactions

image

When you run the report, under normal circumstances, it should not show any blocked processes. Now, re-run the batch of queries designed to simulate blocking in two separate query windows. While these are running, refresh the Blocked process report. This is how it will look like – simple, clear and concise:

image

This query can now be given to the development teams with proof that it is indeed, causing performance issues and needs attention.

Using the SQL Server Profiler – Blocked Process Event Class

Starting Microsoft SQL Server 2005, the Profiler introduces a new Event Class – Blocked Process Report. The Blocked Process Report event class indicates that a task has been blocked for more than a specified amount of time. This event class does not include system tasks or tasks that are waiting on non deadlock-detectable resources. Let’s see how we can use this to detect blocking & deadlocks.

We will begin by setting up a SQL Server Profiler trace on our test instance. Use a (blank) trace template for simplicity. In the “Events Selection” tab, browse out to the “Errors and Warnings” section and choose “Blocked Process Report” as demonstrated below:

image

Run the trace. While the trace is running, re-run the batch of queries designed to simulate blocking in two separate query windows. Monitoring the profiler trace shows us the following:

image

Blocked process threshold uses the deadlock monitor background thread to walk through the list of tasks waiting for a time greater than or multiples of the configured threshold. The event is generated once per reporting interval for each of the blocked tasks. Because our blocked process threshold is set for 5 seconds, a blocked process report has been generated by the blocked process at 5, 10 and 15 seconds of execution time respectively (At the 20 seconds mark, the first process had already proceeded ahead and ended the blockage, which is why it is not seen in the report).

Clicking on the individual blocked process report, we see an XML like the one below, which shows the blocked process as the one with SPID (54) and the blocking process to be one with SPID (53).

< blocked-process-report monitorLoop="20097">
 < blocked-process>
  < process id="process87be28" taskpriority="0" logused="0" waitresource="KEY: 5:72057594044153856 (6d003d0ff717)" waittime="17725" ownerId="120328" transactionname="BlockedProcessReport" lasttranstarted="2011-01-22T09:41:14.083" XDES="0x77247f0" lockMode="U" schedulerid="1" kpid="3128" status="suspended" spid="54" sbid="0" ecid="0" priority="0" transcount="2" lastbatchstarted="2011-01-22T09:41:14.083" lastbatchcompleted="2011-01-22T09:40:58.680" clientapp="Microsoft SQL Server Management Studio - Query" hostname="VPCW2K3" hostpid="2348" loginname="VPCW2K3Administrator" isolationlevel="read committed (2)" xactid="120328" currentdb="5" lockTimeout="4294967295" clientoption1="671090784" clientoption2="390200">
   < executionStack>
    < frame line="4" stmtstart="16" sqlhandle="0x0200000036147f28ca6059811837a9a13bd54860b50d7590"/>
    < frame line="4" stmtstart="252" stmtend="432" sqlhandle="0x02000000ee8af21f3464249db7b445232f6c427f69424d78"/>
   < /executionStack>
   < inputbuf>
BEGIN TRANSACTION BlockedProcessReport
    PRINT &apos;Entering Transaction at:&apos; + CONVERT(VARCHAR(20),GETDATE(),114);
    
    UPDATE HumanResources.Employee SET CurrentFlag = 0
    --Introduce a 20 second delay
    WAITFOR DELAY &apos;00:00:20&apos;

    PRINT &apos;Leaving Transaction at: &apos; + CONVERT(VARCHAR(20),GETDATE(),114);
ROLLBACK TRANSACTION BlockedProcessReport   < /inputbuf>
  < /process>
 < /blocked-process>
 < blocking-process>
  < process status="suspended" waittime="19027" spid="53" sbid="0" ecid="0" priority="0" transcount="1" lastbatchstarted="2011-01-22T09:41:12.773" lastbatchcompleted="2011-01-22T09:40:38.603" clientapp="Microsoft SQL Server Management Studio - Query" hostname="VPCW2K3" hostpid="2348" loginname="VPCW2K3Administrator" isolationlevel="read committed (2)" xactid="120327" currentdb="5" lockTimeout="4294967295" clientoption1="671090784" clientoption2="390200">
   < executionStack>
    < frame line="6" stmtstart="434" stmtend="496" sqlhandle="0x02000000ee8af21f3464249db7b445232f6c427f69424d78"/>
   < /executionStack>
   < inputbuf>
BEGIN TRANSACTION BlockedProcessReport
    PRINT &apos;Entering Transaction at:&apos; + CONVERT(VARCHAR(20),GETDATE(),114);
    
    UPDATE HumanResources.Employee SET CurrentFlag = 0
    --Introduce a 20 second delay
    WAITFOR DELAY &apos;00:00:20&apos;

    PRINT &apos;Leaving Transaction at: &apos; + CONVERT(VARCHAR(20),GETDATE(),114);
ROLLBACK TRANSACTION BlockedProcessReport   < /inputbuf>
  < /process>
 < /blocking-process>
< /blocked-process-report>

Cleanup the environment

As we come to a close on this demo, we will cleanup the environment by resetting the blocked process threshold value to 0.

CAUTION!!! Please do not adjust these settings on your production and Quality Assurance environments without recommendation from a senior database administrator, or from Microsoft.

--Reset the blocked process threshold value to 0
sp_configure 'blocked process threshold',0;
GO
--Use RECONFIGURE hint to prevent a restart of the SQL Server for changes to take effect
RECONFIGURE;
GO
--Fetch the value of the Blocked Process threshold
--By default, this value is 0, i.e. no Blocked Process reports are generated
sp_configure 'blocked process threshold';
GO
--Set the visibility of advanced options to OFF
sp_configure 'show advanced options',0;
GO
--Use RECONFIGURE hint to prevent a restart of the SQL Server for changes to take effect
RECONFIGURE;
GO

Blocked Process Monitoring Tool

Jonathan Kehayias has developed a Blocked Process Monitoring Tool, which is available on CodePlex at: http://sqlblockedprocessmon.codeplex.com/

In Conclusion

As systems scale up to the cloud in the coming days; preventing blocking and deadlocks are going to be of utmost importance. It is required that the entire application development process takes into account the fact that ultimately, if the underlying database is struggling to get the data you need in time because of poor application design, no amount of high-end technology and hardware is going to resolve the problem at hand. I hope that the above has given development teams and DBAs a new and easy way to identify and troubleshoot performance bottle-necks in their systems.

While you do this, please keep in mind the following extract from SQL Server Books On Line: “The blocked process report is done on a "best effort" basis. There is no guarantee of any "real-time" or even close to real-time reporting.“

Until we meet next time,

Be courteous. Drive responsibly.

Advertisements

2 thoughts on “Blocked Process Report & Event Class – Underappreciated Features of SQL Server

  1. Satya Jayanty

    THere is another feature in SQL 2008 onwards called Extended Events (Xevents) ..much better than Profiler in this case to obtain the information.

    Like

    Reply

Let me know what you think about this post by leaving your feedback here!

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s