Monitoring and Tracking SQL Server Blocking & Deadlocks process

Introduction

SQL Server deadlock one of the issues that can be happened in any SQL Server, today in this article I will not explain what is Deadlock and How we can solve it but the main purpose of this article is sharing the scripts I am using it for monitoring this kind of process let us start

It will be great if you share with us your experiences and your scripts in the comment

Demo Preparation
Database Configuration
Extended Event Implementation
SQL Server Custom Jobs Implementation
Deadlock Simulation
Capture the Deadlock information using SQL Server profiler
Capture the Deadlock information using SQL Server Error Log
Capture the Deadlock information using SQL Server Extended Event
Capture the Deadlock information using System_Health Default Extended event
Capture the Deadlock counts per Day
Capture the Deadlock information using SQL Server Custom Jobs
Check the Row Lock Blocking Info
Other Scripts for Monitoring

1- Demo Preparation

In this section, we will create only one Database as demo dB to be used in our demo

Create Database [Deadlockdemo]

Then we need to create two tables that will be used in step 5 (Deadlock Simulation)

CREATE TABLE dbo.invoices_demo (
   id int NOT NULL,
   num nvarchar(20) NOT NULL,
   customer nvarchar(100) NOT NULL,
   created_at DateTime NOT NULL,
   updated_at DateTime NOT NULL,
   CONSTRAINT PK_invoices PRIMARY KEY (id)
);
 
CREATE TABLE dbo.invoice_items_demo (
   invoice_id int NOT NULL,
   item_index int NOT NULL,
   product nvarchar(100) NOT NULL,
   qty int NOT NULL,
   price money NOT NULL,
   CONSTRAINT PK_invoice_items PRIMARY KEY (invoice_id, item_index)
);
 
INSERT INTO dbo.invoices_demo (id, num, customer, created_at, updated_at) VALUES
(1, 'INV180125', 'NASA', '2018-01-25', '2018-01-25'),
(2, 'INV180128', 'SpaceX', '2018-01-28', '2018-01-28');
INSERT INTO invoice_items_demo (invoice_id, item_index, product, qty, price) VALUES
(1, 1, 'NK-33 engine', 7, 145000),
(1, 2, 'Rocketdyne RS-25', 2, 560000),
(2, 1, 'Merlin 1D engine', 7, 125000),
(2, 2, 'J58 engine', 3, 225000);

2- Database Configuration

Now we need to enable trace flags to be able to log the deadlock transaction on error log

DBCC TRACEON (1204, 1222)
DBCC TRACESTATUS (1204, 1222)
EXEC sp_altermessage 1205, 'WITH_LOG', 'true'

The usage of sp_altermessage is the same concept of RAISERROR for more information about it check this ِِArticle

3- Extended Event Implementation

In this section we will create Extended Event to capture the Deadlock blocker transaction and victim transaction Scripts are copied from Brent Ozar Site Check the Source Scripts from Here

Before deploying this script, you need to change the path location

NowCREATE EVENT SESSION [blocked_process] ON SERVER
ADD EVENT sqlserver.blocked_process_report(
    ACTION(sqlserver.client_app_name,
           sqlserver.client_hostname,
           sqlserver.database_name)) ,
ADD EVENT sqlserver.xml_deadlock_report (
    ACTION(sqlserver.client_app_name,
           sqlserver.client_hostname,
           sqlserver.database_name,sqlserver.sql_text))
ADD TARGET package0.asynchronous_file_target
(SET filename = N'C:\Work\Deadlockscripts\blocked_process.xel',
     metadatafile = N'C:\Work\Deadlockscripts\blocked_process.xem',
     max_file_size=(65536),
     max_rollover_files=5)
WITH (MAX_DISPATCH_LATENCY = 5SECONDS)
GO

Now we need to Enable the Blocked Process Threshold

EXEC sp_configure 'show advanced options', 1 ;
GO
RECONFIGURE ;
GO
EXEC sp_configure 'blocked process threshold', '5';
RECONFIGURE

Then Enable the Extended Event

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

4- SQL Server Custom Jobs Implementation

In this part we will deploy one custom job to track the deadlock activities on the server and save it in MSDB Database

Create table on MSDB Database

USE MSDB
GO
SET ANSI_NULLS ON
GO
SET QUOTED_IDENTIFIER ON
GO
CREATE TABLE [dbo].[Blocking](
	[ID] [bigint] IDENTITY(1,1) NOT NULL,
	[ProcessWaiting] [varchar](1000) NULL,
	[ProcessBlocking] [varchar](1000) NULL,
	[WaitingQuery] [nvarchar](4000) NULL,
	[blockingQuery] [nvarchar](4000) NULL,
	[astatus] [varchar](1000) NULL,
	[bstatus] [varchar](1000) NULL,
	[waittime] [varchar](1000) NULL,
	[killbill] [varchar](1000) NULL,
	[Instance] [varchar](1000) NULL,
	[DBName] [varchar](1000) NULL,
	[Btime] [datetime] NULL
) ON [PRIMARY]
GO

ALTER TABLE [dbo].[Blocking] ADD  CONSTRAINT [DF_Blocking_Btime]  DEFAULT (getdate()) FOR [Btime]
GO

Create Jobs with Schedule 10 Seconds

USE [msdb]
GO
BEGIN TRANSACTION
DECLARE @ReturnCode INT
SELECT @ReturnCode = 0
/****** Object:  JobCategory [[Uncategorized (Local)]]    Script Date: 11/8/2020 9:55:15 AM ******/
IF NOT EXISTS (SELECT name FROM msdb.dbo.syscategories WHERE name=N'[Uncategorized (Local)]' AND category_class=1)
BEGIN
EXEC @ReturnCode = msdb.dbo.sp_add_category @class=N'JOB', @type=N'LOCAL', @name=N'[Uncategorized (Local)]'
IF (@@ERROR <> 0 OR @ReturnCode <> 0) GOTO QuitWithRollback

END
DECLARE @jobId BINARY(16)
EXEC @ReturnCode =  msdb.dbo.sp_add_job @job_name=N'Capture_Blocking', 
		@enabled=1, 
		@notify_level_eventlog=0, 
		@notify_level_email=0, 
		@notify_level_netsend=0, 
		@notify_level_page=0, 
		@delete_level=0, 
		@description=N'No description available.', 
		@category_name=N'[Uncategorized (Local)]', @job_id = @jobId OUTPUT
IF (@@ERROR <> 0 OR @ReturnCode <> 0) GOTO QuitWithRollback
/****** Object:  Step [Blocking]    Script Date: 11/8/2020 9:55:15 AM ******/
EXEC @ReturnCode = msdb.dbo.sp_add_jobstep @job_id=@jobId, @step_name=N'Blocking', 
		@step_id=1, 
		@cmdexec_success_code=0, 
		@on_success_action=1, 
		@on_success_step_id=0, 
		@on_fail_action=3, 
		@on_fail_step_id=0, 
		@retry_attempts=0, 
		@retry_interval=0, 
		@os_run_priority=0, @subsystem=N'TSQL', 
		@command=N'
USE [msdb]
GO
INSERT INTO [dbo].[Blocking]
           ([ProcessWaiting]
           ,[ProcessBlocking]
           ,[WaitingQuery]
           ,[blockingQuery]
           ,[astatus]
           ,[bstatus]
           ,[waittime]           
           ,[Instance]
           ,[DBName]
		   ,[killbill]
           )
           
		  select a.spid ProcessWaiting,a.blocked ProcessBlocking,sptxt.text WaitingQuery, blktxt.text blockingQuery 
,a.status,b.status , a.waittime ,  @@SERVERNAME as ServerName , db_name(a.dbid) as DBName
,''KILL '' + cast(a.blocked as varchar) KILLBill
from sys.sysprocesses 
a cross apply sys.dm_exec_sql_text(a.sql_handle) sptxt 
join sys.sysprocesses b on a.blocked = b.spid 
cross apply sys.dm_exec_sql_text(b.sql_handle) blktxt
where a.blocked <> 0  
order by a.spid
', 
		@database_name=N'msdb', 
		@flags=0
