Stored Procedure Execution Count and Average Elapsed Time

Stored procedure execution count comes from one view: sys.dm_exec_procedure_stats. It holds a row for every cached procedure plan, with the number of runs and the time they took. A short query turns it into a list of the busiest and slowest procedures.

What the View Reports

SQL Server keeps statistics for each stored procedure while its plan sits in the plan cache. Each row carries the execution count, the total elapsed time, the total CPU time and the logical reads. The times are in microseconds, so divide by 1000.0 to get milliseconds.

The view holds only what is in the cache. That limit matters for every number below, and a later section returns to it.

Build the Demo

The demo creates a database named ProcStatsDemo with a three-row table and two procedures. One is quick. The other waits 200 milliseconds before it reads the table, so the two have clearly different average times. Run it on a test server.

IF DB_ID(N'ProcStatsDemo') IS NULL CREATE DATABASE ProcStatsDemo;
GO
USE ProcStatsDemo;
GO
DROP TABLE IF EXISTS dbo.Orders;
CREATE TABLE dbo.Orders (OrderID int IDENTITY(1,1) PRIMARY KEY, Customer nvarchar(40) NOT NULL, Amount decimal(10,2) NOT NULL);
INSERT INTO dbo.Orders (Customer, Amount) VALUES (N'Maya', 40.00), (N'Noah', 25.50), (N'Priya', 61.25);
GO
CREATE OR ALTER PROCEDURE dbo.GetOrderTotal
AS
SELECT SUM(Amount) AS TotalAmount FROM dbo.Orders;
GO
CREATE OR ALTER PROCEDURE dbo.BuildOrderReport
AS
WAITFOR DELAY '00:00:00.200';
SELECT Customer, Amount FROM dbo.Orders ORDER BY Amount DESC;
GO
EXEC dbo.GetOrderTotal;
EXEC dbo.GetOrderTotal;
EXEC dbo.GetOrderTotal;
EXEC dbo.GetOrderTotal;
EXEC dbo.GetOrderTotal;
EXEC dbo.BuildOrderReport;
EXEC dbo.BuildOrderReport;

CREATE OR ALTER needs SQL Server 2016 SP1 or later. On an older version, use CREATE PROCEDURE and drop the procedure first.

Read the Execution Count and Average Elapsed Time

The query divides the totals by the execution count. The WHERE clause keeps the list to the current database, because the view covers the whole instance. ORDER BY puts the slowest average first.

SELECT OBJECT_NAME(ps.object_id, ps.database_id) AS ProcedureName,
       ps.execution_count AS ExecutionCount,
       CAST(ps.total_elapsed_time / ps.execution_count / 1000.0 AS decimal(10,2)) AS AvgElapsedMs,
       ps.cached_time AS CachedTime
FROM sys.dm_exec_procedure_stats AS ps
WHERE ps.database_id = DB_ID()
ORDER BY AvgElapsedMs DESC;

The counts are exact. The times differ on every run, so yours will not match these. BuildOrderReport averages about 200 milliseconds, because of its wait. GetOrderTotal averages a small fraction of a millisecond.

A slow average doesn’t always mean a costly procedure. A fast procedure that runs a million times can cost more than a slow one that runs twice. To find what costs the most overall, sort by the total instead.

SELECT TOP (5) OBJECT_NAME(ps.object_id, ps.database_id) AS ProcedureName,
       ps.execution_count AS ExecutionCount,
       ps.total_elapsed_time / 1000 AS TotalElapsedMs
FROM sys.dm_exec_procedure_stats AS ps
WHERE ps.database_id = DB_ID()
ORDER BY ps.total_elapsed_time DESC;

BuildOrderReport comes first, because two waits of 200 milliseconds outweigh five instant calls. On a real server, this list shows where the elapsed time goes. Start tuning at the top.

Why the Name Comes From Two Arguments

A common slip is calling OBJECT_NAME with one argument. That form looks in the current database only. When you run the query from another database, the name comes back NULL. The second argument fixes it. Compare the two columns from the master database.

USE master;
GO
SELECT OBJECT_NAME(ps.object_id) AS WithoutDatabaseId,
       OBJECT_NAME(ps.object_id, ps.database_id) AS WithDatabaseId,
       ps.execution_count
FROM sys.dm_exec_procedure_stats AS ps
WHERE ps.database_id = DB_ID(N'ProcStatsDemo')
ORDER BY ps.execution_count DESC;

Counted Since the Plan Was Cached

The old advice said the numbers cover the time since the last restart. That is not accurate. The stored procedure execution count starts when the current plan was cached, and the CachedTime column shows when. A restart clears the cache, so it resets everything. So do these events: ALTER PROCEDURE, a recompile, memory pressure that evicts the plan, and clearing the cache.

Change one procedure and look again. The altered procedure loses its row, and the other keeps its row.

USE ProcStatsDemo;
GO
ALTER PROCEDURE dbo.GetOrderTotal
AS
SELECT SUM(Amount) AS TotalAmount, COUNT(*) AS OrderCount FROM dbo.Orders;
GO
SELECT OBJECT_NAME(object_id, database_id) AS ProcedureName, execution_count
FROM sys.dm_exec_procedure_stats
WHERE database_id = DB_ID();

GetOrderTotal returns after its next call, with a count of 1. The five earlier calls are gone from the view. The same happens when you clear the plan cache for the database, which leaves no rows at all. That makes every query in the database compile again, so run it on a test server.

ALTER DATABASE SCOPED CONFIGURATION CLEAR PROCEDURE_CACHE;
SELECT COUNT(*) AS StatsRows FROM sys.dm_exec_procedure_stats WHERE database_id = DB_ID();

When This View Misleads

You could argue that these numbers can’t be trusted. There is some truth in that. A procedure evicted an hour ago looks as if it never ran. A plan cached ten minutes ago holds only ten minutes of history.

Read CachedTime first, and trust the counts only when the plan has been cached for a full business cycle. For history that survives restarts, turn on Query Store. It stores runtime statistics inside the database. Triggers and functions have their own views, sys.dm_exec_trigger_stats and sys.dm_exec_function_stats. The view also leaves out procedures created WITH RECOMPILE, which never keep a cached plan. Natively compiled procedures appear only when their statistics collection is switched on.

Keep a History

Save the result into a table every hour. The history then outlives a cache clear. The difference between two snapshots shows the runs in between. A count that drops between snapshots tells you the plan was evicted or recompiled.

What to Remember

Divide the total elapsed time by the execution count, convert microseconds to milliseconds, and pass both arguments to OBJECT_NAME. Read the stored procedure execution count together with CachedTime before you act on it. Sort by average to find slow procedures, and by total to find expensive ones.

When you finish testing, drop the example database.

USE master;
GO
ALTER DATABASE ProcStatsDemo SET SINGLE_USER WITH ROLLBACK IMMEDIATE;
DROP DATABASE ProcStatsDemo;

A procedure counter is not a lifetime total, it is a diary that restarts when the plan leaves.

Published by Pinal Dave on SQLAuthority. More of my work at pinaldave.com.