4

I have a job that executes every 5 minutes to gather info from DMVs that has not changed in over 2 years, normally running under a minute.

All of a sudden starting last week, with no changes deployed, this job started running over 12 minutes on only 1 server out of 15. Looking at the execution plan nothing has changed, but the reads, writes, CPU time, and rowcounts all went up by an order of magnitude. The number of rows inserted hasn't changed by much either.

Could this be bad statistics in the underlying system tables? If so, how can it be solved, because I can't run UPDATE STATISTICS on any of the DMVs which just give a message about the object not existing.

Here is the code in question:

SELECT
    ISNULL(DB_NAME(st.dbid), 'NULL') AS [DatabaseName]  
    ,ISNULL(OBJECT_SCHEMA_NAME(st.objectid, st.dbid), 'NULL') AS [SchemaName] 
    ,ISNULL(OBJECT_NAME(st.objectid, st.dbid), 'NULL') AS [ObjectName]   
    ,cp.objtype AS [ObjectType]
    ,qs.statement_start_offset AS [StatementStartOffset]
    ,qs.statement_end_offset AS [StatementEndOffset]
    ,qs.query_hash AS [QueryHash]
    ,qs.query_plan_hash AS [QueryPlanHash]
    ,qs.sql_handle AS [SQLHandle]
    ,qs.plan_handle AS [PlanHandle]
    ,qs.plan_generation_num AS [PlanGenerationNumber]
    ,cp.usecounts AS [UseCounts]
    ,cp.refcounts AS [RefCounts]
    -- find the offset of the actual statement being executed
    ,SUBSTRING(st.text, 
            CASE
                WHEN qs.statement_start_offset = 0 OR qs.statement_start_offset IS NULL THEN 1  
                ELSE qs.statement_start_offset/2 + 1
            END, 
            CASE 
                WHEN qs.statement_end_offset = 0 OR qs.statement_end_offset = -1 OR qs.statement_end_offset IS NULL THEN LEN(st.text)  
                ELSE qs.statement_end_offset/2 
            END - 
            CASE
                WHEN qs.statement_start_offset = 0 OR qs.statement_start_offset IS NULL THEN 1  
                ELSE qs.statement_start_offset/2
            END + 1 
        ) AS [Statement]  
    ,qs.last_execution_time AS [LastExecutionTime]
    ,qs.creation_time AS [CreationTime]
    ,qs.execution_count AS [ExecutionCount]
    ,qs.total_logical_reads AS [TotalLogicalReads]
    ,qs.last_logical_reads AS [LastLogicalReads]
    ,qs.min_logical_reads AS [MinLogicalReads]
    ,qs.max_logical_reads AS [MaxLogicalReads]
    ,qs.total_logical_writes AS [TotalLogicalWrites]
    ,qs.last_logical_writes AS [LastLogicalWrites]
    ,qs.min_logical_writes AS [MinLogicalWrites]
    ,qs.max_logical_writes AS [MaxLogicalWrites]
    ,qs.total_physical_reads AS [TotalPhysicalReads]
    ,qs.last_physical_reads AS [LastPhysicalReads]
    ,qs.min_physical_reads AS [MinPhysicalReads]
    ,qs.max_physical_reads AS [MaxPhysicalReads]
    ,qs.total_worker_time AS [TotalWorkerTime]
    ,qs.last_worker_time AS [LastWorkerTime]
    ,qs.min_worker_time AS [MinWorkerTime]
    ,qs.max_worker_time AS [MaxWorkerTime]
    ,qs.total_clr_time AS [TotalCLRTime]
    ,qs.last_clr_time AS [LastCLRTime]
    ,qs.min_clr_time AS [MinCLRTime]
    ,qs.max_clr_time AS [MaxCLRTime]
    ,qs.total_elapsed_time AS [TotalElapsedTime]
    ,qs.last_elapsed_time AS [LastElapsedTime]
    ,qs.min_elapsed_time AS [MinElapsedTime]
    ,qs.max_elapsed_time AS [MaxElapsedTime]
    ,qs.total_rows AS [TotalRows]
    ,qs.last_rows AS [LastRows]
    ,qs.min_rows AS [MinRows]
    ,qs.max_rows AS [MaxRows]