IF (@@ERROR <> 0 OR @ReturnCode <> 0) GOTO QuitWithRollback
EXEC @ReturnCode = msdb.dbo.sp_update_job @job_id = @jobId, @start_step_id = 1
IF (@@ERROR <> 0 OR @ReturnCode <> 0) GOTO QuitWithRollback
EXEC @ReturnCode = msdb.dbo.sp_add_jobschedule @job_id=@jobId, @name=N'Blocking_Schdule1', 
		@enabled=1, 
		@freq_type=4, 
		@freq_interval=1, 
		@freq_subday_type=2, 
		@freq_subday_interval=10, 
		@freq_relative_interval=0, 
		@freq_recurrence_factor=0, 
		@active_start_date=20201108, 
		@active_end_date=99991231, 
		@active_start_time=0, 
		@active_end_time=235959, 
		@schedule_uid=N'31cdc500-1447-4926-97af-62073fc8fff0'
IF (@@ERROR <> 0 OR @ReturnCode <> 0) GOTO QuitWithRollback
EXEC @ReturnCode = msdb.dbo.sp_add_jobserver @job_id = @jobId, @server_name = N'(local)'
IF (@@ERROR <> 0 OR @ReturnCode <> 0) GOTO QuitWithRollback
COMMIT TRANSACTION
GOTO EndSave
QuitWithRollback:
    IF (@@TRANCOUNT > 0) ROLLBACK TRANSACTION
EndSave:
GO

5- Deadlock Simulation

Now will Simulate the deadlock process by executing two scripts on the same time

Open SQL Server session and execute below script

USE Deadlockdemo;
GO
BEGIN TRANSACTION
   UPDATE invoices_demo SET updated_at = GETDATE() WHERE id = 1;
   WAITFOR DELAY '00:00:05';
   UPDATE invoice_items_demo SET qty = qty + 1 WHERE invoice_id = 1 AND item_index = 2;
ROLLBACK TRANSACTION

Then open the second SQL Server session and execute below script also

USE Deadlockdemo;
GO
BEGIN TRANSACTION
   UPDATE invoice_items_demo SET qty = qty + 1 WHERE invoice_id = 1 AND item_index = 2;
   WAITFOR DELAY '00:00:05';
   UPDATE invoices_demo SET updated_at = GETDATE() WHERE id = 1;
ROLLBACK TRANSACTION

After 5 second you will find the second script in the second session not completed because of this error

Msg 1205, Level 13, State 51, Line 6 Transaction (Process ID 60) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction

6- Capture the Deadlock information using SQL Server profiler

Now open the SQL Server Profiler and the template select T-SQL_Locks then Execute the two SQL Server scripts used in the Deadlock Simulation, then you will find the SQL server profiler tracked this deadlock transaction process as details and as the graph also.

7- Capture the Deadlock information using SQL Server Error Log

In this part, we will capture the Deadlock information from SQL Server log by below script but this information will give us as notification that was and deadlock process happened on the server and for other details about this transaction you can check the other monitoring solutions in this blog post

--Create Temporary table on Tempdb Database
Create table #Logs
(Logdate Datetime, Processinfo Varchar(100), Errortext Varchar(4000))
GO
---Load the SQL Server Error Log on temp table #Log
insert into #Logs
EXEC master.dbo.xp_readerrorlog
GO
--Select the Deadlock errors
Select * from #Logs
where Errortext like '%Deadlock%'
order by Logdate DESC
--Drop the #Log table
GO
Drop table #Logs

You can add this code in a job and instead of using #Logs as temp table you can create this table in MSDB and keep logging this deadlock information on this table as history information. Or you can build an alert using this code to give you an email notification when the deadlock process happens on the server.

8- Capture the Deadlock information using SQL Server Extended Event

Now we will execute the below script to query the deadlock information from the Extended event (blocked_process) we created it, you need to change the extended event file path location in the script before executing it

