Tracing deadlocks - SQL Server Forums

Please start any new threads on our new site at https://forums.sqlteam.com. We've got lots of great SQL Server experts to answer whatever question you can come up with.

All Forums

Old Forums

CLOSED - General SQL Server

Tracing deadlocks

Author

Topic

beyonder422
Posting Yak Master

124 Posts

Posted - 2005-05-12 : 11:48:14

Anyone have a good url or sample code or whatever of a good way to set-up a trace to ID deadlocks and the spid actually causing the deadlock?

TG
Master Smack Fu Yak Hacker

6065 Posts

Posted - 2005-05-12 : 12:13:51

Here is a simple thing that you can let run while you believe blocking is going on (prior to deadlocks). From another window, select * from ##BlockInfo with (nolock)


If Object_ID('tempdb.dbo.##blockinfo') > 0
	drop table ##blockInfo

create table ##blockInfo (blockedCmd nVarChar(32), blockedSpid int, blockedByCmd nVarChar(32), blockedBySpid int, BlockTime dateTime)
set nocount on
while 1=1
Begin
	insert ##blockInfo (blockedCmd, blockedSpid, blockedByCmd, blockedBySpid, blockTime)
	Select	blocked.cmd [blockedCmd]
		,blocked.spid [blockedSpid]
		,blockedBy.cmd [blockedByCmd]
		,blockedBy.spid [blockedBySpid]
		,getDate()
	From	Master.dbo.sysProcesses blocked with (nolock) 
	JOIN	Master.dbo.sysProcesses blockedBy with (nolock) 
		ON blocked.blocked = blockedBy.spid
	Where	blocked.blocked > 0

	waitfor delay '00:00:00.500'
End

Be One with the Optimizer
TG

nitin1353
Constraint Violating Yak Guru

381 Posts

Posted - 2005-05-12 : 12:19:05

Hi
i am sending you the information which will be very useful in tracing the deadlocks.

Please go through this.

--Chan

Summary:
New Author! Deadlocks aren't the most common problem but they happen they can really degrade performance.

The article here is to identify and track the source for the cause of deadlock. Typically in a system integration solution you wouldn’t encounter deadlock in your testing. This deadlock might creep in production or in live phase as your solution talks to different systems, which is connected, live with users. In a production environment turning the profiler and searching for the deadlock on is really painful and moreover the performance is also affected to a small extent.

Here are the steps to identify the source for the deadlock:

Enable the Trace flag 3604 followed by 1204. The trace flag 3604 is not documented in SQL 2K books online. This option sends the trace to the client.
The trace flag 1204 returns the type of locks participating in the deadlock and the current command affected. The deadlock information is automatically sent to the error log
DBCC TRACEON (3604)
DBCC TRACEON (1204)
Now any deadlocks happening in SQL server will be logged into the error log file, ERRORLOG. You can access the file either through enterprise manager or through explorer. In enterprise manager you can see it under Management / SQL Server Logs or under <Drive:>\\Program Files\Microsoft SQL Server\MSSQL\LOG.

The deadlock information appears in the file as

Deadlock encountered.... Printing deadlock information

2004-02-28 09:31:20.86 spid4

2004-02-28 09:31:20.86 spid4 Wait-for graph

2004-02-28 09:31:20.86 spid4

2004-02-28 09:31:20.86 spid4 Node:1

2004-02-28 09:31:20.86 spid4 RID: 7:1:35443:0 CleanCnt:1 Mode: U Flags: 0x2

2004-02-28 09:31:20.86 spid4 Grant List 0::

2004-02-28 09:31:20.86 spid4 Owner:0x5c53dfa0 Mode: U Flg:0x0 Ref:0 Life:00000001 SPID:61 ECID:0

2004-02-28 09:31:20.86 spid4 SPID: 61 ECID: 0 Statement Type: UPDATE Line #: 167

2004-02-28 09:31:20.86 spid4 Input Buf: Language Event: Sproc_TPS_Reports

2004-02-28 09:31:20.86 spid4 Requested By:

2004-02-28 09:31:20.86 spid4 ResType:LockOwner Stype:'OR' Mode: U SPID:58 ECID:0 Ec:(0x6EF235F8) Value:0x658cb560 Cost:(0/297FC)