INTO #QueryUsageStats
FROM sys.dm_exec_query_stats qs   
INNER JOIN sys.dm_exec_cached_plans cp 
ON qs.plan_handle = cp.plan_handle 
CROSS APPLY sys.dm_exec_sql_text(qs.plan_handle) st
WHERE 1=2;

CREATE UNIQUE CLUSTERED INDEX #PK_#QueryUsageStats ON #QueryUsageStats
(
    [DatabaseName] ASC,
    [SchemaName] ASC,
    [ObjectName] ASC,
    [ObjectType] ASC,
    [StatementStartOffset] ASC,
    [StatementEndOffset] ASC,
    [QueryHash] ASC,
    [QueryPlanHash] ASC,
    [PlanHandle] ASC
);

INSERT INTO #QueryUsageStats
SELECT
    ISNULL(DB_NAME(st.dbid), 'NULL') AS [DatabaseName]  
    ,ISNULL(OBJECT_SCHEMA_NAME(st.objectid, st.dbid), 'NULL') AS [SchemaName] 
    ,ISNULL(OBJECT_NAME(st.objectid, st.dbid), 'NULL') AS [ObjectName]   
    ,cp.objtype AS [ObjectType]
    ,qs.statement_start_offset AS [StatementStartOffset]
    ,qs.statement_end_offset AS [StatementEndOffset]
    ,qs.query_hash AS [QueryHash]
    ,qs.query_plan_hash AS [QueryPlanHash]
    ,qs.sql_handle AS [SQLHandle]
    ,qs.plan_handle AS [PlanHandle]
    ,qs.plan_generation_num AS [PlanGenerationNumber]
    ,cp.usecounts AS [UseCounts]
    ,cp.refcounts AS [RefCounts]
    -- find the offset of the actual statement being executed
    ,SUBSTRING(st.text, 
            CASE
                WHEN qs.statement_start_offset = 0 OR qs.statement_start_offset IS NULL THEN 1  
                ELSE qs.statement_start_offset/2 + 1
            END, 
            CASE 
                WHEN qs.statement_end_offset = 0 OR qs.statement_end_offset = -1 OR qs.statement_end_offset IS NULL THEN LEN(st.text)  
                ELSE qs.statement_end_offset/2 
            END - 
            CASE
                WHEN qs.statement_start_offset = 0 OR qs.statement_start_offset IS NULL THEN 1  
                ELSE qs.statement_start_offset/2
            END + 1 
        ) AS [Statement]  
    ,qs.last_execution_time AS [LastExecutionTime]
    ,qs.creation_time AS [CreationTime]
    ,qs.execution_count AS [ExecutionCount]
    ,qs.total_logical_reads AS [TotalLogicalReads]
    ,qs.last_logical_reads AS [LastLogicalReads]
    ,qs.min_logical_reads AS [MinLogicalReads]
    ,qs.max_logical_reads AS [MaxLogicalReads]
    ,qs.total_logical_writes AS [TotalLogicalWrites]
    ,qs.last_logical_writes AS [LastLogicalWrites]
    ,qs.min_logical_writes AS [MinLogicalWrites]
    ,qs.max_logical_writes AS [MaxLogicalWrites]
    ,qs.total_physical_reads AS [TotalPhysicalReads]
    ,qs.last_physical_reads AS [LastPhysicalReads]
    ,qs.min_physical_reads AS [MinPhysicalReads]
    ,qs.max_physical_reads AS [MaxPhysicalReads]
    ,qs.total_worker_time AS [TotalWorkerTime]
    ,qs.last_worker_time AS [LastWorkerTime]
    ,qs.min_worker_time AS [MinWorkerTime]
    ,qs.max_worker_time AS [MaxWorkerTime]
    ,qs.total_clr_time AS [TotalCLRTime]
    ,qs.last_clr_time AS [LastCLRTime]
    ,qs.min_clr_time AS [MinCLRTime]
    ,qs.max_clr_time AS [MaxCLRTime]
    ,qs.total_elapsed_time AS [TotalElapsedTime]
    ,qs.last_elapsed_time AS [LastElapsedTime]
    ,qs.min_elapsed_time AS [MinElapsedTime]
    ,qs.max_elapsed_time AS [MaxElapsedTime]
    ,qs.total_rows AS [TotalRows]
    ,qs.last_rows AS [LastRows]
    ,qs.min_rows AS [MinRows]
    ,qs.max_rows AS [MaxRows]
