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!

Taking Risks

risk \’risk\ noun : the possibility that something bad or unpleasant (such as an injury or a loss) will happen

[reference: http://www.merriam-webster.com/dictionary/risk]

There are risks in life every day.  Some we see very clearly.  Others we don’t even notice.  Some are related to relationships with family and friends.  Some are related to our careers.  And some involve the hundreds of other components in our daily lives.

When I first started attending user group meetings in Cleveland, every month Allen White would say, “If you are interested in speaking, please consider submitting.  Everyone has something to share, and everyone else has something they can learn from you.”  I admit, at first I kind of thought it was just rhetoric.  I was wrong.  If you know Allen, you know that he really means it when he says it.  And I know he’s right.  I love asking people what they do in their job every day, because rarely do people do the same thing (especially in the SQL Server world) and I always learn something new.  Everyone in the SQL Server community is extremely well-versed in some SQL Server topic – enough so that they could put together a presentation and talk about it for an hour.  But many don’t, for a variety of reasons.  Some people just have no desire to speak in front of a group, and that’s fine.  You can share knowledge in other ways (hello blog posts).

But for those of you that have considered speaking, or are just a little bit interested, I give you:

Evelyn Maxwell

I tweeted about her SQLSaturday Cleveland submission yesterday (it’s on Improving Your PowerPoint Skills, in case you didn’t click through), but a lot of people aren’t on Twitter so I wanted to mention it here, particularly because many people commented that if a 7th grader has the chutzpah (my word, not anyone else’s) to submit to a SQLSaturday, then others can too.  Yes.  Exactly yes.

Now, Evelyn’s not all alone, her dad is David Maxwell (who just won speaker Idol at the PASS Summit) and I’m sure she’s getting some guidance from him.  Anyone who is speaking at a SQLSaturday for the first time is hopefully getting some mentoring – it’s a daunting task to take on all alone!  But if you want to try it, then do it.  Submit to your local SQLSaturday.  Find a mentor.  Take that risk.  I know there’s a fear of failure there.  Your session may not get accepted.  Evelyn’s may not, and she knows that.  But she tried.

Fly...  photo credit: Jonathan Kehayias

Fly… photo credit: Jonathan Kehayias

 

 

Use of the C: drive by the Profiler UI and XE Live Data Viewer

I had an email from a fellow MVP this week who is in the process of learning Extended Events (hooray!). One question this person had was whether Extended Events had the same issue as Profiler where the C: drive can be heavily used and potentially run out space.

To clarify, with regard to Profiler UI, if you are using the UI to capture events (not a server side trace that writes to a file which is the preferred method), the Profiler UI does file caching of events locally when it runs against a SQL Server instance. It also performs caching when reading an existing file. These cached events are stored on the C:\drive by default, unless you have changed the User TMP location in Environment Variables (Control Panel | System | Edit the system environment variables | Advanced | Environment Variables… ):

Accesing the User TMP variable

Accesing the User TMP variable

Depending on what events you have configured for Profiler, your filter(s), the workload, and how long you run Profiler, you could generate more events than the UI can handle. Therefore, they’ll start buffering to the User TMP location. If you’re not paying attention, you can fill up the C: drive. This can cause applications (including SQL Server) to generate errors or stop working entirely. Not good.

Reference: https://msdn.microsoft.com/en-us/library/ms174203.aspx

Now, back to the original question. Does the same problem exist for Extended Events? Only if you’re using the Live Data Viewer.  After you have an event session created (you can just use system_health for this example), within Management Studio, go to Management | Extended Events | Sessions, select the session and right-click and select Watch Live Data:

Using the Live Data Viewer in XE

Using the Live Data Viewer in XE

As events are captured, they will show up in the data view. As with the Profiler UI, the number of events that appear will depend on the session configuration and the workload. The Live Data Viewer will only show a maximum of one million (1,000,000) events. Once that number has been exceeded, it will start to cache events to the User TMP location, just like the Profiler UI. And just like the Profiler UI, that can fill up the C: drive if that is still the User TMP location. Note that the Live Data Viewer will automatically disconnect and stop displaying events if the engine determines it’s negatively affecting performance. If the event session’s internal memory buffers fill up and the events cannot be dispatched to the event stream for consumption, the engine will disconnect the UI from the event stream. –

[More on the viewer if you’re interested: Introducing the Extended Events Reader]

There are two action items for you:

  1. Don’t use the Profiler UI unless it’s a NON-Production environment.
    1. If you refuse to give up that woobie (name the movie reference) at least change the User TMP location to something other than C:
  2. If you use the Live Data View in Extended Events for event sessions that generate a lot of events, change the User TMP location to something other C:

Shout out to Jonathan for a review of this one.