Monday, September 27, 2021

.::: SQL Server: how to simulate and catch deadlock :::.


1. Create database 
create database dead_lock_lab
go 

2. create table & row data 
USE dead_lock_lab;
 
CREATE TABLE dbo.invoices (
   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 (
   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 (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 (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);

select * from invoices;
select * from invoice_items;

3. setting SQL Server Profiler


4. Identify Deadlocks in SQL Server Using Trace Flag 1222 and 1204 (Optional)

Difference between Trace Flag 1222 and 1204
Explanation of Trace Flag 1222 and 1204 as per TechNet Article Detecting and Ending Deadlocks is mentioned below.

Trace Flag 1204:- Focused on the nodes involved in the deadlock. Each node has a dedicated section, and the final section describes the deadlock victim.

Trace Flag 1222:- Returns information in an XML-like format that does not conform to an XML Schema Definition (XSD) schema. The format has three major sections. The first section declares the deadlock victim. The second section describes each process involved in the deadlock. The third section describes the resources that are synonymous with nodes in trace flag 1204.

Scope of a Trace Flag can be either set to Global or Session Only. However, 1204 & 1222 trace flags can be set Global Only.

To enable

DBCC TRACEON (1204,-1)
GO
DBCC TRACEON (1222,-1)
GO

DBCC TRACESTATUS(-1)
GO

To Disable 
DBCC TRACEOFF (1204,-1)
GO
DBCC TRACEOFF (1222,-1)
GO

DBCC TRACESTATUS(-1)
GO

5. Open new query on tab 1 & type query (sample delay 5 second)
USE dead_lock_lab;
BEGIN TRANSACTION
   UPDATE invoices SET updated_at = GETDATE() WHERE id = 1;
   WAITFOR DELAY '00:00:05';
   UPDATE invoice_items SET qty = qty + 1 WHERE invoice_id = 1 AND item_index = 2;
ROLLBACK TRANSACTION

6. Open new query on tab 2 & type query (sample delay 5 second)
USE dead_lock_lab;
BEGIN TRANSACTION
   UPDATE invoice_items SET qty = qty + 1 WHERE invoice_id = 1 AND item_index = 2;
   WAITFOR DELAY '00:00:05';
   UPDATE invoices SET updated_at = GETDATE() WHERE id = 1;
ROLLBACK TRANSACTION

7. run query on tab 1 then tab 2 before on the same time before 4 second 

8. on tab query 2 get error 

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

Completion time: 2021-09-27T13:46:48.1599329+07:00


9. log sql log file viewer


10. log SQL Server Profiler 


11. Deadlock Graph SQL Profiler 


12. Check log sql even viewer if Trace Flag enable 

2021-09-27 14:18:19.13 spid4s      Requested by: 
2021-09-27 14:18:19.13 spid4s        ResType:LockOwner Stype:'OR'Xdes:0x000000016C69E3A8 Mode: X SPID:57 BatchID:0 ECID:0 TaskProxy:(0x000000016EB6E608) Value:0x73b160c0 Cost:(0/248)
2021-09-27 14:18:19.16 spid4s      
2021-09-27 14:18:19.16 spid4s      Victim Resource Owner:
2021-09-27 14:18:19.16 spid4s       ResType:LockOwner Stype:'OR'Xdes:0x000000016C6A2E98 Mode: X SPID:54 BatchID:0 ECID:0 TaskProxy:(0x00000001676E2608) Value:0x73b0f100 Cost:(0/244)
2021-09-27 14:18:19.16 spid54      Error: 1205, Severity: 13, State: 51.
2021-09-27 14:18:19.16 spid54      Transaction (Process ID 54) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
2021-09-27 14:18:19.27 spid21s     deadlock-list
2021-09-27 14:18:19.27 spid21s      deadlock victim=process17701dc38
2021-09-27 14:18:19.27 spid21s       process-list
2021-09-27 14:18:19.27 spid21s        process id=process17701dc38 taskpriority=0 logused=244 waitresource=KEY: 24:72057594039042048 (8194443284a0) waittime=269 ownerId=699997 transactionname=user_transaction lasttranstarted=2021-09-27T14:18:13.863 XDES=0x16c6a2e98 lockMode=X schedulerid=2 kpid=4904 status=suspended spid=54 sbid=0 ecid=0 priority=0 trancount=2 lastbatchstarted=2021-09-27T14:18:13.863 lastbatchcompleted=2021-09-27T14:18:13.847 lastattention=1900-01-01T00:00:00.847 clientapp=Microsoft SQL Server Management Studio - Query hostname=LAPTOP-31OV73CJ hostpid=9856 loginname=sa isolationlevel=read committed (2) xactid=699997 currentdb=24 lockTimeout=4294967295 clientoption1=671090784 clientoption2=390200
2021-09-27 14:18:19.27 spid21s         executionStack
2021-09-27 14:18:19.27 spid21s          frame procname=adhoc line=5 stmtstart=24 sqlhandle=0x020000004d02531fda25d6c8e3bd31ffe48a4d5ca64348a10000000000000000000000000000000000000000
2021-09-27 14:18:19.27 spid21s     UPDATE [invoices] set [updated_at] = getdate()  WHERE [id]=@1     
2021-09-27 14:18:19.27 spid21s          frame procname=adhoc line=5 stmtstart=312 stmtend=426 sqlhandle=0x02000000de12790d98b6603d45032658be828f66910b09150000000000000000000000000000000000000000
2021-09-27 14:18:19.27 spid21s     UPDATE invoices SET updated_at = GETDATE() WHERE id = 1;     
2021-09-27 14:18:19.27 spid21s         inputbuf
2021-09-27 14:18:19.27 spid21s     USE dead_lock_lab;
2021-09-27 14:18:19.27 spid21s     BEGIN TRANSACTION
2021-09-27 14:18:19.27 spid21s        UPDATE invoice_items SET qty = qty + 1 WHERE invoice_id = 1 AND item_index = 2;
2021-09-27 14:18:19.27 spid21s        WAITFOR DELAY '00:00:05';
2021-09-27 14:18:19.27 spid21s        UPDATE invoices SET updated_at = GETDATE() WHERE id = 1;
2021-09-27 14:18:19.27 spid21s     ROLLBACK TRANSACTION
2021-09-27 14:18:19.27 spid21s        process id=process177025c38 taskpriority=0 logused=248 waitresource=KEY: 24:72057594039107584 (0207a0a08e23) waittime=2785 ownerId=699992 transactionname=user_transaction lasttranstarted=2021-09-27T14:18:11.260 XDES=0x16c69e3a8 lockMode=X schedulerid=3 kpid=9556 status=suspended spid=57 sbid=0 ecid=0 priority=0 trancount=2 lastbatchstarted=2021-09-27T14:18:11.197 lastbatchcompleted=2021-09-27T14:18:11.193 lastattention=1900-01-01T00:00:00.193 clientapp=Microsoft SQL Server Management Studio - Query hostname=LAPTOP-31OV73CJ hostpid=9856 loginname=sa isolationlevel=read committed (2) xactid=699992 currentdb=24 lockTimeout=4294967295 clientoption1=671090784 clientoption2=390200
2021-09-27 14:18:19.27 spid21s         executionStack
2021-09-27 14:18:19.27 spid21s          frame procname=adhoc line=5 stmtstart=60 sqlhandle=0x02000000a321d51a96bd6796310f017edfd1e35e88b19a830000000000000000000000000000000000000000
2021-09-27 14:18:19.27 spid21s     UPDATE [invoice_items] set [qty] = [qty]+@1  WHERE [invoice_id]=@2 AND [item_index]=@3     
2021-09-27 14:18:19.27 spid21s          frame procname=adhoc line=5 stmtstart=266 stmtend=426 sqlhandle=0x02000000bbfff30000fa1aefcdf9c29bbdab12d288fb78ec0000000000000000000000000000000000000000
2021-09-27 14:18:19.27 spid21s     UPDATE invoice_items SET qty = qty + 1 WHERE invoice_id = 1 AND item_index = 2;     
2021-09-27 14:18:19.27 spid21s         inputbuf
2021-09-27 14:18:19.27 spid21s     USE dead_lock_lab;
2021-09-27 14:18:19.27 spid21s     BEGIN TRANSACTION
2021-09-27 14:18:19.27 spid21s        UPDATE invoices SET updated_at = GETDATE() WHERE id = 1;
2021-09-27 14:18:19.27 spid21s        WAITFOR DELAY '00:00:05';
2021-09-27 14:18:19.27 spid21s        UPDATE invoice_items SET qty = qty + 1 WHERE invoice_id = 1 AND item_index = 2;
2021-09-27 14:18:19.27 spid21s     ROLLBACK TRANSACTION    
2021-09-27 14:18:19.27 spid21s       resource-list
2021-09-27 14:18:19.27 spid21s        keylock hobtid=72057594039042048 dbid=24 objectname=dead_lock_lab.dbo.invoices indexname=1 id=lock16eb57a00 mode=X associatedObjectId=72057594039042048
2021-09-27 14:18:19.27 spid21s         owner-list
2021-09-27 14:18:19.27 spid21s          owner id=process177025c38 mode=X
2021-09-27 14:18:19.27 spid21s         waiter-list
2021-09-27 14:18:19.27 spid21s          waiter id=process17701dc38 mode=X requestType=wait
2021-09-27 14:18:19.27 spid21s        keylock hobtid=72057594039107584 dbid=24 objectname=dead_lock_lab.dbo.invoice_items indexname=1 id=lock173ac8d80 mode=X associatedObjectId=72057594039107584
2021-09-27 14:18:19.27 spid21s         owner-list
2021-09-27 14:18:19.27 spid21s          owner id=process17701dc38 mode=X
2021-09-27 14:18:19.27 spid21s         waiter-list
2021-09-27 14:18:19.27 spid21s          waiter id=process177025c38 mode=X requestType=wait

12. Enable log using sp_BlitzLock


13. query to check

SELECT @@servername as ServerName,xdr.value('@timestamp', 'datetime') AS [Date],
    xdr.query('.') AS [Event_Data]
FROM (SELECT CAST([target_data] AS XML) AS Target_Data
            FROM sys.dm_xe_session_targets AS xt
            INNER JOIN sys.dm_xe_sessions AS xs ON xs.address = xt.event_session_address
            WHERE xs.name = N'system_health'
              AND xt.target_name = N'ring_buffer'
    ) AS XML_Data
CROSS APPLY Target_Data.nodes('RingBufferTarget/event[@name="xml_deadlock_report"]')
AS XEventData(xdr)
ORDER BY [Date] DESC;
 





No comments:

Post a Comment

Popular Posts