FROM sys.dm_exec_query_stats qs   
INNER JOIN sys.dm_exec_cached_plans cp 
ON qs.plan_handle = cp.plan_handle 
CROSS APPLY sys.dm_exec_sql_text(qs.plan_handle) st;

Here is the execution plan produced:

enter image description here

NOTE that I have also removed the clustered index and the also run the query just as a select discarding the results of the query, and it still takes more than 3 or more minutes. In fact just selecting the data from sys.dm_exec_query_stats seems to take over 3 minutes even without joining to the other tables now and even without the order by clause.

  • 1
    Have you considered just hard-coding the creation of the #temp table for now, until you know that the DMV has changed? Having the entire query repeated - once with a no result clause - seems heavy-handed and the optimizer shouldn't have to deal with that twice. – Aaron Bertrand Apr 3 '18 at 20:07
  • I normally would but it was modified from the original as a "quick-fix". Besides currently this only takes less than 1 sec to run. The real problem is the actual join. However, I will make the change now that I have some time. – Diane Apr 3 '18 at 20:51
  • 1
    I encountered the same issue when querying AG related DMVs - see here dba.stackexchange.com/a/131636/8783 and resolved it using temp tables. – Kin Shah Apr 6 '18 at 14:20
3

Nick Craver ran into performance issues with this too in Opserver. Here's the query he ended up with after working directly with MS folks on the query plan - the joins look kinda contorted, but as I recall, that was the only way he could get consistently good performance and avoid the timeout issues:

SELECT AvgCPU, AvgDuration, AvgReads, AvgCPUPerMinute,
       TotalCPU, TotalDuration, TotalReads,
       PercentCPU, PercentDuration, PercentReads, PercentExecutions,
       ExecutionCount,
       ExecutionsPerMinute,
       PlanCreationTime, LastExecutionTime,
       SUBSTRING(st.text,
                 (StatementStartOffset / 2) + 1,
                 ((CASE StatementEndOffset
                   WHEN -1 THEN DATALENGTH(st.text)
                   ELSE StatementEndOffset
                   END - StatementStartOffset) / 2) + 1) AS QueryText,
        st.Text FullText,
        query_plan AS QueryPlan,
        PlanHandle,
        StatementStartOffset,
        StatementEndOffset,
        MinReturnedRows,
        MaxReturnedRows,
        AvgReturnedRows,
        TotalReturnedRows,
        LastReturnedRows,
        DB_NAME(DatabaseId) AS CompiledOnDatabase
