Using the Blocked Process Report in SQL Server 2005/2008

Question

Using the Blocked Process Report in SQL Server 2005/2008

Jonathan Kehayias

One Orange Chip

Points: 26778
More actions
October 30, 2008 at 12:12 am

#383264

Comments posted to this topic are about the item Using the Blocked Process Report in SQL Server 2005/2008
Jonathan Kehayias | Principal Consultant | MCM: SQL Server 2008
My Blog | Twitter | MVP Profile
Training | Consulting | Become a SQLskills Insider
Troubleshooting SQL Server: A Guide for Accidental DBAs[/url]

Viewing 15 posts - 1 through 15 (of 27 total)

You must be logged in to reply to this topic. Login to reply

Christopher Yager-432479 SSC Enthusiast Points: 108 More actions · Answer 1

This looks like a good way to track blocking (much more proactive than the monitor window...) but what kind of performance hit will the server take? I have some blocking issues in my production server that I need to resolve but I don't want to add to the problem by running an additional process. I may be answering my own question but I guess any blocking would put more strain on the server anyway so resolving that quickly would be more essential.

Should this trace run all the time?

What about cleaning up the trace file?

Thanks - great article!

Jonathan Kehayias One Orange Chip Points: 26778 More actions · Answer 2

The blocked process monitor is actually piggy backing on the deadlock monitor background thread, which is always running, so impact is very minimal. This is covered in the BOL topic for the option:

http://msdn.microsoft.com/en-us/library/ms181150.aspx

It also states that the reporting is done on a best effort basis, without guarantees for real-time or close to real time.

I don't recommend that you run this, just to have it running. I only use this when I have a need to look for specific blocking, or I suspect blocking to be the cause of a performance degradation.

Anipaul SSC-Insane Points: 24681 More actions · Answer 3

Anipaul

SSC-Insane

Points: 24681

October 30, 2008 at 9:03 am

#891876

Very useful one ...

don.schaeffer Ten Centuries Points: 1195 More actions · Answer 4

I don't know whether to always believe the blocked process report. At times I see lots of purported blocking like this, where one select statement is supposedly blocking another. As you can see, we're using the default isolation level, read committed. ( I altered the hostname and loginname fields, and had to replace the ">" with "]" to get the xml to appear in this post for some reason).

If nothing else, the blocked process report does not tell me how/why one query is blocking another.

<blocked-process-report monitorLoop="1649082"]

<blocked-process]

<process id="process38132e8" taskpriority="0" logused="0" waitresource="PAGE: 17:4:94458" waittime="87078" ownerId="13262486200" transactionname="SELECT" lasttranstarted="2008-12-03T13:23:16.110" XDES="0x4e10c8558" lockMode="S" schedulerid="2" kpid="5372" status="suspended" spid="98" sbid="0" ecid="0" priority="0" transcount="0" lastbatchstarted="2008-12-03T13:23:16.110" lastbatchcompleted="2008-12-03T13:23:16.110" clientapp=".Net SqlClient Data Provider" hostname="xxx" hostpid="7216" loginname="xxx" isolationlevel="read committed (2)" xactid="13262486200" currentdb="17" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128056"]

<executionStack]

<frame line="1" sqlhandle="0x020000003c2fd4171752b341f4fb2e78c4fd25a39d3268cb"/]

<frame line="1" sqlhandle="0x02000000272ffe37c5c986299be2ada0f87a7d86ca14ff81"/]

</executionStack]

<inputbuf]

select count(*) from employees where client_id=11343 and isadmin=1 </inputbuf]

</process]

</blocked-process]

<blocking-process]

<process status="suspended" waitresource="PAGE: 17:4:94458" waittime="100500" spid="161" sbid="0" ecid="0" priority="0" transcount="0" lastbatchstarted="2008-12-03T13:23:02.657" lastbatchcompleted="2008-12-03T13:23:02.657" clientapp=".Net SqlClient Data Provider" hostname="xxx" hostpid="7216" loginname="xxx" isolationlevel="read committed (2)" xactid="13262406360" currentdb="17" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128056"]

<executionStack]

<frame line="1" sqlhandle="0x0200000066da5526607b1b624239a36f488fec861b4ab401"/]

<frame line="1" sqlhandle="0x02000000b4e2201f1eda6c0a562330100b742a51c5d4d9f1"/]

</executionStack]

<inputbuf]

select count(*) from employees where client_id=34273 and isadmin=1 </inputbuf]

</process]

</blocking-process]

</blocked-process-report]

Jonathan Kehayias One Orange Chip Points: 26778 More actions · Answer 5

Don,

Something happened to your report, but all that came through were the select statements. Can you repost the blocked process report?

don.schaeffer Ten Centuries Points: 1195 More actions · Answer 6

Sorry, I edited my post. My xml was getting eaten when I posted so I replace the close ">" with right bracket "]"

Jonathan Kehayias One Orange Chip Points: 26778 More actions · Answer 7

Don,

Have you resolved this, and if not, what is the table/index definition for employees? Is there an index on the clientid column and what is the datatype for that column? Your blocked on a page, so I am guessing that you get lock escalation as a scan is occuring on the clustered index to find the rows that have the respective clientid's and that a index addition to the clientid column would resolve the problem. Can you post the execution plan of one of those statements?

don.schaeffer Ten Centuries Points: 1195 More actions · Answer 8

Jonathan, thanks for looking at this. No, I haven't resolved it.

Client_Id is an integer column; there's an index on it:

CREATE NONCLUSTERED INDEX [Employees_Client_id] ON [dbo].[Employees]

