Identifying Blocking via Extended Events

There are a number of ways that you can identify blocking that is occurring in your SQL instance. You can run the undocumented sp_who2 stored procedure but that will only give you the session that is being blocked. You could download the excellent sp_whoisactive, written by Adam Machanic, which will give you the session_id and the SQL script that is causing the blocking. However both of these methods will only show you blocking sessions when you run it (obviously). If you want to capture historical blocking information then another method is needed. If you suspect that blocking is occurring in your system, the best way to capture the information is to use Extended Events.

In order to do this, first enable the blocked process report:-

EXEC sp_configure 'Show Advanced Options', 1
RECONFIGURE

EXEC sp_configure 'blocked process threshold (s)', 1
RECONFIGURE

EXEC sp_configure 'Show Advanced Options', 0
RECONFIGURE

N.B. – I’ve set the threshold limit here to one second. Depending on your environment you may wish to change it.

Then create an extended event to capture the information from the report:-

CREATE EVENT SESSION [BlockedProcesses] ON SERVER 
    ADD EVENT sqlserver.blocked_process_report
    ADD TARGET package0.event_file(SET filename=N'C:\SQLServer\XEvents\BlockedProcesses\BlockedProcesses.xel',max_file_size=(128))
WITH (STARTUP_STATE=OFF)
GO

N.B. – Don’t forget to change the file path.

Then start the session:-

ALTER EVENT SESSION [BlockedProcesses] ON SERVER
    STATE = START;

Now that the session is running you can query it:-

SELECT
 [XML DATA] AS [Raw XML],
 [XML Data].value('(/event[@name=''blocked_process_report'']/@timestamp)[1]','DATETIME') AS [TimeStamp],
 [XML Data].value('(/event/data[@name=''database_name'']/value)[1]','SYSNAME') AS [Database Name],
 [XML Data].value('(/event/action[@name=''username'']/value)[1]','SYSNAME') AS [Username],
 [XML Data].value('(/event/data[@name=''transaction_id'']/value)[1]','BIGINT') AS [Transaction ID],
 [XML Data].value('(/event/data[@name=''lock_mode'']/text)[1]','SYSNAME') AS [Lock Mode],
 [XML Data].value('(/event/data[@name=''duration'']/value)[1]','BIGINT')/1024 AS [Duration (ms)],
 [XML Data].value('(/event/data[@name=''blocked_process'']/value/blocked-process-report/blocked-process/process/inputbuf)[1]','SYSNAME') AS [Blocked Query],
 [XML Data].value('(/event/data[@name=''blocked_process'']/value/blocked-process-report/blocked-process/process/@waitresource)[1]','SYSNAME') AS [Wait Resource], 
 [XML Data].value('(/event/data[@name=''blocked_process'']/value/blocked-process-report/blocking-process/process/inputbuf)[1]','SYSNAME') AS [Blocking Query]
FROM
    (SELECT OBJECT_NAME 			  AS [Event], 
		  CONVERT(XML, event_data) AS [XML Data]
	FROM 
	   sys.fn_xe_file_target_read_file('C:\SQLServer\XEvents\BlockedProcesses\BlockedProcesses*.xel',NULL,NULL,NULL)) AS v
ORDER BY [XML Data].value('(/event[@name=''blocked_process_report'']/@timestamp)[1]','DATETIME') DESC

EDIT:- It’s been pointed out in the comments by Jason that the value for username will return as NULL because no action was defined for this value in the CREATE EVENT script. Adding the following piece of code will allow the username to be returned:-

ADD EVENT sqlserver.blocked_process_report(
Action (sqlserver.Username))

This piece of code will output the time of the block, the blocked query, the blocking query, the duration of the block and the resource that the blocked query is waiting on. I’ll run through a quick example now to show what information is retrieved when a block is recorded. So first I’ll create a demo database with one table (I have already run the setup scripts above):-

USE [master];
GO
 
CREATE DATABASE [BlockingExample];
GO
 
USE [BlockingExample];
GO
 
CREATE TABLE dbo.[BlockedTable]
(RecordID INT IDENTITY(1,1) PRIMARY KEY,
 ColA SYSNAME);
 
INSERT INTO dbo.BlockedTable
(ColA)
VALUES
('Blocking TEST');
GO

Then I’ll open two sessions, the first will be an update in a transaction that I’ll leave open (my blocker):-

USE [BlockingExample];
GO
 
BEGIN TRAN
 
UPDATE dbo.[BlockedTable]
SET ColA = 'BlockingTEST1';

The second will be a simple SELECT against the table (my blocked query):-

USE [BlockingExample];
GO

SELECT * FROM dbo.BlockedTable;

I’ll run this for a while, cancel it and commit the first query. Then I queried the extended event, here’s the results:- BlockedProcessScreenShot As you can see, The SELECT is showing up as the blocked query and the update as the blocker. But we’ve also got the resource the SELECT is waiting on:- KEY: 14:72057594039042048 (8194443284a0) Using this information we can identify the exact row in the table. The 14 is the database_id:-

SELECT name from sys.databases WHERE database_id = 14

This gives the name of the test database “BlockingExample”. Next 72057594039042048 is the hobt_id of the table, we can get the table name by running:-

SELECT o.name
FROM sys.objects o
INNER JOIN sys.partitions p ON o.object_id = p.object_id
WHERE p.hobt_id = 72057594039042048

This outputs the name of the test table “Blocked Table”. Finally we can use (8194443284a0) to identify the exact row in the table by running:-

SELECT *
FROM dbo.BlockedTable
WHERE %%LOCKRES%% = '(8194443284a0)'

This will output the test record that was inserted and then locked by the UPDATE statement. A very contrived example, I know, but it does show how verbose Extended Events are when capturing blocking. Not only can we identity the blocker and blockee but the exact record that the blockee was waiting on.

4 thoughts on “Identifying Blocking via Extended Events

  1. Very neat and very useful. Only comment would be that in SQL 2014 [XML Data].value(‘(/event/action[@name=”username”]/value)[1]’,’SYSNAME’) AS [Username] returns nothing. The /event/action element is missing in the raw XML. No big deal as the loginname, hostname, hostpid etc are in /event/data[@name=”blocked_process”]/value/blocked-process-report/blocked-process/process and /event/data[@name=”blocked_process”]/value/blocked-process-report/blocking-process/process

  2. If you look at the XE Session definition in this article, you will see that no actions are defined. That is most likely why you are not seeing the Username Action populate in the session file.

    Making the action adjustment works fine on 2014. Here is a snippet.
    CREATE EVENT SESSION [BlockedProcesses] ON SERVER
    ADD EVENT sqlserver.blocked_process_report(
    Action (sqlserver.Username))
    ADD TARGET package0.event_file

    Good stuff.

  3. Showing how to find the actual row is really cool. One word of caution, as advised by Microsoft, is to not set the value to less than 5 unless there is a specific reason to do so – https://technet.microsoft.com/en-us/library/bb402879.aspx. This would be a good warning to place in the article so that someone doesn’t come along and use this in a large production environment, which could run very heavily.

Leave a Reply

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