FROM (SELECT TOP (@MaxResultCount) 
             total_worker_time / execution_count AS AvgCPU,
             total_elapsed_time / execution_count AS AvgDuration,
             total_logical_reads / execution_count AS AvgReads,
             Cast(total_worker_time / age_minutes As BigInt) AS AvgCPUPerMinute,
             execution_count / age_minutes AS ExecutionsPerMinute,
             Cast(total_worker_time / age_minutes_lifetime As BigInt) AS AvgCPUPerMinuteLifetime,
             execution_count / age_minutes_lifetime AS ExecutionsPerMinuteLifetime,
             total_worker_time AS TotalCPU,
             total_elapsed_time AS TotalDuration,
             total_logical_reads AS TotalReads,
             execution_count ExecutionCount,
             CAST(ROUND(100.00 * total_worker_time / t.TotalWorker, 2) AS MONEY) AS PercentCPU,
             CAST(ROUND(100.00 * total_elapsed_time / t.TotalElapsed, 2) AS MONEY) AS PercentDuration,
             CAST(ROUND(100.00 * total_logical_reads / t.TotalReads, 2) AS MONEY) AS PercentReads,
             CAST(ROUND(100.00 * execution_count / t.TotalExecs, 2) AS MONEY) AS PercentExecutions,
             qs.creation_time AS PlanCreationTime,
             qs.last_execution_time AS LastExecutionTime,
             qs.plan_handle AS PlanHandle,
             qs.statement_start_offset AS StatementStartOffset,
             qs.statement_end_offset AS StatementEndOffset,
             qs.min_rows AS MinReturnedRows,
             qs.max_rows AS MaxReturnedRows,
             CAST(qs.total_rows as MONEY) / execution_count AS AvgReturnedRows,
             qs.total_rows AS TotalReturnedRows,
             qs.last_rows AS LastReturnedRows,
             qs.sql_handle AS SqlHandle,
             Cast(pa.value as Int) DatabaseId
        FROM (SELECT *, 
                     CAST((CASE WHEN DATEDIFF(second, creation_time, GETDATE()) > 0 And execution_count > 1
                                THEN DATEDIFF(second, creation_time, GETDATE()) / 60.0
                                ELSE Null END) as MONEY) as age_minutes, 
                     CAST((CASE WHEN DATEDIFF(second, creation_time, last_execution_time) > 0 And execution_count > 1
                                THEN DATEDIFF(second, creation_time, last_execution_time) / 60.0
                                ELSE Null END) as MONEY) as age_minutes_lifetime
                FROM sys.dm_exec_query_stats) AS qs
             CROSS JOIN(SELECT SUM(execution_count) TotalExecs,
                               SUM(total_elapsed_time) TotalElapsed,
                               SUM(total_worker_time) TotalWorker,
                               SUM(total_logical_reads) TotalReads
                          FROM sys.dm_exec_query_stats) AS t
             CROSS APPLY sys.dm_exec_plan_attributes(qs.plan_handle) AS pa
     WHERE pa.attribute = 'dbid'
       {0}) sq
    CROSS APPLY sys.dm_exec_sql_text(SqlHandle) AS st
    CROSS APPLY sys.dm_exec_query_plan(PlanHandle) AS qp
  • That would make sense if I was trying to get the calculated statistics, but in this case, it's really just a simple select from sys.dm_exec_query_stats. Even without the joins to sys.dm_exec_sql_text and sys.dm_exec_cached_plans, I'm finding simply selecting from this one DMV is taking way too long. It seems something is way off in the hash join operator. – Diane Apr 3 '18 at 21:17
1

You can further improve this by filtering on last_execution_time >= @lastpolltime. Unless you have a lot of churn in your plan cache this should cut back how many rows are coming back.

0

I was able to optimize the query by basically porting each DMV into it's own temp table and then doing the join on those instead. Also, I got the distinct list of plan handles first and then used that to CROSS APPLY to sys.dm_exec_sql_text, which further reduced the reads.

Here's what it looks like:

CREATE TABLE #ExecQueryStats (
    [StatementStartOffset] int NOT NULL
    ,[StatementEndOffset] int NOT NULL
    ,[QueryHash] binary(8) NULL
    ,[QueryPlanHash] binary(8) NULL
    ,[SQLHandle] varbinary(64) NOT NULL
    ,[PlanHandle] varbinary(64) NOT NULL
    ,[PlanGenerationNumber] int NULL
    ,[LastExecutionTime] datetime NULL
    ,[CreationTime] datetime NULL
    ,[ExecutionCount] bigint NOT NULL
    ,[TotalLogicalReads] bigint NOT NULL
    ,[LastLogicalReads] bigint NOT NULL
    ,[MinLogicalReads] bigint NOT NULL
    ,[MaxLogicalReads] bigint NOT NULL
    ,[TotalLogicalWrites] bigint NOT NULL
    ,[LastLogicalWrites] bigint NOT NULL
    ,[MinLogicalWrites] bigint NOT NULL
    ,[MaxLogicalWrites] bigint NOT NULL
    ,[TotalPhysicalReads] bigint NOT NULL
    ,[LastPhysicalReads] bigint NOT NULL
    ,[MinPhysicalReads] bigint NOT NULL
    ,[MaxPhysicalReads] bigint NOT NULL
    ,[TotalWorkerTime] bigint NOT NULL
    ,[LastWorkerTime] bigint NOT NULL
    ,[MinWorkerTime] bigint NOT NULL
    ,[MaxWorkerTime] bigint NOT NULL
    ,[TotalCLRTime] bigint NOT NULL
    ,[LastCLRTime] bigint NOT NULL
    ,[MinCLRTime] bigint NOT NULL
    ,[MaxCLRTime] bigint NOT NULL
    ,[TotalElapsedTime] bigint NOT NULL
    ,[LastElapsedTime] bigint NOT NULL
    ,[MinElapsedTime] bigint NOT NULL
    ,[MaxElapsedTime] bigint NOT NULL
    ,[TotalRows] bigint NULL
    ,[LastRows] bigint NULL
    ,[MinRows] bigint NULL
    ,[MaxRows] bigint NULL
);