(

[Client_ID] ASC,

[DivID] ASC,

[EmpID] ASC,

[Deleted] ASC

)

The query in question references both Client_Id and the bit column isadmin.

select count(*) from employees where client_id=11343 and isadmin=1

Since isadmin is not part of that index the query performs nested loop lookups of the clustered index. Here's the query plan.

|--Compute Scalar(DEFINE: ([Expr1003]=CONVERT_IMPLICIT(int,[Expr1008],0)))

|--Stream Aggregate(DEFINE: ([Expr1008]=Count(*)))

|--Filter(WHERE: ([phoenix].[dbo].[Employees].[IsAdmin]=(1)))

|--Nested Loops(Inner Join, OUTER REFERENCES: ([phoenix].[dbo].[Employees].[EmpID], [Expr1007]) WITH UNORDERED PREFETCH)

|--Index Seek(OBJECT: ([phoenix].[dbo].[Employees].[Employees_Client_id]), SEEK: ([phoenix].[dbo].[Employees].[Client_ID]=(11343)) ORDERED FORWARD)

|--Clustered Index Seek(OBJECT: ([phoenix].[dbo].[Employees].[PK_Employees]), SEEK: ([phoenix].[dbo].[Employees].[EmpID]=[phoenix].[dbo].[Employees].[EmpID]) LOOKUP ORDERED FORWARD)

I could add isadmin as an included column in the index which might or might not resolve the issue, but more importantly I want to understand just how one select query can block another. I didn't think that could happen. What could be getting locked?

Ken Simmons SSCertifiable Points: 7822 More actions · Answer 9

Ken Simmons

SSCertifiable

Points: 7822

April 1, 2009 at 12:20 pm

#970149

Thanks Jonathan. This one came in handy today.

Wilfred van Dijk SSCrazy Eights Points: 9003 More actions · Answer 10

Which commands and in which order do I have to execute to stop/remove this trace?

Wilfred
The best things in life are the simple things

Jonathan Kehayias One Orange Chip Points: 26778 More actions · Answer 11

You would use sp_trace_setstatus to remove the trace. You'd have to get the traceid from the sys.traces DMV and then you can remove the trace:

-- Find the TraceID for the session in sys.traces

select * from sys.traces

-- Stop and Remove TraceID 2 from the server

exec sp_trace_setstatus 2, 2

rafa.aborges Default port Points: 1430 More actions · Answer 12

I'm monitoring the whole SQL Server environment with the blocked process report.

I'm running this process in background as a job to get the informations.

The problem is that it generated a lot of lines of blocked informations and I'm having issues to parse the information.

Is there any script that I could get only the sqlhandle and the line of the object of the blocked and blocking process? That's all I need.

Anyone can help me?

Thanks

rafa.aborges Default port Points: 1430 More actions · Answer 13

How reliable is the information generated in the blocked process report?

I'm asking that because we let the report on for several days and when we parsed the information, we had some unusual locks, like a table being blocked by another that is not related to the blocking table.

The only reliable information we had was the blocked process.

Does anyone know something related to this?

Thanks in advance

don.schaeffer Ten Centuries Points: 1195 More actions · Answer 14

This script might get what you want:

select

WaitTime = cast( textdata as xml ).value( '/blocked-process-report[1]/blocked-process[1]/process[1]/@waittime','varchar(20)' ),

BlockingQuery = cast( textdata as xml ).value( '(/blocked-process-report/blocking-process/process/inputbuf)[1]','varchar(200)'),

BlockingSpid = cast( textdata as xml ).value( '/blocked-process-report[1]/blocking-process[1]/process[1]/@spid','varchar(20)' ),

BlockingLastBatchStarted = cast( textdata as xml ).value( '/blocked-process-report[1]/blocking-process[1]/process[1]/@lastbatchstarted','varchar(20)' ),

BlockingSQLHandle = cast( textdata as xml ).value( '/blocked-process-report[1]/blocking-process[1]/process[1]/executionStack[1]/frame[1]/@sqlhandle','varchar(50)' ),

BlockingStmtstart = cast( textdata as xml ).value( '/blocked-process-report[1]/blocking-process[1]/process[1]/executionStack[1]/frame[1]/@stmtstart','varchar(50)' ),

BlockingStmtend = cast( textdata as xml ).value( '/blocked-process-report[1]/blocking-process[1]/process[1]/executionStack[1]/frame[1]/@stmtend','varchar(50)' ),

BlockedQuery = cast( textdata as xml ).value( '(/blocked-process-report/blocked-process/process/inputbuf)[1]','varchar(200)'),

BlockedSpid = cast( textdata as xml ).value( '/blocked-process-report[1]/blocked-process[1]/process[1]/@spid','varchar(20)' ),

BlockedLastBatchStarted = cast( textdata as xml ).value( '/blocked-process-report[1]/blocked-process[1]/process[1]/@lastbatchstarted','varchar(20)' ),

BlockedSQLHandle = cast( textdata as xml ).value( '/blocked-process-report[1]/blocked-process[1]/process[1]/executionStack[1]/frame[1]/@sqlhandle','varchar(50)' ),

BlockedStmtstart = cast( textdata as xml ).value( '/blocked-process-report[1]/blocked-process[1]/process[1]/executionStack[1]/frame[1]/@stmtstart','varchar(50)' ),

BlockedStmtend = cast( textdata as xml ).value( '/blocked-process-report[1]/blocked-process[1]/process[1]/executionStack[1]/frame[1]/@stmtend','varchar(50)' )

from dbo.Feb02 t

where eventclass = 137

order by BlockedLastBatchStarted