Blocked Process Detection and Analysis
Blocked process detection provides the DBA an excellent tool for improving the apparent responsiveness of SQL Server. This post provides example code for creating a blocked process Extended Events capture session. Also included is a SQL Server Agent Job to capture blocked processes on an ongoing basis. Finally, we delve into some sample queries for analyzing the captured blocked process reports.
Not a lot of blocked process detection going on there!
Wolf Dietrich Klebeband Städtebilder
Configuring SQL Server to report Blocked Process
The following code configures the blocked process threshold. This threshold is used by SQL Server to trigger blocked process detection. Without this threshold set up, SQL Server will never report details about what is causing blocking. Without it, you can only see processes currently being blocked via the Dynamic Management Views, such as sys.dm_exec_sessions. Configuring this setting allows the rest of our code to actually work, and captures far more detail.
|
1 2 3 4 5 6 7 8 9 |
IF ( SELECT c.value_in_use FROM sys.configurations c WHERE c.name = N'blocked process threshold (s)' ) = 0 BEGIN EXEC sys.sp_configure @configname = N'blocked process threshold (s)', @configvalue = '5'; RECONFIGURE END |
The code above only modifies the threshold if it currently disabled. If you have manually set it up, or adjusted it in the past, this code won’t modify that value. By default, it sets the value at 5, which represents 5 seconds. That is, a blocked process event will be fired at most every 5 seconds. You could adjust this to a larger value, but I wouldn’t suggest making it less than 5 seconds. Depending on how much blocking is happening, values lower than 5 seconds can place a noticeable amount of load on the server.
Capturing Blocked Process Details via Extended Events
The following code will create an Extended Events session named blocked_processes. The session is configured to start at server startup, and is automatically started at the end of the script. It’s the heart of our blocked process detection system.
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 |
/* Creates the "blocked_processes" Extended Events session to capture blocking events into a ring_buffer target. Yes, I know. See this site for some gotchas: https://www.sqlskills.com/blogs/jonathan/why-i-hate-the-ring_buffer-target-in-extended-events/ */ IF NOT EXISTS ( /* only create this session if one doesn't already exist to prevent inadvertant loss of events. */ SELECT 1 FROM sys.server_event_sessions ss WHERE ss.name = N'blocked_processes' ) BEGIN CREATE EVENT SESSION [blocked_processes] ON SERVER ADD EVENT sqlserver.blocked_process_report ( ACTION ( sqlserver.client_app_name , sqlserver.client_hostname , sqlserver.database_name ) ) ADD TARGET package0.ring_buffer( SET max_memory = 2048 /* Maximum amount of memory in KB to use. Old events are dropped when this value is reached. 0 means unbounded. 2048 is recommended to avoid posible XML data truncation */ , occurrence_number = 0 /* Preferred number of events of each type to keep. */ , max_events_limit = 0 /* Maximum number of events to store. Old events are dropped when this value is reached. 0 means unbounded. */ ) WITH ( MAX_MEMORY = 10 MB , EVENT_RETENTION_MODE = ALLOW_SINGLE_EVENT_LOSS , MAX_DISPATCH_LATENCY = 5 SECONDS , MAX_EVENT_SIZE = 0 KB , MEMORY_PARTITION_MODE = NONE , TRACK_CAUSALITY = OFF , STARTUP_STATE = ON ); END IF NOT EXISTS ( --XE sessions on show up in sys.dm_xe_sessions if they are running SELECT 1 FROM sys.dm_xe_sessions xs WHERE xs.name = N'blocked_processes' ) BEGIN ALTER EVENT SESSION [blocked_processes] ON SERVER STATE = START; END |
Creating a database to store the captured events
The following code creates a database named dba_admin where we’ll store the captured events for historical analysis purposes. The ring buffer in the Extended Events session is set to a maximum size of 2MB to avoid XML truncation. This database will allow us to capture lots of events. If you have a lot of blocking ongoing all the time, I’d recommend monitoring the size of the database. That will allow you to avoid running low on disk space.
|
1 2 3 4 5 6 7 |
IF DB_ID(N'db_admn') IS NULL BEGIN CREATE DATABASE db_admn; ALTER DATABASE db_admn SET RECOVERY SIMPLE; BACKUP DATABASE db_admn TO DISK = N'NUL:'; END GO |
Preserving Historical Blocked Process Details via a SQL Server Agent Job
Next, we’ll create a stored procedure in the dba_admin database that records the blocked process xml. Then we’ll create a SQL Server Agent Job to schedule capturing the events.
The stored procedure:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 |
IF OBJECT_ID(N'dbo.GatherBlockedProcessEvents', N'P') IS NOT NULL BEGIN DROP PROCEDURE dbo.GatherBlockedProcessEvents; END GO /* Gathers BlockedProcess events from the ring buffer target into the dbo.BlockedProcess_xml_events table. Should be ran from a frequently occurring SQL Server Agent job. */ CREATE PROCEDURE dbo.GatherBlockedProcessEvents AS BEGIN SET XACT_ABORT, NOCOUNT ON; IF OBJECT_ID(N'dbo.BlockedProcess_xml_events', N'U') IS NULL BEGIN DECLARE @cmd nvarchar(max); SET @cmd = N' CREATE TABLE dbo.BlockedProcess_xml_events ( xeTimeStamp datetimeoffset NOT NULL , xeXML XML NOT NULL ); CREATE CLUSTERED INDEX BlockProcess_xml_events_pk ON dbo.BlockedProcess_xml_events (xeTimeStamp);' EXEC sys.sp_executesql @cmd; END IF OBJECT_ID(N'tempdb..#xmlResults', N'U') IS NULL CREATE TABLE #xmlResults ( xeTimeStamp datetimeoffset NOT NULL , xeXML XML NOT NULL ); TRUNCATE TABLE #xmlResults; DECLARE @target_data xml; SELECT @target_data = CONVERT(xml, target_data) FROM sys.dm_xe_sessions AS s JOIN sys.dm_xe_session_targets AS t ON t.event_session_address = s.address WHERE s.name = N'blocked_processes' AND t.target_name = N'ring_buffer'; ;WITH src AS ( SELECT xeXML = xm.s.query('.') FROM @target_data.nodes('/RingBufferTarget/event') AS xm(s) ) INSERT INTO #xmlResults (xeXML, xeTimeStamp) SELECT src.xeXML , [xeTimeStamp] = src.xeXML.value('(/event/@timestamp)[1]', 'datetimeoffset(7)') FROM src INSERT INTO dbo.BlockedProcess_xml_events (xeTimeStamp, xeXML) SELECT xr.xeTimeStamp , xr.xeXML FROM #xmlResults xr WHERE NOT EXISTS ( --crudely excludes "duplicate" events based solely on the timestamp SELECT 1 FROM dbo.BlockedProcess_xml_events dxe WHERE dxe.xeTimeStamp = xr.xeTimeStamp ); END GO EXEC dbo.GatherBlockedProcessEvents; |
And the SQL Server Agent Job:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 |
/* Creates a SQL Server Agent job to run the dbo.GatherBlockedProcessEvents stored procedure. The job is scheduled to run every 5 minutes. */ DECLARE @JobID uniqueidentifier = NULL; DECLARE @ScheduleID int = NULL; IF NOT EXISTS ( SELECT 1 FROM msdb.dbo.sysjobs sj WHERE sj.name = N'DBA : Gather BlockedProcess Events' ) BEGIN IF NOT EXISTS ( SELECT 1 FROM msdb.dbo.syscategories sc WHERE sc.name = N'DBA Tools' ) BEGIN EXEC msdb.dbo.sp_add_category @class = 'JOB' , @type = 'LOCAL' , @name = N'DBA Tools'; END EXEC msdb.dbo.sp_add_job @job_name = N'DBA : Gather BlockedProcess Events' , @enabled = 1 , @description = N'Gathers BlockedProcess XML event data from the blocked_processes Extended Events Session, and persists the data in dbo.BlockedProcess_xml_events.' , @start_step_id = 1 , @category_name = N'DBA Tools' , @owner_login_name = N'sa' , @notify_level_eventlog = 0 , @notify_level_email = 2 , @notify_level_netsend = 0 , @notify_level_page = 0 , @notify_email_operator_name = N'DBA' , @notify_netsend_operator_name = NULL , @notify_page_operator_name = NULL , @delete_level = 0 , @originating_server = N'(local)' , @job_id = @JobID OUTPUT; EXEC msdb.dbo.sp_add_jobstep @job_id = @JobID , @step_id = 1 , @step_name = N'Gather blocked_processes' , @subsystem = N'TSQL' , @command = 'EXEC dbo.GatherBlockedProcessEvents;' , @on_success_action = 1 , @on_fail_action = 2 , @database_name = N'db_admn' , @database_user_name = NULL; EXEC msdb.dbo.sp_add_schedule @schedule_name = N'DBA : Gather BlockedProcess Events Schedule' , @enabled = 1 , @freq_type = 4 --daily , @freq_interval = 1 --every day , @freq_subday_type = 0x04 -- every @freq_subday_interval minutes , @freq_subday_interval = 5 , @owner_login_name = N'sa' , @schedule_id = @ScheduleID OUTPUT , @originating_server = N'(local)'; EXEC msdb.dbo.sp_attach_schedule @job_id = @JobID , @schedule_id = @ScheduleID; EXEC msdb.dbo.sp_add_jobserver @job_name = N'DBA : Gather BlockedProcess Events', @server_name = N'(local)'; END GO |
Analyzing Blocked Process Reports
Finally, the code below shows a couple of analysis queries. These queries show a couple of simple methods of “slicing-and-dicing” the Extended Events XML.
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 |
/* Analysis code */ USE db_admn; DECLARE @StartTime datetimeoffset; DECLARE @EndTime datetimeoffset; DECLARE @Offset int; SET @StartTime = DATEADD(HOUR, -4, GETDATE()); --modify these to suit your needs SET @EndTime = GETDATE(); SET @Offset = DATEDIFF(MINUTE, GETDATE(), GETUTCDATE()); SET @StartTime = DATEADD(MINUTE, @Offset, @StartTime); SET @EndTime = DATEADD(MINUTE, @Offset, @EndTime); SELECT StartTimeUTC = CONVERT(varchar(30), @StartTime, 127) , StartTimeLocal = CONVERT(varchar(30), DATEADD(MINUTE, 0 - @Offset, @StartTime), 120) , EndTimeUTC = CONVERT(varchar(30), @EndTime, 127) , EndTimeLocal = CONVERT(varchar(30), DATEADD(MINUTE, 0 - @Offset, @EndTime), 120); SELECT Blocked_Spid = x.xeXML.value('(/event/data[@name="blocked_process"]/value/blocked-process-report/blocked-process/process/@spid)[1]', 'int') , Blocked_Spid_Status = x.xeXML.value('(/event/data[@name="blocked_process"]/value/blocked-process-report/blocked-process/process/@status)[1]', 'varchar(1000)') , Blocked_Proc = x.xeXML.value('(/event/data[@name="blocked_process"]/value/blocked-process-report/blocked-process/process/executionStack/frame/@procname)[1]', 'nvarchar(128)') , Blocked_Text = x.xeXML.value('(/event/data[@name="blocked_process"]/value/blocked-process-report/blocked-process/process/inputbuf)[1]', 'nvarchar(4000)') , Blocked_Client_App = x.xeXML.value('(/event/data[@name="blocked_process"]/value/blocked-process-report/blocked-process/process/@clientapp)[1]', 'varchar(1000)') , Blocked_Host_Name = x.xeXML.value('(/event/data[@name="blocked_process"]/value/blocked-process-report/blocked-process/process/@hostname)[1]', 'varchar(1000)') , Blocked_Login_Nmae = x.xeXML.value('(/event/data[@name="blocked_process"]/value/blocked-process-report/blocked-process/process/@loginname)[1]', 'varchar(1000)') , Blocking_Spid = x.xeXML.value('(/event/data[@name="blocked_process"]/value/blocked-process-report/blocking-process/process/@spid)[1]', 'int') , Blocking_Spid_Status = x.xeXML.value('(/event/data[@name="blocked_process"]/value/blocked-process-report/blocking-process/process/@status)[1]', 'varchar(1000)') , Blocking_Proc = x.xeXML.value('(/event/data[@name="blocked_process"]/value/blocked-process-report/blocking-process/process/executionStack/frame/@procname)[1]', 'nvarchar(128)') , Blocking_Text = x.xeXML.value('(/event/data[@name="blocked_process"]/value/blocked-process-report/blocking-process/process/inputbuf)[1]', 'nvarchar(4000)') , Blocking_Client_App = x.xeXML.value('(/event/data[@name="blocked_process"]/value/blocked-process-report/blocking-process/process/@clientapp)[1]', 'varchar(1000)') , Blocking_Host_Name = x.xeXML.value('(/event/data[@name="blocked_process"]/value/blocked-process-report/blocking-process/process/@hostname)[1]', 'varchar(1000)') , Blocking_Login_Nmae = x.xeXML.value('(/event/data[@name="blocked_process"]/value/blocked-process-report/blocking-process/process/@loginname)[1]', 'varchar(1000)') FROM dbo.BlockedProcess_xml_events x WHERE x.xeXML.exist('/event[@name="blocked_process_report"]') = 1 AND x.xeXML.exist('/event[@timestamp>=sql:variable("@StartTime")]') = 1 AND x.xeXML.exist('/event[@timestamp<=sql:variable("@EndTime")]') = 1 ;WITH src AS ( SELECT Blocked_Proc = x.xeXML.value('(/event/data[@name="blocked_process"]/value/blocked-process-report/blocked-process/process/executionStack/frame/@procname)[1]', 'nvarchar(128)') , Blocked_Text = x.xeXML.value('(/event/data[@name="blocked_process"]/value/blocked-process-report/blocked-process/process/inputbuf)[1]', 'nvarchar(4000)') , Blocking_Proc = x.xeXML.value('(/event/data[@name="blocked_process"]/value/blocked-process-report/blocking-process/process/executionStack/frame/@procname)[1]', 'nvarchar(128)') , Blocking_Text = x.xeXML.value('(/event/data[@name="blocked_process"]/value/blocked-process-report/blocking-process/process/inputbuf)[1]', 'nvarchar(4000)') FROM dbo.BlockedProcess_xml_events x WHERE x.xeXML.exist('/event[@name="blocked_process_report"]') = 1 AND x.xeXML.exist('/event[@timestamp>=sql:variable("@StartTime")]') = 1 AND x.xeXML.exist('/event[@timestamp<=sql:variable("@EndTime")]') = 1 ) SELECT src.Blocked_Proc , src.Blocked_Text , src.Blocking_Proc , src.Blocking_Text , [Number of blocked_processes] = COUNT(1) FROM src GROUP BY src.Blocked_Proc , src.Blocked_Text , src.Blocking_Proc , src.Blocking_Text; |
Our next post will show some sample blocking, and the results of analyzing the sample blocking.
It’s pretty common to see deadlocks occurring frequently when there is a lot of blocking. See our Deadlock Detection and Analysis post for details on how to detect and analyze them!
[…] Blocked Process Detection and Analysis Hmmm, I did not even know about that threshold before. […]