CREATE CLUSTERED INDEX #PK_#ExecQueryStats ON #ExecQueryStats
(
    [PlanHandle] ASC
);

CREATE TABLE #ExecQueryStatsPlans (
    [PlanHandle] varbinary(64) NOT NULL
);

CREATE UNIQUE CLUSTERED INDEX #PK_#ExecQueryStatsPlans ON #ExecQueryStatsPlans
(
    [PlanHandle] ASC
);

CREATE TABLE #ExecCachedPlans (
    [PlanHandle] varbinary(64) NOT NULL
    ,[ObjectType] nvarchar(40) NOT NULL
    ,[UseCounts] int NOT NULL
    ,[RefCounts] int NOT NULL
    );

CREATE UNIQUE CLUSTERED INDEX #PK_#ExecCachedPlans ON #ExecCachedPlans
(
    [PlanHandle] ASC
);

CREATE TABLE #ExecSqlText (
    [PlanHandle] varbinary(64) NOT NULL
    ,[DatabaseName] sysname NULL
    ,[SchemaName] sysname NULL
    ,[ObjectName] sysname NULL 
    ,[Text] nvarchar(max) NULL
    );

CREATE UNIQUE CLUSTERED INDEX #PK_#ExecSqlText ON #ExecSqlText
(
    [PlanHandle] ASC
);

CREATE TABLE #QueryUsageStats (
    [DatabaseName] sysname NULL
    ,[SchemaName] sysname NULL
    ,[ObjectName] sysname NULL    
    ,[ObjectType] nvarchar(40) NOT NULL
    ,[StatementStartOffset] int NOT NULL
    ,[StatementEndOffset] int NOT NULL
    ,[QueryHash] binary(8) NULL
    ,[QueryPlanHash] binary(8) NULL
    ,[SQLHandle] varbinary(64) NOT NULL
    ,[PlanHandle] varbinary(64) NOT NULL
    ,[PlanGenerationNumber] int NULL
    ,[UseCounts] int NOT NULL
    ,[RefCounts] int NOT NULL
    ,[Statement] nvarchar(max) NULL 
    ,[LastExecutionTime] datetime NULL
    ,[CreationTime] datetime NULL
    ,[ExecutionCount] bigint NOT NULL
    ,[TotalLogicalReads] bigint NOT NULL
    ,[LastLogicalReads] bigint NOT NULL
    ,[MinLogicalReads] bigint NOT NULL
    ,[MaxLogicalReads] bigint NOT NULL
    ,[TotalLogicalWrites] bigint NOT NULL
    ,[LastLogicalWrites] bigint NOT NULL
    ,[MinLogicalWrites] bigint NOT NULL
    ,[MaxLogicalWrites] bigint NOT NULL
    ,[TotalPhysicalReads] bigint NOT NULL
    ,[LastPhysicalReads] bigint NOT NULL
    ,[MinPhysicalReads] bigint NOT NULL
    ,[MaxPhysicalReads] bigint NOT NULL
    ,[TotalWorkerTime] bigint NOT NULL
    ,[LastWorkerTime] bigint NOT NULL
    ,[MinWorkerTime] bigint NOT NULL
    ,[MaxWorkerTime] bigint NOT NULL
    ,[TotalCLRTime] bigint NOT NULL
    ,[LastCLRTime] bigint NOT NULL
    ,[MinCLRTime] bigint NOT NULL
    ,[MaxCLRTime] bigint NOT NULL
    ,[TotalElapsedTime] bigint NOT NULL
    ,[LastElapsedTime] bigint NOT NULL
    ,[MinElapsedTime] bigint NOT NULL
    ,[MaxElapsedTime] bigint NOT NULL
    ,[TotalRows] bigint NULL
    ,[LastRows] bigint NULL
    ,[MinRows] bigint NULL
    ,[MaxRows] bigint NULL
);

