SQL Server DMV Views might be very helpful. Let’s imagine that you have a couple of nested stored procedures and you find out that it’s slow. It would be nice if you could discover which single query/ies in your procedures causes that it is slow. Few DMV views can tell you that.
Ian W. Stirk wrote whole book about practical use DMV views which is definitely worth to read. I’ve received comment from Ian to one of my post recently which contained helpful piece of advice I would like to share here.
Here is link to his book:
SQL Server DMVs in Action: Better Queries with Dynamic Management Views
He post me query which is using DMV view to basically order part of your stored procedure’s source code from slowest to fastest. After some time of using it I found out that it had really great value for me because it discovered things you couldn’t realize (e.g. that scalar functions are terribly slow).
Core of the query are two views – sys.dm_exec_query_stat and sys.dm_exec_sql_text.
Sys.dm_exec_query_stat query contains performance statistics for each query executed on your SQL Server instance. No rocket science. But it contains even offset which can lead you to exact portion of query which is slow – this means that you can find out statistics for e.g. one SELECT query in your procedure. Sys.dm_exec_sql_text contains source code of executed SQL objects. If you combine those two views together you will find out statistics for each individual part of your stored procedure.
Here is the query:
SELECT CAST(total_elapsed_time / 1000000.0 AS DECIMAL(28, 2)) AS [Total Duration (s)] , CAST(total_worker_time * 100.0 / total_elapsed_time AS DECIMAL(28, 2)) AS [% CPU] , CAST((total_elapsed_time - total_worker_time)* 100.0 / total_elapsed_time AS DECIMAL(28, 2)) AS [% Waiting] , execution_count , CAST(total_elapsed_time / 1000000.0 / execution_count AS DECIMAL(28, 2)) AS [Average Duration (s)] , SUBSTRING (qt.text,(qs.statement_start_offset/2) + 1, ((CASE WHEN qs.statement_end_offset = -1 THEN LEN(CONVERT(NVARCHAR(MAX), qt.text)) * 2 ELSE qs.statement_end_offset END - qs.statement_start_offset)/2) + 1) AS [Individual Query] , SUBSTRING(qt.text,1,100) AS [Parent Query] , DB_NAME(qt.dbid) AS DatabaseName FROM sys.dm_exec_query_stats qs CROSS APPLY sys.dm_exec_sql_text(qs.sql_handle) as qt WHERE total_elapsed_time > 0 ORDER BY total_elapsed_time DESC
There’s one but – I found out these DMV views contain all statistics data from start of your SQL Server Instance. I didn’t find out how to display these statistics only for last query. I always restart SQL Server instance if I don’t want to get mix of slow queries which are not related to last batch I executed. It’s dumb but I didn’t make up better solution. If you know better solution, please share.
Tags: Average, CAST, COUNT, DMV, duration, Microsoft SQL Server, performance statistics, scalar function, SELECT, SQL, SQL Server, SUBSTRING, view, WHERE
Greetings,
There are 2 fields in the sys.dm_exec_query_stats table that may interest you. They are (Creation_Time) and (Last_Execution_Time). You can check these compared to the current time (GetDate() or CURRENT_TIMESTAMP) and subtract a few seconds or even a few minutes to get the last few queries that were processed. Here is a modification of your script.
SELECT
CAST(qs.Total_Elapsed_Time / 1000000.0 AS DECIMAL(28, 2)) AS [Total Duration (s)],
CAST
(
qs.Total_Worker_Time * 100.0 /
(
CASE
WHEN ISNULL(qs.Total_Elapsed_Time, 0.0) = 0.0 THEN 1.0
ELSE qs.Total_Elapsed_Time
END
) AS DECIMAL(28, 2)
) AS [% CPU],
CAST
(
(qs.Total_Elapsed_Time – qs.Total_Worker_Time) *
100.0 /
(
CASE
WHEN ISNULL(qs.Total_Elapsed_Time, 0.0) = 0.0 THEN 1.0
ELSE qs.Total_Elapsed_Time
END
)
AS DECIMAL(28, 2)
) AS [% Waiting],
qs.Execution_Count,
CAST(qs.Total_Elapsed_Time / 1000000.0 / qs.Execution_Count AS DECIMAL(28, 2)) AS [Average Duration (s)],
SUBSTRING
(
qt.Text,
(qs.Statement_Start_Offset / 2) + 1,
(
(
CASE
WHEN qs.Statement_End_Offset = -1 THEN LEN(CONVERT(NVARCHAR(MAX), qt.Text)) * 2
ELSE qs.Statement_End_Offset
END -
qs.Statement_Start_Offset
) /
2
) +
1
) AS [Individual Query],
SUBSTRING(qt.Text, 1, 100) AS [Parent Query],
DB_NAME(qt.DBid) AS DatabaseName,
qs.Creation_Time,
qs.Last_Execution_Time
FROM sys.dm_exec_query_stats AS qs
CROSS APPLY sys.dm_exec_sql_text(qs.sql_handle) AS qt
WHERE
qs.Total_Elapsed_Time > 0
AND
(
qs.Creation_Time >= DATEADD(mm, -10, CURRENT_TIMESTAMP)
OR qs.Last_Execution_Time >= DATEADD(mm, -10, CURRENT_TIMESTAMP)
)
ORDER BY
qs.Total_Elapsed_Time DESC
I had also added a divide by zero check for the Total_Elapsed_Time field. That way you don’t need to filter by it if you want to see the fast executions too.
Thanks for your post.
Terry Steadman
Thanks! Good point. I think that far enought for development server where there is low traffic.
Hi,
I’m glad you liked my query and book…
To answer your question… instead of restarting the server, it is possible to use DMV snapshots (this is described in detail in my book).
In essence you take a snapshot of the relevant DMVs, run the query/batch you want to investigate, take another snapshot of your DMVs, then calculate the delta between the two snapshot.
See the query below.
–ThisRoutineIdentifier
– Do not lock anything, and do not get held up by any locks.
SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED
– Take a pre-work snapshot.
SELECT sql_handle, plan_handle, total_elapsed_time, total_worker_time
, total_logical_reads, total_logical_writes, total_clr_time
, execution_count, statement_start_offset, statement_end_offset
INTO #PreWorkQuerySnapShot
FROM sys.dm_exec_query_stats
– TODO: put your query here!
– Take a post-work snapshot.
SELECT sql_handle, plan_handle, total_elapsed_time, total_worker_time
, total_logical_reads, total_logical_writes, total_clr_time
, execution_count, statement_start_offset, statement_end_offset
INTO #PostWorkQuerySnapShot
FROM sys.dm_exec_query_stats
– Calculate the delta between the snapshots, and order by duration.
SELECT
p2.total_elapsed_time – ISNULL(p1.total_elapsed_time, 0) AS [Duration]
, p2.total_worker_time – ISNULL(p1.total_worker_time, 0) AS [Time on CPU]
, (p2.total_elapsed_time – ISNULL(p1.total_elapsed_time, 0)) -
(p2.total_worker_time – ISNULL(p1.total_worker_time, 0))
AS [Time blocked]
, p2.total_logical_reads – ISNULL(p1.total_logical_reads, 0) AS [Reads]
, p2.total_logical_writes – ISNULL(p1.total_logical_writes, 0)
AS [Writes]
, p2.total_clr_time – ISNULL(p1.total_clr_time, 0) AS [CLR time]
, p2.execution_count – ISNULL(p1.execution_count, 0) AS [Executions]
, SUBSTRING (qt.text,p2.statement_start_offset/2 + 1,
((CASE WHEN p2.statement_end_offset = -1
THEN LEN(CONVERT(NVARCHAR(MAX), qt.text)) * 2
ELSE p2.statement_end_offset
END – p2.statement_start_offset)/2) + 1) AS [Individual Query]
, qt.text AS [Parent Query]
, DB_NAME(qt.dbid) AS DatabaseName
FROM #PreWorkQuerySnapShot p1
RIGHT OUTER JOIN
#PostWorkQuerySnapShot p2 ON p2.sql_handle =
ISNULL(p1.sql_handle, p2.sql_handle)
AND p2.plan_handle = ISNULL(p1.plan_handle, p2.plan_handle)
AND p2.statement_start_offset =
ISNULL(p1.statement_start_offset, p2.statement_start_offset)
AND p2.statement_end_offset =
ISNULL(p1.statement_end_offset, p2.statement_end_offset)
CROSS APPLY sys.dm_exec_sql_text(p2.sql_handle) as qt
WHERE p2.execution_count != ISNULL(p1.execution_count, 0)
AND qt.text NOT LIKE ‘–ThisRoutineIdentifier%’
ORDER BY [Duration] DESC
– Tidy up.
DROP TABLE #PreWorkQuerySnapShot
DROP TABLE #PostWorkQuerySnapShot
Enjoy
Ian
Author: SQL Server DMVs in Action http://www.amazon.com/gp/product/1935182730/
Try this version (the previous one is really for when you call a stored proc). The below one is for inline SQL, note it will also contain metrics for the below sql itself too.
Thanks
Ian
– Do not lock anything, and do not get held up by any locks.
SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED
– Take a pre-work snapshot.
SELECT sql_handle, plan_handle, total_elapsed_time, total_worker_time
, total_logical_reads, total_logical_writes, total_clr_time
, execution_count, statement_start_offset, statement_end_offset
INTO #PreWorkQuerySnapShot
FROM sys.dm_exec_query_stats
– TODO: put your query here!
– Take a post-work snapshot.
SELECT sql_handle, plan_handle, total_elapsed_time, total_worker_time
, total_logical_reads, total_logical_writes, total_clr_time
, execution_count, statement_start_offset, statement_end_offset
INTO #PostWorkQuerySnapShot
FROM sys.dm_exec_query_stats
– Calculate the delta between the snapshots, and order by duration.
SELECT
p2.total_elapsed_time – ISNULL(p1.total_elapsed_time, 0) AS [Duration]
, p2.total_worker_time – ISNULL(p1.total_worker_time, 0) AS [Time on CPU]
, (p2.total_elapsed_time – ISNULL(p1.total_elapsed_time, 0)) -
(p2.total_worker_time – ISNULL(p1.total_worker_time, 0))
AS [Time blocked]
, p2.total_logical_reads – ISNULL(p1.total_logical_reads, 0) AS [Reads]
, p2.total_logical_writes – ISNULL(p1.total_logical_writes, 0) AS [Writes]
, p2.total_clr_time – ISNULL(p1.total_clr_time, 0) AS [CLR time]
, p2.execution_count – ISNULL(p1.execution_count, 0) AS [Executions]
, SUBSTRING (qt.text,p2.statement_start_offset/2 + 1,
((CASE WHEN p2.statement_end_offset = -1
THEN LEN(CONVERT(NVARCHAR(MAX), qt.text)) * 2
ELSE p2.statement_end_offset
END – p2.statement_start_offset)/2) + 1) AS [Individual Query]
, qt.text AS [Parent Query]
, DB_NAME(qt.dbid) AS DatabaseName
FROM #PreWorkQuerySnapShot p1
RIGHT OUTER JOIN
#PostWorkQuerySnapShot p2 ON p2.sql_handle =
ISNULL(p1.sql_handle, p2.sql_handle)
AND p2.plan_handle = ISNULL(p1.plan_handle, p2.plan_handle)
AND p2.statement_start_offset =
ISNULL(p1.statement_start_offset, p2.statement_start_offset)
AND p2.statement_end_offset =
ISNULL(p1.statement_end_offset, p2.statement_end_offset)
CROSS APPLY sys.dm_exec_sql_text(p2.sql_handle) as qt
WHERE p2.execution_count != ISNULL(p1.execution_count, 0)
ORDER BY [Duration] DESC
– Tidy up.
DROP TABLE #PreWorkQuerySnapShot
DROP TABLE #PostWorkQuerySnapShot
Great. I will need it very soon.
SQL can execute queeirs against a database, retrieve,update,insert data from a database and empty refer to an empty result of no rows and NULL refer to a table with one row holding a NULL value.