Blocking in SQL Server is not an uncommon phenomena. Many times it is rather trivial. Sometimes, it extends beyond the realm of trivial and needs to be addressed.
How do you know when a blocked process has gone beyond the realm of trivial? What can you do to find long held blocks in SQL Server? The answer to that is actually not that simple. Why? Because there are so many methods that can help uncover blocking issues that it would be difficult to address in a single article.
However, there is a combination of tools I wish to discuss in this article that can be added to your toolbelt. These tools will help address the varying levels of blocking issues within your database environment. What are the tools? Naturally one of the tools would be Extended Events (XEvents). And it just so happens that the other tool is somewhat new to me – it is the Blocked Process Report.
Yeah yeah yeah, I said it is new to me. Truth is I haven’t used it previously because I have always used a custom built solution. That isn’t to say I wasn’t aware of the option – just hadn’t employed it. Why now? Well, to be honest it is because of the ease of use with XEvents.
For the sake of posterity, I am also adding this to the MASSIVE collection of Extended Events articles.
More Value from the Blocked Process Report
One of the big problems, I fear, with the blocked process report is that it is not easily consumed. It is somewhat kludgy and hard to read – unless you are really familiar with that kind of output. In addition, you have to twist a couple of knobs to make it work. Tweak these knobs too far and you can cause more harm than good.
Behind the scenes, the blocked process report is controlled by the deadlock detector in SQL Server. By default, the deadlock detector wakes every 5 seconds and checks for “problems”. To get the blocked process report to utilize this resource, you must configure a setting. This setting is named “blocked process threshold (s)” and is an advanced option. It is easy to adjust with a script such as the following.
SELECT * FROM sys.configurations c WHERE c.[name] LIKE 'block%'; IF EXISTS (SELECT * FROM sys.configurations c WHERE c.[name] LIKE 'block%' AND (c.value = 0 OR c.value_in_use = 0)) BEGIN EXECUTE sp_configure 'show advanced options', 1; RECONFIGURE WITH OVERRIDE; EXECUTE sp_configure 'blocked', 20; --blocked process threshold (s) RECONFIGURE WITH OVERRIDE; END GO SELECT * FROM sys.configurations c WHERE c.[name] LIKE 'block%';
The previous script will evaluate the “blocked process threshold (3)” setting. If that setting is set to 0, then it will be updated (with override) to 20. This means that now the blocked process report will tap into the deadlock detector every 20 seconds and report on any blocking.
Great! Where do we find that data? That is where the power of XEvents comes into play!
XEvents Power and Blocked Processes
As previously mentioned, consuming the blocked process report is a bit of a problem. Sure, one could have used a server side trace to monitor the blocked_process_report event. That, honestly, was less than ideal. With the presence of XEvents, we have a true power tool and a remarkably ideal tool to consume and monitor the event. In the following script, I have provided the means to create an XE Session that will capture the blocked_process_report event as well as parse it into human friendly format.
Note, I have included the trace_print event in the provided session. This is to demonstrate the power of the parse script. If you have multiple events being tracked in the same session, the parse script will just bypass all of those events and only look at the blocked_process_report event.
USE master;
GO
DECLARE @XESession NVARCHAR(MAX) = 'Blocking'
, @DropXESQL VARCHAR(256);
-- Create the Event Session
IF EXISTS ( SELECT *
FROM sys.server_event_sessions ses
WHERE ses.[name] = @XESession )
BEGIN
SET @DropXESQL = 'DROP EVENT SESSION ' + @XESession + '
ON SERVER;'
EXECUTE (@DropXESQL)
END;
CREATE EVENT SESSION [Blocking]
ON SERVER
ADD EVENT sqlserver.blocked_process_report
(ACTION (
package0.event_sequence
, sqlserver.client_app_name
, sqlserver.client_hostname
, sqlserver.database_name
, sqlserver.plan_handle
, sqlserver.session_id
, sqlserver.sql_text
)
)
, ADD EVENT sqlserver.trace_print
(ACTION (
package0.event_sequence
, sqlserver.client_app_name
, sqlserver.client_hostname
, sqlserver.database_name
, sqlserver.plan_handle
, sqlserver.session_id
, sqlserver.sql_text
)
)
ADD TARGET package0.event_file
(SET filename = N'C:DatabaseXEBlocking.xel')
WITH (
MAX_MEMORY = 4096KB
, EVENT_RETENTION_MODE = ALLOW_SINGLE_EVENT_LOSS
, MAX_DISPATCH_LATENCY = 30 SECONDS
, MAX_EVENT_SIZE = 0KB
, MEMORY_PARTITION_MODE = NONE
, TRACK_CAUSALITY = ON
, STARTUP_STATE = OFF
);
GO
IF OBJECT_ID('tempdb..#xmlprocess') IS NOT NULL
BEGIN
DROP TABLE #xmlprocess;
END;
IF OBJECT_ID('tempdb..#ReportsXML') IS NOT NULL
BEGIN
DROP TABLE #ReportsXML;
END;
SET NOCOUNT ON;
IF NOT EXISTS (
SELECT *
FROM sys.server_event_sessions es
INNER JOIN sys.server_event_session_targets est
ON es.event_session_id = est.event_session_id
WHERE est.name IN ( 'event_file' )
AND es.name = @XESession
)
RAISERROR(
'Warning: The extended event session you supplied does not exist or does not have an "event_file" or "ring_buffer" target.'
, 10
, 1
);
CREATE TABLE #ReportsXML
(
MonitorLoopID NVARCHAR(100) NOT NULL
, endTime DATETIME NULL
, blocking_spid INT NOT NULL
, blocking_ecid INT NOT NULL
, blocked_spid INT NOT NULL
, blocked_ecid INT NOT NULL
, blocked_hierarchy_string AS CAST(blocked_spid AS VARCHAR(20)) + '.' + CAST(blocked_ecid AS VARCHAR(20)) + '/'
, blocking_hierarchy_string AS CAST(blocking_spid AS VARCHAR(20)) + '.' + CAST(blocking_ecid AS VARCHAR(20)) + '/'
, BlockedProcessReportXML XML NOT NULL
,
PRIMARY KEY CLUSTERED (
MonitorLoopID
, blocked_spid
, blocked_ecid
)
,
UNIQUE NONCLUSTERED (
MonitorLoopID
, blocking_spid
, blocking_ecid
, blocked_spid
, blocked_ecid
)
);
BEGIN
DECLARE @SessionType NVARCHAR(MAX);
DECLARE @SessionId INT;
DECLARE @SessionTargetId INT;
DECLARE @FilenamePattern NVARCHAR(MAX);
SELECT TOP (1)
@SessionType = est.name
, @SessionId = est.event_session_id
, @SessionTargetId = est.target_id
FROM sys.server_event_sessions es
INNER JOIN sys.server_event_session_targets est
ON es.event_session_id = est.event_session_id
WHERE est.name IN ( 'event_file')
AND es.name = @XESession;
IF (@SessionType = 'event_file')
BEGIN
SELECT @FilenamePattern = REPLACE(CAST([value] AS NVARCHAR(MAX)), '.xel', '*xel')
FROM sys.server_event_session_fields esf
WHERE esf.event_session_id = @SessionId
AND esf.[object_id] = @SessionTargetId
AND esf.[name] = 'filename';
IF (@FilenamePattern NOT LIKE '%xel')
SET @FilenamePattern += '*xel';
/* parse event data */
SELECT CAST ([t2].[event_data] AS XML) AS event_data, t2.file_offset,t2.file_name, cte1.event_session_id
INTO #xmlprocess
FROM ( SELECT CASE
WHEN CAST(sesf.[value] AS NVARCHAR(128)) NOT LIKE '%xel'
THEN REPLACE(CONVERT(NVARCHAR(128),CONVERT(NVARCHAR(128),sesf.[value]) + '.xel'),'.xel','*.xel')
ELSE REPLACE(CONVERT(NVARCHAR(128),sesf.[value]),'.xel','*.xel')
END AS targetvalue
, ses.event_session_id
FROM sys.server_event_sessions ses
INNER JOIN sys.server_event_session_fields sesf
ON ses.event_session_id = sesf.event_session_id
WHERE sesf.[name] = 'filename'
AND ses.[name] = @XESession
) cte1
OUTER APPLY sys.fn_xe_file_target_read_file(cte1.targetvalue, NULL, NULL, NULL) t2
WHERE t2.event_data LIKE '<event name="blocked%';
INSERT INTO #ReportsXML
(
blocked_ecid
, blocked_spid
, blocking_ecid
, blocking_spid
, MonitorLoopID
, BlockedProcessReportXML
, endTime
)
SELECT bpShredded.blocked_ecid
, bpShredded.blocked_spid
, bpShredded.blocking_ecid
, bpShredded.blocking_spid
, COALESCE(
bpShredded.MonitorLoopID, CONVERT(NVARCHAR(100), bpReports.EventDate, 120), CAST(NEWID() AS NVARCHAR(100))
)
, bpReports.BlockedProcessReportXML
, bpReports.EventDate
FROM #xmlprocess AS x
CROSS APPLY (
SELECT x.[event_data].value('(event/@timestamp)[1]', 'datetime') AS EventDate
, x.[event_data].query('//event/data/value/blocked-process-report') AS BlockedProcessReportXML
) AS bpReports
CROSS APPLY (
SELECT MonitorLoopID = BlockedProcessReportXML.value('(//@monitorLoop)[1]', 'nvarchar(100)')
, blocked_spid = BlockedProcessReportXML.value(
'(/blocked-process-report/blocked-process/process/@spid)[1]'
, 'int'
)
, blocked_ecid = BlockedProcessReportXML.value(
'(/blocked-process-report/blocked-process/process/@ecid)[1]'
, 'int'
)
, blocking_spid = BlockedProcessReportXML.value(
'(/blocked-process-report/blocking-process/process/@spid)[1]'
, 'int'
)
, blocking_ecid = BlockedProcessReportXML.value(
'(/blocked-process-report/blocking-process/process/@ecid)[1]'
, 'int'
)
) AS bpShredded
WHERE bpShredded.blocking_spid IS NOT NULL
AND bpShredded.blocked_spid IS NOT NULL;
END;
END;
WITH HeadBlockers AS (
SELECT blocking_spid
, blocking_ecid
, MonitorLoopID
, blocking_hierarchy_string
FROM #ReportsXML
EXCEPT
SELECT blocked_spid
, blocked_ecid
, MonitorLoopID
, blocked_hierarchy_string
FROM #ReportsXML
)
, Hierarchy AS (
SELECT MonitorLoopID
, blocking_spid AS spid
, blocking_ecid AS ecid
, CAST('/' + blocking_hierarchy_string AS VARCHAR(MAX)) AS chain
, 0 AS level
FROM HeadBlockers
UNION ALL
SELECT irx.MonitorLoopID
, irx.blocked_spid
, irx.blocked_ecid
, CAST(h.chain + irx.blocked_hierarchy_string AS VARCHAR(MAX))
, h.level + 1
FROM #ReportsXML irx
INNER JOIN Hierarchy h
ON irx.MonitorLoopID = h.MonitorLoopID
AND irx.blocking_spid = h.spid
AND irx.blocking_ecid = h.ecid
)
SELECT ISNULL(CONVERT(NVARCHAR(30), irx.endTime, 120), '') AS TraceTime
,CASE WHEN ISNULL(CONVERT(NVARCHAR(30), irx.endTime, 120), '') = ''
THEN 'Lead Blocker'
ELSE 'Blocked Process'
END AS BlockingParticipationType
, SPACE(4 * h.[level]) + CAST(h.spid AS VARCHAR(20)) + CASE h.ecid
WHEN 0
THEN ''
ELSE '(' + CAST(h.ecid AS VARCHAR(20)) + ')'
END AS BlockingTree
, irx.BlockedProcessReportXML
FROM Hierarchy h
LEFT OUTER JOIN #ReportsXML irx
ON irx.MonitorLoopID = h.MonitorLoopID
AND irx.blocked_spid = h.spid
AND irx.blocked_ecid = h.ecid
ORDER BY h.MonitorLoopID
, h.chain;
DROP TABLE #ReportsXML;
DROP TABLE #xmlprocess;
The parse script is mostly attributable to Michael J. Swart. He provided the bulk of the work that I used to tune and make go faster (roughly 4x faster). You can find his original work here.
Blocked Process Output
If I parse a running XE Session, looking at the blocked_process_report, I could see something like the following.
As you can see, the output lets us see a rudimentary blocking tree and helps to identify the lead blocker. In addition, this blocked process output also produces an XML value that is clickable so we can see more information about the blocked process. Here is a sample of one of the XML clickable values from a parse of this session I have running.
This is where the power resides. The ease of XEvents coupled with the blocked process report, means minimal code and easy access to see blocking sessions. Not just current blocking sessions, but now I have easily logged the blocking sessions to be reviewed at a future date. In short, this provides the means for historical review as well as real time blocking info. Even better is that I can make a tweak here or there and make it so somebody can be paged when certain thresholds are met. All based upon this simple XE Session. That is true power! That is real value for the blocked process report!
Put a bow on it
By combining the raw power of the Extended Events engine in SQL Server with the Blocked Process Report, we are able to achieve real value in blocking monitoring. This can be achieved without excessive expense, expertise, or effort!
Go ahead, have a try at it!
Interested in learning more deep technical information? Check these out!
Want to learn more about your indexes? Try this index maintenance article or this index size article.
This is the third article in the 2021 “12 Days of Christmas” series. For the full list of articles, please visit this page.
The post Blocked Process Report: How to Get More Value first appeared on SQL RNNR.