CREATE UNIQUE CLUSTERED INDEX #PK_#QueryUsageStats ON #QueryUsageStats
(
    [DatabaseName] ASC,
    [SchemaName] ASC,
    [ObjectName] ASC,
    [ObjectType] ASC,
    [StatementStartOffset] ASC,
    [StatementEndOffset] ASC,
    [QueryHash] ASC,
    [QueryPlanHash] ASC,
    [PlanHandle] ASC
);

INSERT INTO #ExecQueryStats
SELECT 
    qs.statement_start_offset AS [StatementStartOffset]
    ,qs.statement_end_offset AS [StatementEndOffset]
    ,qs.query_hash AS [QueryHash]
    ,qs.query_plan_hash AS [QueryPlanHash]
    ,qs.sql_handle AS [SQLHandle]
    ,qs.plan_handle AS [PlanHandle]
    ,qs.plan_generation_num AS [PlanGenerationNumber]
    ,qs.last_execution_time AS [LastExecutionTime]
    ,qs.creation_time AS [CreationTime]
    ,qs.execution_count AS [ExecutionCount]
    ,qs.total_logical_reads AS [TotalLogicalReads]
    ,qs.last_logical_reads AS [LastLogicalReads]
    ,qs.min_logical_reads AS [MinLogicalReads]
    ,qs.max_logical_reads AS [MaxLogicalReads]
    ,qs.total_logical_writes AS [TotalLogicalWrites]
    ,qs.last_logical_writes AS [LastLogicalWrites]
    ,qs.min_logical_writes AS [MinLogicalWrites]
    ,qs.max_logical_writes AS [MaxLogicalWrites]
    ,qs.total_physical_reads AS [TotalPhysicalReads]
    ,qs.last_physical_reads AS [LastPhysicalReads]
    ,qs.min_physical_reads AS [MinPhysicalReads]
    ,qs.max_physical_reads AS [MaxPhysicalReads]
    ,qs.total_worker_time AS [TotalWorkerTime]
    ,qs.last_worker_time AS [LastWorkerTime]
    ,qs.min_worker_time AS [MinWorkerTime]
    ,qs.max_worker_time AS [MaxWorkerTime]
    ,qs.total_clr_time AS [TotalCLRTime]
    ,qs.last_clr_time AS [LastCLRTime]
    ,qs.min_clr_time AS [MinCLRTime]
    ,qs.max_clr_time AS [MaxCLRTime]
    ,qs.total_elapsed_time AS [TotalElapsedTime]
    ,qs.last_elapsed_time AS [LastElapsedTime]
    ,qs.min_elapsed_time AS [MinElapsedTime]
    ,qs.max_elapsed_time AS [MaxElapsedTime]
    ,qs.total_rows AS [TotalRows]
    ,qs.last_rows AS [LastRows]
    ,qs.min_rows AS [MinRows]
    ,qs.max_rows AS [MaxRows]
FROM sys.dm_exec_query_stats qs;

INSERT INTO #ExecQueryStatsPlans
SELECT DISTINCT [PlanHandle]
FROM #ExecQueryStats;

INSERT INTO #ExecCachedPlans
SELECT 
    #ExecQueryStatsPlans.[PlanHandle]
    ,cp.objtype AS [ObjectType]
    ,cp.usecounts AS [UseCounts]
    ,cp.refcounts AS [RefCounts]
FROM sys.dm_exec_cached_plans cp
INNER JOIN #ExecQueryStatsPlans
ON cp.[plan_handle] = #ExecQueryStatsPlans.[PlanHandle];