2004-02-28 09-: 31:20.86 spid4

2004-02-28 09:31:20.86 spid4 Node:2

2004-02-28 09:31:20.86 spid4 RID: 7:1:76320:0 CleanCnt:1 Mode: X Flags: 0x2

2004-02-28 09:31:20.86 spid4 Grant List 1::

2004-02-28 09:31:20.86 spid4 Owner:0xdabf560 Mode: X Flg:0x0 Ref:0 Life:02000000 SPID:58 ECID:0

2004-02-28 09:31:20.86 spid4 SPID: 58 ECID: 0 Statement Type: DELETE Line #: 158

2004-02-28 09:31:20.86 spid4 Input Buf: Language Event: EXEC Sproc_TPS_CaptureMissingEvent

2004-02-28 09:31:20.86 spid4 Requested By:

2004-02-28 09:31:20.86 spid4 ResType:LockOwner Stype:'OR' Mode: U SPID:61 ECID:0 Ec:(0x5A507578) Value:0x8c32720 Cost:(0/0)

2004-02-28 09:31:20.86 spid4 Victim Resource Owner:

2004-02-28 09:31:20.86 spid4 ResType:LockOwner Stype:'OR' Mode: U SPID:61 ECID:0 Ec:(0x5A507578) Value:0x8c32720 Cost:(0/0)

Let’s analyze the log file. In the above case 2 nodes were involved in deadlock. Node :1 belongs to SPID :61 and Node :2 belongs to SPID :58. To know the source query that was under execution during deadlock, can be found from the input buffer. This line can be found from the line starting with “input Buf:” For Node:1 its “Sproc_TPS_reports” and for Node :2 its “Sproc_TPS_CaptureMissingEvent”.

Now that we know the query source we need to know what was the statement and the line no# that caused the deadlock. This can be retrieved from “Statement Type” present just above the “Input Buf” statement. In this case its “Update Line #167” for SPID:61 and “Delete Line #158” for SPID : 58.

Now that you know the line no# , you can attack the query to optimize it for avoiding deadlock. The problem lies if there are multiple calls to stored procedure within this stored procedure Sproc_TPS_Reports or Sproc_TPS_CaptureMissingEvent? Then this line no # and statement type can’t say much to pinpoint the object involved in the deadlock. The next step is to look at the line next to “Node :1” or “Node :2”. In the this example its RID: X: X: X: X. The RID indicates that the data is fetched from heap directly and it’s a row lock. The The SQL server can lock on the following items

Items Description
RID
is a row identifier. It is used to individually lock a single row within a table.

The format is RID: db_id:file_id:page_no:row_no

Key
is a row lock within an index. Used to protect key ranges in serializable transactions

The format is KEY: db_id:object_id:index_id;

Page
is a lock, when entire 8-KB data page or index page will be locked.

The format is PAG: db_id:file_id:page_no

Extent
is only used for allocation. When it's used, entire extent will be locked

The format is EXT: db_id:file_id:extent_no

Table
lock is used when a large percentage of the table's rows are queried or updated. This lock includes all table's data and indexes

The format is TAB: db_id:object_id;

Database
is used when you restore the database.

The format is DB: db_id

From the above table its clear that except for Extent and Database Items you can trace the deadlock object with ease. Anyways extent and database will not be encountered in your custom code stored procedure. Other than the extent and database, key and table have the object_id in it. So by just executing the query "select object_name(<object_id>)". You can determine the object name easily. For other lock items RID and page you can determine the object name from the Page_no. This can be determined through an undocumented DBCC command DBCC PAGE. The syntax for this is:

DBCC PAGE ({db_id|dbname}, pagenum [,print option] [,cache] [,logical])

where:

db_id|dbname - Enter either the dbid or the name of the database

pagenum - Enter the page number of the SQL Server page that is to be examined

print option - (Optional) Print option can be either 0, 1, or 2

0 - (Default) This option causes DBCC PAGE to print out only the page header information.

1 - This option causes DBCC PAGE to print out the page header information, each row of information from the page, and the page's offset table. Each of the rows printed out will be separated from each other.

