Slowest Cached Queries in SQL Server: Time, Reads and Plan

To find the slowest cached queries in SQL Server, rank each statement by its average elapsed time. Keep its plan beside it. The numbers come from the plan cache, so they cover only what is cached. They are quick to read, and they point straight at the statement to open first.

What the Plan Cache Remembers

The view sys.dm_exec_query_stats keeps one row for every statement of every cached plan. Each row holds the execution count and the total, last and maximum elapsed time. It also holds the CPU time and the reads. All times are in microseconds, and a row goes away when its plan leaves the cache. A restart empties the view, and so does a recompile. Query Store keeps similar numbers inside the database and survives a restart, but the cache is there without any setup.

Reading it needs the VIEW SERVER STATE permission, or VIEW SERVER PERFORMANCE STATE on SQL Server 2022 and later. The demo builds a small workload with a known shape. You see the ranking before you point the query at your own server. The query below fetches each plan only for the ten rows that win. Fetching it for every cached statement is slow on a large cache.

Build a Workload

The demo database is SlowStatementDemo. It holds one table of 5,000 rows and three procedures. The two big ones join the first rows of the table to themselves. The number of rows sets the cost. The third procedure is a plain lookup. Run it on a test server.

IF DB_ID(N'SlowStatementDemo') IS NULL CREATE DATABASE SlowStatementDemo;
GO
USE SlowStatementDemo;
GO
DROP PROCEDURE IF EXISTS dbo.usp_NightlyReport;
DROP PROCEDURE IF EXISTS dbo.usp_Dashboard;
DROP PROCEDURE IF EXISTS dbo.usp_SeedLookup;
DROP TABLE IF EXISTS dbo.Seeds;
CREATE TABLE dbo.Seeds (SeedID int NOT NULL CONSTRAINT PK_Seeds PRIMARY KEY, Kind varchar(20) NOT NULL);
INSERT INTO dbo.Seeds (SeedID, Kind)
SELECT n, CHOOSE(n % 3 + 1, 'Fern', 'Moss', 'Ivy')
FROM (SELECT TOP (5000) ROW_NUMBER() OVER (ORDER BY (SELECT NULL)) AS n
      FROM sys.all_objects AS a CROSS JOIN sys.all_objects AS b) AS x;
GO
CREATE PROCEDURE dbo.usp_NightlyReport AS
SELECT COUNT_BIG(*) AS Pairs
FROM (SELECT TOP (4000) SeedID FROM dbo.Seeds ORDER BY SeedID) AS a
CROSS JOIN (SELECT TOP (4000) SeedID FROM dbo.Seeds ORDER BY SeedID) AS b
WHERE a.SeedID < b.SeedID OPTION (MAXDOP 1);
GO
CREATE PROCEDURE dbo.usp_Dashboard AS
SELECT COUNT_BIG(*) AS Pairs
FROM (SELECT TOP (1000) SeedID FROM dbo.Seeds ORDER BY SeedID) AS a
CROSS JOIN (SELECT TOP (1000) SeedID FROM dbo.Seeds ORDER BY SeedID) AS b
WHERE a.SeedID < b.SeedID OPTION (MAXDOP 1);
GO
CREATE PROCEDURE dbo.usp_SeedLookup @SeedID int AS SELECT Kind FROM dbo.Seeds WHERE SeedID = @SeedID;

The next script clears the plan cache of this database only and runs the workload. The report runs twice, the dashboard five times and the lookup fifty times. One ad hoc statement, which is not in any procedure, runs three times. The GO 5 style lines repeat the batch above them.

ALTER DATABASE SCOPED CONFIGURATION CLEAR PROCEDURE_CACHE;
GO
EXEC dbo.usp_NightlyReport;
GO 2
EXEC dbo.usp_Dashboard;
GO 5
EXEC dbo.usp_SeedLookup 77;
GO 50
SELECT COUNT_BIG(*) AS Pairs
FROM (SELECT TOP (2000) SeedID FROM dbo.Seeds ORDER BY SeedID) AS a
CROSS JOIN (SELECT TOP (2000) SeedID FROM dbo.Seeds ORDER BY SeedID) AS b
WHERE a.SeedID < b.SeedID OPTION (MAXDOP 1);
GO 3

The Slowest Cached Queries Query

The query for the slowest cached queries ranks the statements of the current database by average elapsed time. It cuts the statement out of the batch text with the start and end offsets. It returns the plan XML in the last column. In SSMS, a click on that cell opens the plan. The last line of the WHERE clause hides the query itself. It also hides the housekeeping statements of Query Store, which can show up in a database where it is on.

SELECT t.ObjectName, t.Executions, t.AvgElapsedMs, t.TotalElapsedMs, t.AvgLogicalReads, t.StatementStart,
       qp.query_plan AS PlanXml