INSERT INTO #ExecSqlText
SELECT
    #ExecQueryStatsPlans.[PlanHandle]
    ,ISNULL(DB_NAME(st.dbid), 'NULL') AS [DatabaseName]  
    ,ISNULL(OBJECT_SCHEMA_NAME(st.objectid, st.dbid), 'NULL') AS [SchemaName] 
    ,ISNULL(OBJECT_NAME(st.objectid, st.dbid), 'NULL') AS [ObjectName]   
    ,st.text AS [Text]
FROM #ExecQueryStatsPlans
CROSS APPLY sys.dm_exec_sql_text(#ExecQueryStatsPlans.[PlanHandle]) st;

INSERT INTO #QueryUsageStats
SELECT
    st.[DatabaseName]  
    ,st.[SchemaName] 
    ,st.[ObjectName]   
    ,cp.[ObjectType]
    ,qs.[StatementStartOffset]
    ,qs.[StatementEndOffset]
    ,qs.[QueryHash]
    ,qs.[QueryPlanHash]
    ,qs.[SQLHandle]
    ,qs.[PlanHandle]
    ,qs.[PlanGenerationNumber]
    ,cp.[UseCounts]
    ,cp.[RefCounts]
    -- find the offset of the actual statement being executed
    ,SUBSTRING(st.[Text], 
            CASE
                WHEN qs.[StatementStartOffset] = 0 OR qs.[StatementStartOffset] IS NULL THEN 1  
                ELSE qs.[StatementStartOffset]/2 + 1
            END, 
            CASE 
                WHEN qs.[StatementEndOffset] = 0 OR qs.[StatementEndOffset] = -1 OR qs.[StatementEndOffset] IS NULL THEN LEN(st.[Text])  
                ELSE qs.[StatementEndOffset]/2 
            END - 
            CASE
                WHEN qs.[StatementStartOffset] = 0 OR qs.[StatementStartOffset] IS NULL THEN 1  
                ELSE qs.[StatementStartOffset]/2
            END + 1 
        ) AS [Statement]  
    ,qs.[LastExecutionTime]
    ,qs.[CreationTime]
    ,qs.[ExecutionCount]
    ,qs.[TotalLogicalReads]
    ,qs.[LastLogicalReads]
    ,qs.[MinLogicalReads]
    ,qs.[MaxLogicalReads]
    ,qs.[TotalLogicalWrites]
    ,qs.[LastLogicalWrites]
    ,qs.[MinLogicalWrites]
    ,qs.[MaxLogicalWrites]
    ,qs.[TotalPhysicalReads]
    ,qs.[LastPhysicalReads]
    ,qs.[MinPhysicalReads]
    ,qs.[MaxPhysicalReads]
    ,qs.[TotalWorkerTime]
    ,qs.[LastWorkerTime]
    ,qs.[MinWorkerTime]
    ,qs.[MaxWorkerTime]
    ,qs.[TotalCLRTime]
    ,qs.[LastCLRTime]
    ,qs.[MinCLRTime]
    ,qs.[MaxCLRTime]
    ,qs.[TotalElapsedTime]
    ,qs.[LastElapsedTime]
    ,qs.[MinElapsedTime]
    ,qs.[MaxElapsedTime]
    ,qs.[TotalRows]
    ,qs.[LastRows]
    ,qs.[MinRows]
    ,qs.[MaxRows]
FROM #ExecQueryStats qs   
INNER JOIN #ExecCachedPlans cp 
ON qs.[PlanHandle] = cp.[PlanHandle] 
INNER JOIN #ExecSqlText st
ON qs.[PlanHandle] = st.[PlanHandle];

This took it down from 7-8 minutes to about 2-3 minutes. Note that I took Aaron's suggestion to manually build the temp tables as opposed to using the "SELECT INTO...WHERE 1=2" method, though it didn't make noticeable difference here, but just as a good code practice to do.

I would still like to know what could cause this to change, given that the cache didn't suddenly bloat. We did have Query Store enabled on one DB, but even after temporarily disabling it and purging the data, it had no impact. There doesn't seem to be a significant change in the number of queries, either Ad-Hoc or Compiled that are running on the server either. And it's only happening on 1 instance as well. My gut still feels like this could be a statistics issue, but not sure where to look for that for these DMVs. I also wonder if clearing the procedure cache would help, though that would have to wait until our next maintenance window.

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.