I was attending a SQL Server event a few weeks back when a
number of DBA types were talking about new features in SQL Server 2005. One of
the topics that came up was how might you monitor execution of stored
procedures. One DBA said it would be nice if he had a method to identify how
many times a stored procedure (SP) was executed. He was looking for some
information to help fine tune his environment and the applications running in
his environment. Or at least identify the processes that where run frequently
so they could be reviewed by developers to determine if they could be written
more efficiently. So what new features in SQL Server 2005 might be used to accomplish
the monitoring of SP executions? Dynamic Management views (DMV) of course. In
this article I will show you how you can use a few DMV’s to identify the most
frequently run SP’s of an instance of SQL Server, as well as those SPs that use
the most CPU, I/O or run the longest.
Execution Statistics
It is relatively easy to identify the use count and resource
usage of your SP’s, but first let me discuss how SQL Server maintains the
execution statistics. The SQL Server engine keeps execution statistics for
each SQL Server 2005 instance. Execution Statistics are an accumulation of execution
information about what has been run since the instances has started. Each time
an instance is stopped and restarted all execution statistics are reset.
Individual execution statistics for an object are tied to cached
execution plans. When a SP is compiled, an execution plan is cached in memory.
These cached execution plans are uniquely identified by a plan_handle. Since
memory is limited, SQL Server from time to time will remove execution plans from
memory, if the cached plan is not being actively used. Therefore the
statistics stored for a particular SP maybe for an accumulation of stats since
SQL Server started, if the SP has only be compiled once. Or, it may only have
statistics for the last few minutes if the SP had recently been compiled.
How to Get the Execution Count of a Stored Procedure?
To determine how many times a stored procedure in the cache
has been executed you need to use a couple of DMV’s and a dynamic management
function (DMF). The plan_handle for the cached plans are used to join together
the DMV’s and retrieve records for a DMF. To get the execution counts for
each cached SPs you can run the following code:
SELECT DB_NAME(st.dbid) DBName
,OBJECT_SCHEMA_NAME(st.objectid,dbid) SchemaName
,OBJECT_NAME(st.objectid,dbid) StoredProcedure
,max(cp.usecounts) Execution_count
FROM sys.dm_exec_cached_plans cp
CROSS APPLY sys.dm_exec_sql_text(cp.plan_handle) st
where DB_NAME(st.dbid) is not null and cp.objtype = ‘proc’
group by cp.plan_handle, DB_NAME(st.dbid),
OBJECT_SCHEMA_NAME(objectid,st.dbid),
OBJECT_NAME(objectid,st.dbid)
order by max(cp.usecounts)
Here I used the plan_handle of the “sys.dm_exec_cached_plans” DMV to obtain the object type. I used the object type to identify stored procedure cached plans. The “usecounts” column of the “sys.dm_exec_cached_plans” DMV identifies the number of times each statement with a cached_plan (or SP) has been executed since the last compilation of the SP, I called this “Execution_count”. I use the plan_handle in conjunction with the CROSS APPLY operator to return the object information (DBName, SchemaName, and ObjectName) using the table-value DMF “sys.dm_exec_sql_text”. The output from this SELECT statement is ordered by the “Execution_count”, so the SP with the most executions will be displayed first.
Determining Which SP is using the Most CPU, I/O, or has the Longest Duration.
Knowing which SPs are frequently executed is useful
information, although from a performance standpoint you might like to know
which SP is consuming the greatest amount of CPU resources. Or possibly you
might be interested in which SP takes the longest to run, or which SP performs
the most physical I/O operations? By modifying the above command, we can
easily answer each one of these questions.
If you want to show the SP that consumes the most CPU resources
you can run the following TSQL command:
SELECT DB_NAME(st.dbid) DBName
,OBJECT_SCHEMA_NAME(st.objectid,dbid) SchemaName
,OBJECT_NAME(st.objectid,dbid) StoredProcedure
,max(cp.usecounts) Execution_count
,sum(qs.total_worker_time) total_cpu_time
,sum(qs.total_worker_time) / (max(cp.usecounts) * 1.0) avg_cpu_timeFROM sys.dm_exec_cached_plans cp join sys.dm_exec_query_stats qs on cp.plan_handle = qs.plan_handle
CROSS APPLY sys.dm_exec_sql_text(cp.plan_handle) st
where DB_NAME(st.dbid) is not null and cp.objtype = ‘proc’
group by DB_NAME(st.dbid),OBJECT_SCHEMA_NAME(objectid,st.dbid), OBJECT_NAME(objectid,st.dbid)
order by sum(qs.total_worker_time) desc
The “sys.dm_exec_query_stats” view contains the column
“total_worker_time”, which is the total number of microseconds that a given
cached query plan has executed. Keep in mind that cached plans are sometimes removed
from memory and replaced with newer ones. Therefore, the statistics for which
SP has consumed the most CPU only takes into account statistics for those plans
that are in the cache when this T-SQL is run.
To determine which SP has executed the most I/O requests you
can run the following TSQL code:
SELECT DB_NAME(st.dbid) DBName
,OBJECT_SCHEMA_NAME(objectid,st.dbid) SchemaName
,OBJECT_NAME(objectid,st.dbid) StoredProcedure
,max(cp.usecounts) execution_count
,sum(qs.total_physical_reads + qs.total_logical_reads + qs.total_logical_writes) total_IO
,sum(qs.total_physical_reads + qs.total_logical_reads + qs.total_logical_writes) / (max(cp.usecounts)) avg_total_IO
,sum(qs.total_physical_reads) total_physical_reads
,sum(qs.total_physical_reads) / (max(cp.usecounts) * 1.0) avg_physical_read
,sum(qs.total_logical_reads) total_logical_reads
,sum(qs.total_logical_reads) / (max(cp.usecounts) * 1.0) avg_logical_read
,sum(qs.total_logical_writes) total_logical_writes
,sum(qs.total_logical_writes) / (max(cp.usecounts) * 1.0) avg_logical_writes
FROM sys.dm_exec_query_stats qs CROSS APPLY sys.dm_exec_sql_text(qs.plan_handle) st
join sys.dm_exec_cached_plans cp on qs.plan_handle = cp.plan_handle
where DB_NAME(st.dbid) is not null and cp.objtype = ‘proc’
group by DB_NAME(st.dbid),OBJECT_SCHEMA_NAME(objectid,st.dbid), OBJECT_NAME(objectid,st.dbid)
order by sum(qs.total_physical_reads + qs.total_logical_reads + qs.total_logical_writes) desc
Here I have displayed the total physical and logical read
I/O’s, plus the logical write I/O’s. In addition, I have calculated the
average number of I/O’s per execution of each SP. Physical reads are the
number of reads that are actually made against the physical disk drives; where
as logical reads and writes are the number of I/O’s against the cached data
pages in memory in the buffer cache. Therefore, by adding the physical and
logical I/O’s together I was able to calculate the total I/O’s for each SP.
To determine which SP’s take the longest time to execute I
can use the follow TSQL code:
SELECT DB_NAME(st.dbid) DBName
,OBJECT_SCHEMA_NAME(objectid,st.dbid) SchemaName
,OBJECT_NAME(objectid,st.dbid) StoredProcedure
,max(cp.usecounts) execution_count
,sum(qs.total_elapsed_time) total_elapsed_time
,sum(qs.total_elapsed_time) / max(cp.usecounts) avg_elapsed_time
FROM sys.dm_exec_query_stats qs CROSS APPLY sys.dm_exec_sql_text(qs.plan_handle) st
join sys.dm_exec_cached_plans cp on qs.plan_handle = cp.plan_handle
where DB_NAME(st.dbid) is not null and cp.objtype = ‘proc’
group by DB_NAME(st.dbid),OBJECT_SCHEMA_NAME(objectid,st.dbid), OBJECT_NAME(objectid,st.dbid)
order by sum(qs.total_elapsed_time) desc
In this TSQL, I am calculating the duration of each SP by
summing up the “total_elapsed_time” in the “sys.dm_exec_sql_query_stats” DMV by
database, schema and object name. I am also calculating the average elapsed
time per execution of each SP. I order the output so the SP that took the
longest total duration will be displayed first. If you where interested in
determining the SP that had the longest average duration all you would need to
change is the “ORDER BY” clause to sort by “avg_elapsed_time”.
Conclusion
The “sys.dm_exec_query_stats” SP is used to look at the
accumulated statistics for cached plans. By joining the “sys.dm_exec_query_stats”
view with other DMV’s, you can determine other information about the cached
plan, like the object type for the cached plan, and the actual name of the
object. Having these DMVs in SQL Server 2005 now provides you with some data
mining tools to review some performance information for a SQL Server instance.
Next time you want to review statistics related to your code run on you SQL
Server box consider looking at the information available in the SQL Server 2005
dynamic management views.