WITH events_cte AS (
  SELECT
    xevents.event_data,
    DATEADD(mi,
    DATEDIFF(mi, GETUTCDATE(), CURRENT_TIMESTAMP),
    xevents.event_data.value(
      '(event/@timestamp)[1]', 'datetime2')) AS [event time] ,
    xevents.event_data.value(
      '(event/action[@name="client_app_name"]/value)[1]', 'nvarchar(128)')
      AS [client app name],
    xevents.event_data.value(
      '(event/action[@name="client_hostname"]/value)[1]', 'nvarchar(max)')
      AS [client host name],
    xevents.event_data.value(
      '(event[@name="blocked_process_report"]/data[@name="database_name"]/value)[1]', 'nvarchar(max)')
      AS [database name],
    xevents.event_data.value(
      '(event[@name="blocked_process_report"]/data[@name="database_id"]/value)[1]', 'int')
      AS [database_id],
    xevents.event_data.value(
      '(event[@name="blocked_process_report"]/data[@name="object_id"]/value)[1]', 'int')
      AS [object_id],
    xevents.event_data.value(
      '(event[@name="blocked_process_report"]/data[@name="index_id"]/value)[1]', 'int')
      AS [index_id],
    xevents.event_data.value(
      '(event[@name="blocked_process_report"]/data[@name="duration"]/value)[1]', 'bigint') / 1000
      AS [duration (ms)],
    xevents.event_data.value(
      '(event[@name="blocked_process_report"]/data[@name="lock_mode"]/text)[1]', 'varchar')
      AS [lock_mode],
    xevents.event_data.value(
      '(event[@name="blocked_process_report"]/data[@name="login_sid"]/value)[1]', 'int')
      AS [login_sid],
    xevents.event_data.query(
      '(event[@name="blocked_process_report"]/data[@name="blocked_process"]/value/blocked-process-report)[1]')
      AS blocked_process_report,
    xevents.event_data.query(
      '(event/data[@name="xml_report"]/value/deadlock)[1]')
      AS deadlock_graph
  FROM    sys.fn_xe_file_target_read_file
    ('C:\Work\Deadlockscripts\blocked_process*.xel',
     'C:\Work\Deadlockscripts\blocked_process*.xem',
     null, null)
    CROSS APPLY (SELECT CAST(event_data AS XML) AS event_data) as xevents
)
SELECT
  CASE WHEN blocked_process_report.value('(blocked-process-report[@monitorLoop])[1]', 'nvarchar(max)') IS NULL
       THEN 'Deadlock'
       ELSE 'Blocked Process'
       END AS ReportType,
  [event time],
  CASE [client app name] WHEN '' THEN ' -- N/A -- '
                         ELSE [client app name]
                         END AS [client app _name],
  CASE [client host name] WHEN '' THEN ' -- N/A -- '
                          ELSE [client host name]
                          END AS [client host name],
  [database name],
  COALESCE(OBJECT_SCHEMA_NAME(object_id, database_id), ' -- N/A -- ') AS [schema],
  COALESCE(OBJECT_NAME(object_id, database_id), ' -- N/A -- ') AS [table],
  index_id,
  [duration (ms)],
  lock_mode,
  COALESCE(SUSER_NAME(login_sid), ' -- N/A -- ') AS username,
  CASE WHEN blocked_process_report.value('(blocked-process-report[@monitorLoop])[1]', 'nvarchar(max)') IS NULL
       THEN deadlock_graph
       ELSE blocked_process_report
       END AS Report
FROM events_cte
ORDER BY [event time] DESC

IF you open the XML record you will find all of the query details participated in this Deadlock process

9- Capture the Deadlock information using the System_Health Default Extended Event

Before Executing this Query you need to check the Location path for the System_Health Extended event usually it is exists with the SQL Log Error Location in the setup location.

SELECT s.name, se.event_name
FROM sys.dm_xe_sessions s
       INNER JOIN sys.dm_xe_session_events se ON (s.address = se.event_session_address) and (event_name = 'xml_deadlock_report')
WHERE name = 'system_health'
SELECT CONVERT(xml, event_data).query('/event/data/value/child::*'),
       CONVERT(xml, event_data).value('(event[@name="xml_deadlock_report"]/@timestamp)[1]','datetime') as Execution_Time
FROM sys.fn_xe_file_target_read_file('C:\Program Files\Microsoft SQL Server\MSSQL14.SQL2017\MSSQL\Log\system_health*.xel', null, null, null)
WHERE object_name like 'xml_deadlock_report'

10- Capture the Deadlock counts per Day

