While in the previous post we talked about finding who's locking our table today i want to show you how to find deadlock!
How many times does the customer call you to tell you that they were all blocked?
Yeah, today let's talk about how to identify deadlocks!
However, we use a method that can trace them in such a way as to avoid being called by the customer when the block occurs.
Enjoy the reading!
Activate trace flags
First of all we need to activate two trace flags through the T-SQL commands below:
DBCC TRACEON (1204,-1)
GO
DBCC TRACEON (1222,-1)
GO
Now deadlocks will be stored in the SQL Server error log
Important: Just remember to disable these trace flag after detected your deadlock.
Remember that in this manner these trace flag are enabled until the SQL Server restart
Where is located the Error Log
You can locate the error log under the SQL Server Agent menu.
Look at the image below:
Now click on the check highlighted below in yellow:
Now "between other informations" you can see also the information related to deadlock.
How to simulate a deadlock
Let’s now take two minutes to see how to simulate a deadlock.
I suggest personally to try these T-SQL command in order to understand how deadlock works
Create our 2 tables:
CREATE TABLE TestTableA(
Code integer,
Descr VARCHAR(100)
,Qty INT
)
CREATE TABLE TestTableB(
Code integer,
Descr VARCHAR(100)
,Qty INT
)
Populate them with some data
INSERT INTO dbo.TestTableA(
Code,
Descr,
Qty
)
VALUES
(1,'TORX T10', 1)
,(2, 'TORX T20', 2)
INSERT INTO dbo.TestTableB(
Code
,Descr
,Qty
)
VALUES
(3,'TORX T30', 2)
,(4, 'TORX T40', 3)
And now execute updates below:
In a first session (open a new windows of the management studio)
BEGIN TRAN
UPDATE dbo.TestTableA SET Qty = 100 WHERE Code = 1
WAITFOR DELAY '00:00:30'
UPDATE dbo.TestTableB SET Qty = 200 WHERE Code = 3
In a second session (open another windows in SSMS)
BEGIN TRAN
WAITFOR DELAY '00:00:10'
UPDATE dbo.TestTableB SET Qty = 300 WHERE Code = 3
UPDATE dbo.TestTableA SET Qty = 400 WHERE Code = 1
We get this error:
(1 riga interessata)
Messaggio 1205, livello 13, stato 45, riga 6
La transazione (ID di processo 61) è stata interrotta a causa di un deadlock delle risorse blocco con un altro processo. Ripetere la transazione.
This is a deadlock!
How to decode the deadlock informations
Below i reported the deadlock generated by the T-SQL commands of the previous paragraph.
Now let's see where to find just some basic but useful informations.
First, note that every lock have the same date for example: "01/28/2020 17:05:38".
Data,Origine,Gravità,Messaggio
01/28/2020 17:05:38,spid23s,Sconosciuta,waiter id=process17b8d047848 mode=U requestType=wait
01/28/2020 17:05:38,spid23s,Sconosciuta,waiter-list
01/28/2020 17:05:38,spid23s,Sconosciuta,owner id=process17b8d047c28 mode=X
01/28/2020 17:05:38,spid23s,Sconosciuta,owner-list
01/28/2020 17:05:38,spid23s,Sconosciuta,ridlock fileid=1 pageid=560856 dbid=24 objectname=SAMA0.dbo.TestTableB id=lock17b34ac3900 mode=X associatedObjectId=72057984635699200
01/28/2020 17:05:38,spid23s,Sconosciuta,waiter id=process17b8d047c28 mode=U requestType=wait
01/28/2020 17:05:38,spid23s,Sconosciuta,waiter-list
01/28/2020 17:05:38,spid23s,Sconosciuta,owner id=process17b8d047848 mode=X
01/28/2020 17:05:38,spid23s,Sconosciuta,owner-list
01/28/2020 17:05:38,spid23s,Sconosciuta,ridlock fileid=1 pageid=552528 dbid=24 objectname=SAMA0.dbo.TestTableA id=lock17b7a358300 mode=X associatedObjectId=72057984635633664
01/28/2020 17:05:38,spid23s,Sconosciuta,resource-list
Here we can read what is the first Query involved in the deadlock
01/28/2020 17:05:38,spid23s,Sconosciuta,UPDATE dbo.TestTableB SET Qty = 200 WHERE Code = 3
01/28/2020 17:05:38,spid23s,Sconosciuta,WAITFOR DELAY '00:00:30'
01/28/2020 17:05:38,spid23s,Sconosciuta,UPDATE dbo.TestTableA SET Qty = 100 WHERE Code = 1
01/28/2020 17:05:38,spid23s,Sconosciuta,BEGIN TRAN
01/28/2020 17:05:38,spid23s,Sconosciuta,inputbuf
01/28/2020 17:05:38,spid23s,Sconosciuta,unknown
01/28/2020 17:05:38,spid23s,Sconosciuta,frame procname=adhoc line=5 stmtstart=190 stmtend=288 sqlhandle=0x020000009dc0853694817179d005df97fe420c91151af1a50000000000000000000000000000000000000000
01/28/2020 17:05:38,spid23s,Sconosciuta,unknown
01/28/2020 17:05:38,spid23s,Sconosciuta,frame procname=adhoc line=5 stmtstart=38 stmtend=150 sqlhandle=0x02000000d54d1620448d72442ea35f826f4168cb3dedcdfc0000000000000000000000000000000000000000
01/28/2020 17:05:38,spid23s,Sconosciuta,executionStack
Here below in blu we can read who is the second Query involved
In red some useful infos:
The process id of the Query
The spid of the process who performed the Query
The name of the application who performed the Query (clientApp)
The name of the host (hostname)
The login name (loginname)
01/28/2020 17:05:38,spid23s,Sconosciuta,
process id=process17b8d047848
taskpriority=0
logused=248
waitresource=RID: 24:1:560856:0
waittime=4690
ownerId=72433616
transactionname=user_transaction lasttranstarted=2020-01-28T17:05:03.470
XDES=0x17b8ddf0490
lockMode=U
schedulerid=6
kpid=92324
status=suspended
spid=59
sbid=0
ecid=0
priority=0
trancount=2
lastbatchstarted=2020-01-28T17:05:03.460 lastbatchcompleted=2020-01-28T17:05:03.457 lastattention=1900-01-01T00:00:00.457
clientapp=Microsoft SQL Server Management Studio - Query hostname=XXXXXX
hostpid=11308
loginname=BOHDE\BiondiL
isolationlevel=read committed (2)
xactid=72433616 currentdb=24
lockTimeout=4294967295
clientoption1=671090784
clientoption2=390200
01/28/2020 17:05:38,spid23s,Sconosciuta,UPDATE dbo.TestTableA SET Qty = 400 WHERE Code = 1
01/28/2020 17:05:38,spid23s,Sconosciuta,UPDATE dbo.TestTableB SET Qty = 300 WHERE Code = 3
01/28/2020 17:05:38,spid23s,Sconosciuta,WAITFOR DELAY '00:00:10'
01/28/2020 17:05:38,spid23s,Sconosciuta,BEGIN TRAN
01/28/2020 17:05:38,spid23s,Sconosciuta,inputbuf
01/28/2020 17:05:38,spid23s,Sconosciuta,unknown
01/28/2020 17:05:38,spid23s,Sconosciuta,frame procname=adhoc line=6 stmtstart=188 stmtend=286 sqlhandle=0x0200000043cda20c74e0f5ba1b8276de9e516513f9eed60b0000000000000000000000000000000000000000
01/28/2020 17:05:38,spid23s,Sconosciuta,unknown
01/28/2020 17:05:38,spid23s,Sconosciuta,frame procname=adhoc line=6 stmtstart=38 stmtend=150 sqlhandle=0x02000000d5c9eb146ddfb3f4519b827e7972019c17de44070000000000000000000000000000000000000000
01/28/2020 17:05:38,spid23s,Sconosciuta,executionStack
01/28/2020 17:05:38,spid23s,Sconosciuta,process id=process17b8d047c28
taskpriority=0
logused=248
waitresource=RID: 24:1:552528:0
waittime=22051
ownerId=72433662
transactionname=user_transaction lasttranstarted=2020-01-28T17:05:06.110
XDES=0x17b0084c490
lockMode=U
schedulerid=6
kpid=105860
status=suspended
spid=61
sbid=0
ecid=0
priority=0
trancount=2
lastbatchstarted=2020-01-28T17:05:06.110 lastbatchcompleted=2020-01-28T17:05:06.107 lastattention=1900-01-01T00:00:00.107
clientapp=Microsoft SQL Server Management Studio - Query hostname=XXXXX
hostpid=11308
loginname=BOHDE\BiondiL
isolationlevel=read committed (2)
xactid=72433662
currentdb=24
lockTimeout=4294967295
clientoption1=671090784
clientoption2=390200
Important: in blu some info about the victim process
01/28/2020 17:05:38,spid23s,Sconosciuta,process-list
01/28/2020 17:05:38,spid23s,Sconosciuta,deadlock victim=process17b8d047c28
01/28/2020 17:05:38,spid23s,Sconosciuta,deadlock-list
01/28/2020 17:05:38,spid5s,Sconosciuta,
ResType:LockOwner
Stype:'OR'
Xdes:0x0000017B0084C490
Mode: U
SPID:61
BatchID:0
ECID:0
TaskProxy:(0x0000017B08882988)
Value:0x872bdb40
Cost:(0/248)
01/28/2020 17:05:38,spid5s,Sconosciuta,Victim Resource Owner:
01/28/2020 17:05:38,spid5s,Sconosciuta,
01/28/2020 17:05:38,spid5s,Sconosciuta,
ResType:LockOwner
Stype:'OR'
Xdes:0x0000017B8DDF0490
Mode: U
SPID:59
BatchID:0
ECID:0
TaskProxy:(0x0000017B7C788988)
Value:0x7dfe1900 Cost:(0/248)
01/28/2020 17:05:38,spid5s,Sconosciuta,Requested by:
01/28/2020 17:05:38,spid5s,Sconosciuta,Input Buf: Language Event: BEGIN TRANWAITFOR DELAY '00:00:10'UPDATE dbo.TestTableB SET Qty = 300 WHERE Code = 3UPDATE dbo.TestTableA SET Qty = 400 WHERE Code = 1
01/28/2020 17:05:38,spid5s,Sconosciuta, SPID: 61 ECID: 0 Statement Type: UPDATE Line #: 6
01/28/2020 17:05:38,spid5s,Sconosciuta,Owner:0x0000017B872B1740 Mode: X Flg:0x40 Ref:0 Life:02000000 SPID:61 ECID:0 XactLockInfo: 0x0000017B0084C4C8
01/28/2020 17:05:38,spid5s,Sconosciuta,Grant List 2:
01/28/2020 17:05:38,spid5s,Sconosciuta,RID: 24:1:560856:0 CleanCnt:2 Mode:X Flags: 0x3
01/28/2020 17:05:38,spid5s,Sconosciuta,Node:2
01/28/2020 17:05:38,spid5s,Sconosciuta,
01/28/2020 17:05:38,spid5s,Sconosciuta,ResType:LockOwner Stype:'OR'Xdes:0x0000017B0084C490 Mode: U SPID:61 BatchID:0 ECID:0 TaskProxy:(0x0000017B08882988) Value:0x872bdb40 Cost:(0/248)
01/28/2020 17:05:38,spid5s,Sconosciuta,Requested by:
01/28/2020 17:05:38,spid5s,Sconosciuta,Input Buf: Language Event: BEGIN TRANUPDATE dbo.TestTableA SET Qty = 100 WHERE Code = 1WAITFOR DELAY '00:00:30'UPDATE dbo.TestTableB SET Qty = 200 WHERE Code = 3
01/28/2020 17:05:38,spid5s,Sconosciuta,SPID: 59 ECID: 0 Statement Type: UPDATE Line #: 5
01/28/2020 17:05:38,spid5s,Sconosciuta,Owner:0x0000017B757B34C0 Mode: X Flg:0x40 Ref:0 Life:02000000 SPID:59 ECID:0 XactLockInfo: 0x0000017B8DDF04C8
01/28/2020 17:05:38,spid5s,Sconosciuta,Grant List 2:
01/28/2020 17:05:38,spid5s,Sconosciuta,RID: 24:1:552528:0 CleanCnt:2 Mode:X Flags: 0x3
01/28/2020 17:05:38,spid5s,Sconosciuta,Node:1
01/28/2020 17:05:38,spid5s,Sconosciuta,
01/28/2020 17:05:38,spid5s,Sconosciuta,Wait-for graph
01/28/2020 17:05:38,spid5s,Sconosciuta,Deadlock encountered .... Printing deadlock information
End of the our deadlock and start of another lock. here ...
01/28/2020 16:26:16,spid10s,Sconosciuta,A significant part of sql server process memory has been paged out. This may result in a performance degradation. Duration: 3613 seconds. Working set (KB): 237792 committed (KB): 774632 memory utilization: 30%.
01/28/2020 15:56:44,spid10s,Sconosciuta,A significant part of sql server process memory has been paged out. This may result in a performance degradation. Duration: 1841 seconds. Working set (KB): 263532 committed (KB): 781032 memory utilization: 33%.
[...]
That all for today.
I hope You enjoy this Post!
Luca Biondi @ SQLServerPerformance blog!
Next post: SQL Server and the Plan Guides, An easy way create and utilize!
Previous post: SQL Server, Why doesn't my update come to an end? a light post!
A song with the mood of the day: Blue (Da Ba Dee)