FROM (SELECT TOP (10)
             OBJECT_NAME(st.objectid, st.dbid) AS ObjectName,
             qs.execution_count AS Executions,
             qs.total_elapsed_time / qs.execution_count / 1000 AS AvgElapsedMs,
             qs.total_elapsed_time / 1000 AS TotalElapsedMs,
             qs.total_logical_reads / qs.execution_count AS AvgLogicalReads,
             LEFT(REPLACE(REPLACE(SUBSTRING(st.text, qs.statement_start_offset / 2 + 1,
                       (CASE qs.statement_end_offset WHEN -1 THEN DATALENGTH(st.text) ELSE qs.statement_end_offset END
                        - qs.statement_start_offset) / 2 + 1), CHAR(13), N' '), CHAR(10), N' '), 40) AS StatementStart,
             qs.plan_handle,
             qs.total_elapsed_time / qs.execution_count AS AvgElapsedUs
      FROM sys.dm_exec_query_stats AS qs
      CROSS APPLY sys.dm_exec_plan_attributes(qs.plan_handle) AS pa
      CROSS APPLY sys.dm_exec_sql_text(qs.sql_handle) AS st
      WHERE pa.attribute = N'dbid' AND CONVERT(int, pa.value) = DB_ID()
        AND st.text NOT LIKE N'%dm_exec_query_stats%' AND st.text NOT LIKE N'%sys.plan_persist%'
      ORDER BY qs.total_elapsed_time / qs.execution_count DESC) AS t
CROSS APPLY sys.dm_exec_query_plan(t.plan_handle) AS qp
ORDER BY t.AvgElapsedUs DESC;

How to Read It

The order tells you where to look first among the slowest cached queries. The ObjectName column is NULL for the ad hoc statement, because it belongs to no procedure. The nightly report runs twice and costs the most per run. The ad hoc statement comes next, and the dashboard follows. The lookup runs fifty times and still costs almost nothing. The elapsed times change with the load of the server, so the table shows approximate values and ranges. The reads are steady, and they rank the statements the same way.

Average and total answer different questions. The average finds the statement that hurts one user. The total finds the statement that hurts the server, because it multiplies the average by the execution count. Change the ORDER BY to qs.total_elapsed_time DESC for the second view. Use qs.max_elapsed_time to find a statement that is fast on most runs and terrible on a few.

The next question is what counts as long running. No number fits every system. Compare a statement with its own history and with what the users expect. Note that logical reads count pages, not milliseconds. A statement with a million reads can finish faster than one with a thousand reads that waits on a lock.

The Ad Hoc Trap

A filter on dbid from the sql text function drops ad hoc batches, because that column is NULL for them. With optimize for ad hoc workloads on, a statement that ran once has no plan XML yet. The plan attribute dbid holds the database of the context for ad hoc statements as well. This script counts both.

SELECT COUNT(*) AS StatementsWithDbIdFilter
FROM sys.dm_exec_query_stats AS qs
CROSS APPLY sys.dm_exec_sql_text(qs.sql_handle) AS st
WHERE st.dbid = DB_ID() AND st.text NOT LIKE N'%dm_exec_query_stats%' AND st.text NOT LIKE N'%sys.plan_persist%';
SELECT COUNT(*) AS StatementsWithPlanAttribute
FROM sys.dm_exec_query_stats AS qs
CROSS APPLY sys.dm_exec_plan_attributes(qs.plan_handle) AS pa
CROSS APPLY sys.dm_exec_sql_text(qs.sql_handle) AS st
WHERE pa.attribute = N'dbid' AND CONVERT(int, pa.value) = DB_ID()
  AND st.text NOT LIKE N'%dm_exec_query_stats%' AND st.text NOT LIKE N'%sys.plan_persist%';

The first filter finds the three procedures and misses the ad hoc statement. Applications that send plain text, and every query a person types, would be invisible to it.

Next Steps for a Slow Query

The query finds the statement. It does not explain it. Open the plan XML. Look for the operator with the largest cost. Look for a scan where a seek should be, and for estimates far from the actual rows. Blocking and deadlocks are different stories, and a deadlock victim is an error, not a slow query. For a query that runs 21 minutes, open its plan first. Then check the missing index suggestions in the plan and the waits of the session.

You could argue that Query Store is the better tool. It is, because its history survives a restart and shows how a query changed. The cache query has one advantage: it needs no setup, and it answers in seconds. For the other side of the story, Find the Most Resource Intensive Queries in SQL Server ranks by CPU. For a query that is running now, see Query Percentage Complete: Watch a Long Query Finish.

What to Remember

To list the slowest cached queries, rank by average elapsed time for the user’s view. Rank by total time for the server’s view. Keep the plan in the same row, filter by the plan attribute, and remember that the cache forgets. When you finish the demo, drop the database.

USE master;
GO
DROP DATABASE SlowStatementDemo;

A slow query is not a number in a list, it is a plan you still have to read.

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