SELECT 
    'Deadlocks Occurrences Report', 
    CONVERT(BIGINT,((1.0 * p.cntr_value / 
NULLIF(datediff(DD,d.create_date,CURRENT_TIMESTAMP),0)))) as 
AveragePerDay,
    CAST(p.cntr_value AS NVARCHAR(100)) + ' deadlocks have been recorded 
since startup.' AS Details, 
    d.create_date as StartupDateTime
FROM sys.dm_os_performance_counters p
INNER JOIN sys.databases d ON d.name = 'tempdb'
WHERE RTRIM(p.counter_name) = 'Number of Deadlocks/sec'
AND RTRIM(p.instance_name) = '_Total'
;

11- Capture the Deadlock information using SQL Server Custom Jobs

We already implanted Jobs to capture the Deadlock transaction details and to save it in table “Blocking” exists on MSDB Database

Select * from MSDB..Blocking
order by Btime DESC

12- Check the Row Lock Blocking Info

-- Row Locks / Blocking
SELECT  OBJECT_SCHEMA_NAME(ios.object_id)+'.'+OBJECT_NAME(ios.object_id) AS table_name
	   ,i.name AS index_name
	   ,row_lock_count
	   ,row_lock_wait_count
	   ,CAST(100.*row_lock_wait_count/NULLIF(row_lock_count,0) AS DECIMAL(6,
															2)) AS row_block_pct
	   ,row_lock_wait_in_ms
	   ,CAST(1.*row_lock_wait_in_ms/NULLIF(row_lock_wait_count,0) AS DECIMAL(12,
															  2)) AS row_avg_lock_wait_ms
FROM    sys.dm_db_index_operational_stats(DB_ID(),NULL,NULL,NULL) ios
		INNER JOIN sys.indexes i
			ON i.object_id=ios.object_id
			   AND i.index_id=ios.index_id
WHERE   OBJECTPROPERTY(ios.object_id,'IsUserTable')=1
--and OBJECT_SCHEMA_NAME(ios.object_id)+'.'+OBJECT_NAME(ios.object_id) = 'Person.Person'
ORDER BY row_lock_wait_count+page_lock_wait_count DESC
	   ,row_lock_count+page_lock_count DESC

13- Other Scripts for Monitoring

Sp_blocked_process_report_viewer This Stored Procedure created by Michael J. Swart for Deadlocks monitoring check his post from Here and you download the Stored procedure from GitHub project check this Link
Stored procedure sp_WhoIsActive created by Adam Machanic download it from Here
DMV for Checking SQL Server Waits Created by Paul Randal download the script from HERE
For other information about Extended event check this Article and this Article

Keep Following

Cloud Tech Website blog survey

IF you found this blog is helpful and sharing useful content please take few second to do rate the website blog from here

Monitoring and Tracking SQL Server Blocking & Deadlocks process

Introduction

1- Demo Preparation

2- Database Configuration

3- Extended Event Implementation

4- SQL Server Custom Jobs Implementation

5- Deadlock Simulation

6- Capture the Deadlock information using SQL Server profiler

7- Capture the Deadlock information using SQL Server Error Log

8- Capture the Deadlock information using SQL Server Extended Event

9- Capture the Deadlock information using the System_Health Default Extended Event

10- Capture the Deadlock counts per Day

11- Capture the Deadlock information using SQL Server Custom Jobs

12- Check the Row Lock Blocking Info

13- Other Scripts for Monitoring

Keep Following

Cloud Tech Website blog survey

Published by Mustafa EL-Masry

Leave a Reply Cancel reply

Monitoring and Tracking SQL Server Blocking & Deadlocks process

Introduction

1- Demo Preparation

2- Database Configuration

3- Extended Event Implementation

4- SQL Server Custom Jobs Implementation

5- Deadlock Simulation

6- Capture the Deadlock information using SQL Server profiler

7- Capture the Deadlock information using SQL Server Error Log

8- Capture the Deadlock information using SQL Server Extended Event

9- Capture the Deadlock information using the System_Health Default Extended Event

10- Capture the Deadlock counts per Day

11- Capture the Deadlock information using SQL Server Custom Jobs

12- Check the Row Lock Blocking Info

13- Other Scripts for Monitoring

Keep Following

Cloud Tech Website blog survey

Share this:

Like this:

Related

Published by Mustafa EL-Masry

Leave a Reply Cancel reply