Capture Blocking Information with Extended Events and the Blocked Process Report

I am a big fan of Adam Machanic’s WhoIsActive script, and when customers have issues with performance, it’s one of the first tools I recommend because it’s so simple to use and provides great information.  Very often it helps with quickly determining an issue, but sometimes there’s a need to capture more information, particularly when locking and blocking is part of the issue.  Adam’s script has an option to include blocking information, for example including the [blocking_session_id] column in the output and using @find_block_leaders = 1as an parameter.  But sometimes you need more information, like the blocked process report.  I’ve found one of the easiest ways to get that in SQL Server 2012 and higher is Extended Events.  If you’re running SQL Server 2005 and higher, you can use Event Notifications to capture the blocked process report.  This option is nice because you are notified when the problem occurs.  For those of you using SQL Server 2008R2 and below, you also have the option of capturing the blocked process report event through a server-side Trace.  But if you’re on SQL Server 2012 and higher, you can use Extended Events and the blocked process report.  Note: the blocked_process_report event does not exist in SQL Server 2008 or SQL Server 2008R2, which is why Trace is the method there.  The drawback to Extended Events is that you don’t get a notification that blocking occurred, but for those who are not as comfortable with Event Notifications – for whatever reason – Extended Events is a very simple alternative.

The Setup

In order to capture a blocked process report, you must have the blocked process threshold system configuration option enabled.  A good starting value is 15, which is the threshold in seconds at which the report is generated.  To set this value, run the following code:

EXECUTE sp_configure 'show advanced options', 1;
GO
RECONFIGURE;
GO
EXECUTE sp_configure 'blocked process threshold', 15;
GO
RECONFIGURE;
GO
EXECUTE sp_configure 'show advanced options', 0;
GO
RECONFIGURE;
GO

The following code will create the event session and then start it.  Note that you can create the event session and just have it defined in your system without running it.  Then, if you start to have blocking you can set the blocked process threshold and start the event session.

/*
check to see if the event session exists
*/
IF EXISTS ( SELECT  1
FROM    sys.server_event_sessions
WHERE   name = 'Capture_BlockedProcessReport' )
DROP EVENT SESSION [Capture_BlockedProcessReport] ON SERVER;
GO

/*
create the event session
edit the filename entry if C:\temp is not appropriate
*/
CREATE EVENT SESSION [Capture_BlockedProcessReport]
ON SERVER
ADD EVENT sqlserver.blocked_process_report
ADD TARGET package0.event_file(
SET filename=N'C:\Temp\Capture_BlockedProcessReport.xel'
)
WITH (MAX_MEMORY=8192 KB,EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,
MAX_DISPATCH_LATENCY=30 SECONDS,MAX_EVENT_SIZE=0 KB,MEMORY_PARTITION_MODE=NONE,
TRACK_CAUSALITY=OFF,STARTUP_STATE=OFF);
GO

/*
start the event session
*/
ALTER EVENT SESSION [Capture_BlockedProcessReport]
ON SERVER
STATE = START;
GO

Capturing Data

Once the event session is started, then you just wait until the blocking occurs.  The following code can be used to generate an example in your test/dev environment:

/*
create a table and insert
one row without committing
*/
USE [tempdb];
GO

CREATE TABLE [BlockingTest] (
[ID] INT IDENTITY(1,1) PRIMARY KEY,
[INFO] VARCHAR(10)
);
GO

BEGIN TRANSACTION
INSERT INTO [BlockingTest] ([INFO]) VALUES ('SQLskills');
GO

/*
run the following statement in a different window
*/
USE [tempdb];
GO
SELECT *
FROM [BlockingTest];

GO

After about 15 seconds, run the following code back in the original window:

/*
clean up (run in original window)
*/
USE [tempdb];
GO
COMMIT;
GO
DROP TABLE [BlockingTest];
GO

You can then stop the event session, and either leave it there until you need it again, or drop it entirely:

/*
stop the event session
*/
ALTER EVENT SESSION [Capture_BlockedProcessReport]
ON SERVER
STATE = STOP;
GO

/*
drop the event session
*/
DROP EVENT SESSION [Capture_BlockedProcessReport]
ON SERVER;
GO

Viewing the Report

To view the output from extended events you can open the .xel file in Management Studio or query the data using the sys.fn_xe_file_target_read_file function. I typically prefer the UI, but there’s currently no great way to copy the blocking report text and view it in the format you’re used to.  But if you use the function to read and parse the XML from the file, you can…

SELECT
    event_data.value('(event/@name)[1]', 'varchar(50)') AS event_name,
    event_data.query('(event/data[@name="blocked_process"]/value/blocked-process-report)[1]') as [blocked_process_report]
FROM
(
    SELECT CAST(event_data AS XML) AS event_data
    FROM sys.fn_xe_file_target_read_file('C:\Temp\Capture_BlockedProcessReport*.xel', NULL, NULL, NULL)
) AS sub;
GO

Depending on how long you let the blocking continue, you may have captured more than one event and therefore have multiple reports in the output:

Retrieving the blocked process report
Retrieving the blocked process report

 

You can click on the output for any row to see the blocked process in XML format, and then work through the blocking:

