Friday, February 6, 2009

SQL Server Leveraging dm_exec_requests to Find Running Statement and Blocking

The sys.dm_exec_requests is one of the most significant DMV’s added to 2005. The reason is because it’s what’s happenning at this moment, where sys.dm_exec_sessions or sys.sysprocesses is session based or since the session was started. When your working with connection pooling this really doesn’t help you. One technique I love to use is finding out what statement is running for a long time and why. In past this required grabbing a session id, then pumping into dbcc inputbuffer. The query below grabs this info all within one statement.

With RequestResults
as
(
select * from sys.dm_exec_requests r
Cross apply
sys.dm_exec_sql_text(r.sql_handle)
)
--select * from RequestResults where session_id > 54

select text,Session_id, Start_time,status, database_id, blocking_session_id,
wait_type, wait_time,open_transaction_count,cpu_time, reads, writes,logical_reads
from RequestResults
where session_id > 54

All these fields can give you insight into what’s happenning within your system. For example open up two tabs in ssms, in the first run the following command.

Create table t1
(pkint int not null identity(1,1),
DTEField datetime,
Filler varchar(10))

While 1 = 1
Begin
insert into t1(dteField, Filler) (select dtefield, filler from t1)
end

In the second tab use the DMV query above to find out what’s going on. Very straight forward. If you do this a few times, you’ll notice that reads, writes, cpu time isn’t culmulative, so you get a snapshot into time. One of the areas I find this is great is during long processes whether it be ETL or a job. You’ll often notice a process that’s supposed to take 4 hrs is now taking 6 hrs into the run. What differs in this situation between this and a trace is the trace requires you to catch the results after completion, while this is real-time.

You can also use this view for catching blocking. Open up two more tabs in the first run the following query which will leave a transaction open.

begin tran
update t1 set filler = 'Hello'
waitfor Delay '00:00:20'

In the second run a select all
Select * from t1

Then go back and run your DMV from above you’ll not only be able catch the 2nd query is being blocked, but the statement that is blocking.


Unfortunately one time queries usually don’t tell the story, rather you need to catch historical time. Historical time to me gathering information over and hour period. The following loops kicks off every minute for an hour, and will allow for better trending.


Create table HoldRequests(
querytext varchar(max),
Session_id int,
Start_time datetime,
status varchar(50),
database_id int,
blocking_session_id int,
wait_type int,
wait_time bigint,
open_transaction_count int,
cpu_time bigint,
reads int,
writes int,
logical_reads int)

Declare @interval int
set @interval = 0
While @interval <>
Begin
With RequestResults
as
(
select * from sys.dm_exec_requests r
Cross apply
sys.dm_exec_sql_text(r.sql_handle)
)
--select * from RequestResults where session_id > 54
insert into HoldRequests
select text,Session_id, Start_time,status, database_id, blocking_session_id,
wait_type, wait_time,open_transaction_count,cpu_time, reads, writes,logical_reads
from RequestResults
where session_id > 54
set @interval = @interval + 1
waitfor delay '00:01:00'
end


Of course the loop is only there for demonstration purposes rather then having your cpu spinning on a waitfor command, its best to use SQL Server Agent to schedule the job

No comments: