Deadlock Graphs

A deadlock can appear to be a very obtuse error, as the only advice offered with the error message is an instruction to ‘rerun the transaction’, and there’s no apparent way to find the cause of the deadlock.

There are in fact several ways to get information on what caused the deadlock and on what resources the deadlock occurred. This information is generally referred to as the ‘deadlock graph’

Traceflag 1204

This is the oldest of the ways to get at the deadlock graph and it’s the main way used on SQL 2000. If traceflag 1204 is enabled server-wide, either by adding it as a startup parameter or by using the TraceOn command (DBCC TRACEON(1204,-1)), then anytime the SQL deadlock detector detects and resolves a deadlock, the information on that is written into the SQL Server error log. It looks something like this:

Deadlock encountered …. Printing deadlock information
Wait-for graph

Node:1

OBJECT: 12:629577281:0         CleanCnt:3 Mode:S Flags: 0×1
Grant List 2:
Owner:0x000000008673B900 Mode: S        Flg:0×40 Ref:2 Life:02000000 SPID:52 ECID:0 XactLockInfo: 0x0000000085F64ED0
SPID: 52 ECID: 0 Statement Type: UPDATE Line #: 11
Input Buf: Language Event: exec CauseDeadlock
Requested by:
ResType:LockOwner Stype:’OR’Xdes:0x0000000085F65740 Mode: IX SPID:53 BatchID:0 ECID:0 TaskProxy:(0x0000000085F5C538) Value:0x85b66a00 Cost:(0/0)

Node:2

OBJECT: 12:629577281:0         CleanCnt:3 Mode:S Flags: 0×1
Grant List 2:
Owner:0x00000000867FA180 Mode: S        Flg:0×40 Ref:2 Life:02000000 SPID:53 ECID:0 XactLockInfo: 0x0000000085F65780
SPID: 53 ECID: 0 Statement Type: UPDATE Line #: 11
Input Buf: Language Event: exec CauseDeadlock
Requested by:
ResType:LockOwner Stype:’OR’Xdes:0x0000000085F64E90 Mode: IX SPID:52 BatchID:0 ECID:0 TaskProxy:(0x00000000810B8538) Value:0x85b66a40 Cost:(0/0)

Victim Resource Owner:
ResType:LockOwner Stype:’OR’Xdes:0x0000000085F65740 Mode: IX SPID:53 BatchID:0 ECID:0 TaskProxy:(0x0000000085F5C538) Value:0x85b66a00 Cost:(0/0) 

It’s hard to read, but all the information on what statement finally caused the deadlock and what locks were held and requested is there.

In more recent version of SQL, there are other ways to get at that info, some giving more info, some just giving it in different ways.

Traceflag 1222

Much the same as the previous one, enabling traceflag 1222 server-wide, either as a startup parameter or using the TRACEON command, writes deadlock info into the error log.

TraceFlag 1222 puts far more information into the error log than 1204 did, and as such is preferred over 1204 on SQL 2005 and higher.

deadlock-list
deadlock victim=process4aedb88
process-list
process id=process4aedb88 taskpriority=0 logused=0 waitresource=OBJECT: 12:629577281:0 waittime=4370 ownerId=7679 transactionname=user_transaction lasttranstarted=2008-09-16T20:16:58.470 XDES=0x80692e90 lockMode=IX schedulerid=4 kpid=4460 status=suspended spid=51 sbid=0 ecid=0 priority=0 trancount=3 lastbatchstarted=2008-09-16T21:26:27.507 lastbatchcompleted=2008-09-16T20:17:03.160 lastattention=2008-09-16T20:16:59.430 clientapp=Microsoft SQL Server Management Studio – Query hostname=MYRLIN hostpid=4328 loginname=AVALON\Gail isolationlevel=repeatable read (3) xactid=7679 currentdb=12 lockTimeout=4294967295 clientoption1=671090784 clientoption2=390200
executionStack
frame procname=Testing.dbo.CauseDeadlock line=11 stmtstart=330 stmtend=470 sqlhandle=0x03000c00a54369232632d600169b00000100000000000000
update LargeTable Set SomeString = ‘hys’ where SomeString like ‘a%’
frame procname=adhoc line=1 sqlhandle=0x01000c00e5ffdf06d08a0e80000000000000000000000000
exec CauseDeadlock
inputbuf
exec CauseDeadlock
process id=process806fce08 taskpriority=0 logused=0 waitresource=OBJECT: 12:629577281:0 waittime=3213 ownerId=19635 transactionname=user_transaction lasttranstarted=2008-09-16T21:26:23.457 XDES=0x84e09970 lockMode=IX schedulerid=4 kpid=2016 status=suspended spid=52 sbid=0 ecid=0 priority=0 trancount=2 lastbatchstarted=2008-09-16T21:26:23.457 lastbatchcompleted=2008-09-16T21:26:20.057 clientapp=Microsoft SQL Server Management Studio – Query hostname=MYRLIN hostpid=4328 loginname=AVALON\Gail isolationlevel=repeatable read (3) xactid=19635 currentdb=12 lockTimeout=4294967295 clientoption1=671090784 clientoption2=390200
executionStack
frame procname=Testing.dbo.CauseDeadlock line=11 stmtstart=330 stmtend=470 sqlhandle=0x03000c00a54369232632d600169b00000100000000000000
update LargeTable Set SomeString = ‘hys’ where SomeString like ‘a%’
frame procname=adhoc line=1 sqlhandle=0x01000c00bf7e3f20a0890e80000000000000000000000000
exec CauseDeadlock
inputbuf
exec CauseDeadlock
resource-list
objectlock lockPartition=0 objid=629577281 subresource=FULL dbid=12 objectname=Testing.dbo.LargeTable id=lock80106f00 mode=S associatedObjectId=629577281
owner-list
owner id=process806fce08 mode=S
waiter-list
waiter id=process4aedb88 mode=IX requestType=convert
objectlock lockPartition=0 objid=629577281 subresource=FULL dbid=12 objectname=Testing.dbo.LargeTable id=lock80106f00 mode=S associatedObjectId=629577281
owner-list
owner id=process4aedb88 mode=S
waiter-list
waiter id=process806fce08 mode=IX requestType=convert