The blocked process report
The blocked process report

[Huge thanks to Jonathan for help with the XML.  I don’t think XML and I will ever be friends.  Geez.]

Summary

If you’re in need of the blocked process report and running SQL Server 2012, you now have another option for getting that information.  If you’re still new to extended events, check out the first two stairways in my XE series on SQLServerCentral

Happy New Year!

14 thoughts on “Capture Blocking Information with Extended Events and the Blocked Process Report

  1. Thanks Erin!

    Posting a query here if somebody could use some more stripped info in grid format via SSMS, ordered by the longest blocked queries.

    SELECT
    event_data.value(‘(event/@name)[1]’, ‘varchar(50)’) AS event_name,
    event_data.query(‘(event/data[@name=”blocked_process”]/value/blocked-process-report)[1]’) as [blocked_process_report],
    CAST(event_data.value(‘(event/data[@name=”blocked_process”]/value/blocked-process-report/blocked-process/process/@waittime)[1]’, ‘varchar(50)’) AS INT)AS Blocked_wait_time,
    event_data.value(‘(event/data[@name=”blocked_process”]/value/blocked-process-report/blocked-process/process/inputbuf)[1]’, ‘varchar(8000)’) AS Blocked_query,
    event_data.value(‘(event/data[@name=”blocked_process”]/value/blocked-process-report/blocked-process/process/@loginname)[1]’, ‘varchar(50)’) AS Blocked_login_name,
    event_data.value(‘(event/data[@name=”blocked_process”]/value/blocked-process-report/blocked-process/process/@hostname)[1]’, ‘varchar(50)’) AS Blocked_host_name,
    event_data.value(‘(event/data[@name=”blocked_process”]/value/blocked-process-report/blocked-process/process/@lasttranstarted)[1]’, ‘varchar(50)’) AS Blocked_last_transaction_started,
    event_data.value(‘(event/data[@name=”blocked_process”]/value/blocked-process-report/blocking-process/process/@waittime)[1]’, ‘varchar(50)’) AS Blocker_wait_time,
    event_data.value(‘(event/data[@name=”blocked_process”]/value/blocked-process-report/blocking-process/process/inputbuf)[1]’, ‘varchar(8000)’) AS Blocker_query,
    event_data.value(‘(event/data[@name=”blocked_process”]/value/blocked-process-report/blocking-process/process/@hostname)[1]’, ‘varchar(50)’) AS Blocker_host_name,
    event_data.value(‘(event/data[@name=”blocked_process”]/value/blocked-process-report/blocking-process/process/@loginname)[1]’, ‘varchar(50)’) AS Blocker_host_name,
    event_data.value(‘(event/data[@name=”blocked_process”]/value/blocked-process-report/blocking-process/process/@lastbatchstarted)[1]’, ‘varchar(50)’) AS Blocker_last_transaction_started
    FROM
    (
    SELECT CAST(event_data AS XML) AS event_data
    FROM sys.fn_xe_file_target_read_file(‘F:\Log\Capture_BlockedProcessReport*.xel’, NULL, NULL, NULL)
    ) AS sub
    ORDER BY Blocked_wait_time desc;

  2. So much hassle and hard work, compared to just loading up SQL profile and using my ready made template for showing blocks.
    Why make your life harder!

    1. I don’t think it does make your life harder. As a reminder, once you have created the event session, you can leave it on the server, in a stopped state, and then start and stop it when needed. You can also create a template, just like you can in Profiler.

    2. I still haven’t found a way to show the HostName like on SQLProfiler, Eg HostName = “User=admin, ProcID=3386, Host=SERVERNAME”. I’m trying to find the individual NT user (admin) using XE, but our system uses a common SQL login through ODBC.

  3. I was recently assigned a priority 0 case where a high profile customer was experiencing sporadic database timeouts and the client application would seemingly hang on all of the terminals when the problem would occur. This article helped me identify the blocking query which contained a bug. Got it fixed and now life is good. Thank you very much.

  4. Hello Erin,
    Good information about blocked extended events. I have tried to setup on 2016 SQL version. I have set up everything as per steps. Am unable to view the blocked events when we execute T-SQL in SSMS from Capture_BlockedProcessReport*.xel? But am able to view in server level blocking table we set up previously.

    any comments.

  5. The inputbuf attribute does not capture the entire SQL text if the text is really large one. I noticed this during a troubleshooting event. I do not know what is the solution to capture the entire text which is responsible for the blocking.

    1. Try adding the query_hash as an action and then querying sys.dm_exec_query_stats by the query_hash (you’ll have to do that quickly, as it is assumes the query is still in cache). If that doesn’t work, you can try the tsql_stack action, which has a lot more overhead, but if you get that, you can parse the XML, get the handle and offsets, and then query the cache with that (again, assumes the query is still in cache).

Leave a Reply

Your email address will not be published. Required fields are marked *

Other articles

A Fond Farewell

If you haven’t guessed from the title, I’m writing this post because I am leaving SQLskills. This Friday, January 14th, is my last day, and

Explore

Imagine feeling confident enough to handle whatever your database throws at you.

With training and consulting from SQLskills, you’ll be able to solve big problems, elevate your team’s capacity, and take control of your data career.