2 - This option is the same as option 1, except it prints the page rows as a single block of information rather than separating the individual rows. The offset and header will also be displayed.

cache - (Optional) This parameter allows either a 1 or a 0 to be entered

0 - This option causes DBCC PAGE to retrieve the page number from disk rather than checking to see if it is in cache.

1 - (Default) This option takes the page from cache if it is in cache rather than getting it from disk only.

logical - (Optional) This parameter is for use if the page number that is to be retrieved is a virtual page rather then a logical page. It can be either 0 or 1.

0 - If the page is to be a virtual page number.

1 - (Default) If the page is the logical page number.

So just pass the parameter that you get from RID / Page Lock items. In the above case it would be DBCC Page(7,1,35443,3)

The output for this will appear in client as below. For ease in understanding, only the portion that is of interest is copied here.

PAGE: (1:35443)

---------------

BUFFER:

-------

BUF @0x0196D440

---------------

bpage = 0x7BA22000 bhash = 0x00000000 bpageno = (1:35443)

bdbid = 7 breferences = 0 bstat = 0x9

bspin = 0 bnext = 0x00000000

PAGE HEADER:

------------

Page @0x7BA22000

----------------

m_pageId = (1:35443) m_headerVersion = 1 m_type = 1

m_typeFlagBits = 0x0 m_level = 0 m_flagBits = 0x0

m_objId = 2029457433 m_indexId = 0 m_prevPage = (1:37670)

m_nextPage = (1:106590) pminlen = 5 m_slotCnt = 8

m_freeCnt = 7408 m_freeData = 7996 m_reservedCnt = 0

m_lsn = (77495:484:39) m_xactReserved = 0 m_xdesId = (0:9175698)

m_ghostRecCnt = 0 m_tornBits = 0

of all these info , the data of m_objID is of interest( which is highlighted in bold). The value is 2029457433. Now that you know the object ID you can determine the object name by executing the query

SELECT object_name(2029457433)

Now that you have traced the source, you can work out to find the solution for avoiding the deadlock.

nitin1353
Constraint Violating Yak Guru

381 Posts

Posted - 2005-05-12 : 12:19:36

beyonder422
Posting Yak Master

124 Posts

Posted - 2005-05-12 : 12:48:13

DBCC TRACEON (3605,1204,-1)

From what I've gathered this is the best way to trace deadlocks (ie. actual deadlock alert, action/dbo-call causing deadlock, and possibly specific line within dbo-call causing deadlock).

I was hoping I could use minimal tracing filters, but those wouldn't give me as much info as the above.

Specifically, what is causing deadlock and any clue about identifying what line of code is causing deadlock.

Is the resource impact great?

nitin1353
Constraint Violating Yak Guru

381 Posts

Posted - 2005-05-12 : 13:18:24

Hi
if you read the article which i have send carefully you will find that you will be able to find the statement also which is causing the deadlock.
Regards
Nitin

beyonder422
Posting Yak Master

124 Posts

Posted - 2005-05-12 : 14:33:20

Nitin,

Yes I see that I can identify the line of code. This is exactly what i am looking for.

I was just curious if there is any other way to do it (ie. through code or trace), that would give me as much detail.

Thanx for the input.

Crito
Starting Member

40 Posts

Posted - 2005-05-12 : 17:33:37

So is it 3604 or 3605 or do they both do same thing?

jen
Master Smack Fu Yak Hacker

4110 Posts

Posted - 2005-05-12 : 22:48:14

this is great, thanks for sharing this nitin

--------------------
keeping it simple...

nitin1353
Constraint Violating Yak Guru

381 Posts

Posted - 2005-05-13 : 14:09:41

Hi all.
thanks.just wanted to tell you guyz that i am facing major problems with deadlock so i searched this article which i sent you.Enjoy

Regards
nitin
P.s: this is a great forum

nitin1353
Constraint Violating Yak Guru

381 Posts

Posted - 2005-05-13 : 14:12:47

Hi crito
it is 3604 .i guess .this is what i did.

Subscribe to SQLTeam.com

SQLTeam.com Articles via RSS

SQLTeam.com Weblog via RSS

- Advertisement -

Resources