There’s a lot more info in there than in the output via traceflag 1204, including the SQL handles (useful for extracting info via the sys.dm_exec_sql_text DMV), the isolation level, the times of the batches, the client app, hostname and login name.

Profiler

The other way to get deadlock info, especially if the deadlock can be reproduced on demand, is to use SQL Profiler and capture the deadlock graph event (new in SQL 2005). In older versions of SQL, the deadlock chain event can be used, but it’s a little obtuse.

When profiler records a deadlock graph event, it can write out a deadlock file (.xdl) which can be opened in management studio and examined. The graphs produced look something like this:

I tend to prefer the output of traceflag 1222 when working with deadlocks. all the information is there and is easy to see and copy

12 Responses to “Deadlock Graphs”

  1. Hi,

    Nice article..rather nice articles :)

    I tried the DBCC TRACEON(1204,-1).
    I added it on the query analyzer as first stmt and after that on the same connection(Query analyzer window) i created a deadlock and made that process crash.
    My errorlog just has this info

    ‘DBCC TRACEON 1204, server process ID (SPID) 55′

    Thats it and Not all the useful info you have mentioned.
    Is there anyother way i need to see the error log. I am seeing if from EM( also checked C:\Program Files\Microsoft SQL Server\MSSQL\LOG folder) no luck..

    Please help where can i see the deadlock graph as i need it badly..thanks in advance..

    Does it have to do anythng with SQL versions?
    I use sql2000 developer version..

  2. That should be enough. It’s all that I used to do on SQL 2000.

    How did you create a deadlock? Did you get the error message (in query analyser) saying that a deadlock had been detected and your process picked as the victim?

  3. Thanks for your reply.

    Yes I did get the error. Let me briefly explain how i mananged to create the deadlock.

    t1,t2 are my tables with a single column called id
    On the first query analyzer I had the following script
    **************************
    dbcc traceon(1204,-1)
    begin tran
    update t2 set id = 50 where id = 5
    select * from t1
    commit
    ********************
    I executed first 3 stmts that is till ‘update’

    2nd qry window had the following
    **************************************

    dbcc traceon(1204,-1)
    begin tran
    update t1 set id = 50 where id = 5
    select * from t2
    commit

    ******************************************

    Again executed till update.

    Then Executed the select in Query analyzer 1
    Executed the select in query analyzer 2.

    Got the error in one of the windows
    ‘Transaction (Process ID 52) was deadlocked on {lock} resources with another process and has been chosen as the deadlock victim. Rerun the transaction.’

    I guess i am missing something. Please let me know.

    Again thanks a million for your efforts :)

  4. Try enabling the traceflag in a separate window, before doing the updates.

    The -1 parameter means the flag is enabled globally (for all sessions), so there’s no need to do it in both and, in fact no point, as it’s the system spids that detect deadlocks and generate the graph, not your user connections

  5. Hi,

    It worked..Thanks a million :)
    Sorry for the late reply..

    Regards,
    Raj

  6. Gila,

    Thank you for the aticle.I have been using 1222 for a while now,but i do not know how to make use of the sqlhandle being displayed.How do i make use of it to see more details?Do I run something like select * from sys.dm_exec_sql_text (sql_handle)?

  7. You can run that. It’ll only show results if the plan for that query is still in cache. If not then the sql_handle’s fairly useless and you’ll have to go on what pieces of the query are shown in the deadlock graph.

  8. Hi Gail -
    How does the dumping of the information influence performance? if any?
    I manage a few critical SQL servers, and we dont enable anything that could potentially put strain on the servers.

    Please Advise…

  9. I haven’t seen a performance degradation from these and I used to work on a very busy, very critical trading system that had traceflag 1204 enabled permanently. I’d say unless you’re having multiple deadlocks a sec there shouldn’t be an impact. If you are having multiple deadlocks a sec, then I would suggest there’s a bigger problem at hand.

  10. [...] of the suggestions in my deadlocks presentation is to sanitize the deadlock graph and then reach out to the SQL Server community (by way of forum of newsgroup) or send the graph to [...]

  11. Thanks Gail, this is answer to question that I was brewing in my head for a long time. Now time to convince DBAs to enable 1222 on our prod system :)

  12. Gail,

    Read your deadlock article in Deep Dives.

    Nice.

    Very lucid and focused.

    Mike

Leave a Reply