Friday, March 11, 2022

Find timeouts using Query Store

 Kendra Little has a great blog post that explains a lot about timeouts, how to create one on purpose, and various ways to find them. She includes a simple query to get the essential information about each timeout from Query Store.

However, I often find myself in the "too much is never enough" mode, and have been using a more complex script that provides significantly more detail. Kendra's post inspired me to Optimize my script, clean it up a bit, and post it here.

/* Find timeouts using Query Store.sql

Purpose:        This will get data from Query Store about statement timeouts. Two results sets are provided,
                one with statement text and plans, and one without. The latter is for easy sharing (pasting 
                into Excel, etc.).
Author:         Mark Freeman (@m60freeman)
Last Edited:    2022-03-11
Instructions:   Provide a value for @QueryHash or set it to NULL to revieve data for all statements, then 
                execute.
Compatibility:  SQL Server 2016+, Azure SQL Database
License:        This work is licensed under a Creative Commons Attribution-NonCommercial-ShareAlike 3.0 
                Unported License.
                    http://creativecommons.org/licenses/by-nc-sa/3.0/

References:
    https://blogs.technet.microsoft.com/dataplatform/2017/03/02/query-store-how-it-works-how-to-use-the-new-query-store-dmvs
    https://docs.microsoft.com/en-us/sql/relational-databases/system-catalog-views/sys-query-store-wait-stats-transact-sql
    https://sqlperformance.com/2017/11/waits-2/wait-statistics-query-store
    https://davegugg.wordpress.com/2015/01/29/creating-a-comma-separated-list-with-for-xml-path-and-stuff
*/
SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED;

DECLARE @QueryHash  UNIQUEIDENTIFIER    --= 0xE99B152E01DBEF83
;

CREATE TABLE #Result (
    ExecutionType           NVARCHAR(60)        NULL,
    FirstExecutionTime      DATETIMEOFFSET(7)   NOT NULL,
    LastExecutionTime       DATETIMEOFFSET(7)   NOT NULL,
    LastQueryExecutionTime  DATETIMEOFFSET(7)   NOT NULL,
    IntervalStart           DATETIMEOFFSET(7)   NOT NULL,
    IntervalEnd             DATETIMEOFFSET(7)   NOT NULL,
    MaxDurationSecs         DECIMAL(18, 4)      NOT NULL,
    AvgDurationSecs         DECIMAL(18, 4)      NOT NULL,
    ExecutionCount          BIGINT              NOT NULL,
    ObjectName              NVARCHAR(128)       NULL,
    QueryHash               BINARY(8)           NOT NULL,
    QueryId                 BIGINT              NOT NULL,
    StatementHandle         VARBINARY(44)       NOT NULL,
    StatementType           VARCHAR(6)          NULL,
    StmtText                NVARCHAR(MAX)       NOT NULL,
    QueryPlan               XML                 NOT NULL,
    QueryPlanHash           BINARY(8)           NOT NULL,
    QueryParameterization   NVARCHAR(60)        NOT NULL,
    IsTrivial               BIT                 NOT NULL,
    IsParallel              BIT                 NOT NULL,
    IsForced                BIT                 NOT NULL,
    MaxLogicalReads         BIGINT              NOT NULL,
    AvgLogicalReads         INT                 NOT NULL,
    MaxLogicalWrites        BIGINT              NOT NULL,
    AvgLogicalWrites        INT                 NOT NULL,
    Waits                   NVARCHAR(MAX)       NOT NULL,
    PRIMARY KEY (   IntervalEnd DESC, 
                    LastQueryExecutionTime DESC, 
                    MaxLogicalReads DESC, 
                    StatementHandle, 
                    QueryPlanHash)
);

WITH Query AS (
    SELECT  LastQueryExecutionTime  =   q.last_execution_time
            ,QueryParameterization  =   q.query_parameterization_type_desc
            ,QueryPlan              =   CAST(p.query_plan AS XML)
            ,IsTrivial              =   p.is_trivial_plan
            ,IsParallel             =   p.is_parallel_plan
            ,IsForced               =   p.is_forced_plan
            ,ObjectName             =   OBJECT_NAME(q.[object_id])
            ,QueryHash              =   q.query_hash
            ,QueryId                =   q.query_id
            ,StatementHandle        =   t.statement_sql_handle
            ,StmtText               =   t.query_sql_text
            ,QueryPlanHash          =   p.query_plan_hash
            ,QueryPlanId            =   p.plan_id
      FROM  sys.query_store_query_text t
            JOIN sys.query_store_query q   ON t.query_text_id = q.query_text_id
            JOIN sys.query_store_plan p    ON q.query_id = p.query_id
     WHERE  t.query_sql_text    NOT LIKE 'ALTER INDEX %'
       AND  t.query_sql_text    NOT LIKE 'SELECT StatMan%'
       AND  t.query_sql_text    NOT LIKE '%encrypted%'
       AND  t.query_sql_text    NOT LIKE '(@plan_handle%'
       AND  t.query_sql_text    NOT LIKE 'WITH tempdbObjects%'
       AND  t.query_sql_text    NOT LIKE 'SELECT SUM(reserved_page_count)%'
       AND  t.query_sql_text    NOT LIKE 'SELECT secondary_lag_seconds%'
       AND  q.query_hash        =   ISNULL(@QueryHash, q.query_hash)
)
INSERT  INTO #Result WITH (TABLOCK)
SELECT  ExecutionType               =   rs.execution_type_desc
        ,FirstExecutionTime         =   rs.first_execution_time
        ,LastExecutionTime          =   rs.last_execution_time
        ,q.LastQueryExecutionTime
        ,IntervalStart              =   i.start_time
        ,IntervalEnd                =   i.end_time
        ,MaxDurationSecs            =   CAST(ROUND(rs.max_duration / 1000000.0, 4) AS DECIMAL(18, 4))
        ,AvgDurationSecs            =   CAST(ROUND(rs.avg_duration / 1000000.0, 4) AS DECIMAL(18, 4))
        ,ExecutionCount             =   rs.count_executions
        ,q.ObjectName
        ,q.QueryHash
        ,q.QueryId
        ,q.StatementHandle
        ,StatementType              =   CASE
                                            WHEN CHARINDEX(N'MERGE ',  q.StmtText) > 0 THEN 'MERGE'
                                            WHEN CHARINDEX(N'INSERT ', q.StmtText) > 0 THEN 'INSERT'
                                            WHEN CHARINDEX(N'UPDATE ', q.StmtText) > 0 THEN 'UPDATE'
                                            WHEN CHARINDEX(N'DELETE ', q.StmtText) > 0 THEN 'DELETE'
                                            WHEN CHARINDEX(N'SELECT ', q.StmtText) > 0 THEN 'SELECT'
                                        END
        ,q.StmtText       
        ,q.QueryPlan
        ,q.QueryPlanHash  
        ,q.QueryParameterization
        ,q.IsTrivial
        ,q.IsParallel
        ,q.IsForced  
        ,MaxLogicalReads            =   rs.max_logical_io_reads
        ,AvgLogicalReads            =   CAST(ROUND(rs.avg_logical_io_reads, 0) AS INT)
        ,MaxLogicalWrites           =   rs.max_logical_io_writes
        ,AvgLogicalWrites           =   CAST(ROUND(rs.avg_logical_io_writes, 0) AS INT)
        ,w.Waits
  FROM  Query q
        JOIN sys.query_store_runtime_stats rs           ON q.QueryPlanId = rs.plan_id
        JOIN sys.query_store_runtime_stats_interval i   ON rs.runtime_stats_interval_id = i.runtime_stats_interval_id
        OUTER APPLY ( 
        SELECT  Waits   =   STUFF(  (   SELECT  ', ' + CONVERT(VARCHAR, wait_category_desc) + ': '
                                                + CONVERT(VARCHAR, total_query_wait_time_ms) + 'ms'
                                          FROM  (   SELECT  ws.wait_category_desc, ws.total_query_wait_time_ms
                                                      FROM  sys.query_store_wait_stats ws
                                                     WHERE  ws.runtime_stats_interval_id    = rs.runtime_stats_interval_id
                                                       AND  ws.plan_id                      = rs.plan_id
                                                       AND  rs.execution_type               = ws.execution_type
                                                ) WaitValues
                                         ORDER  BY total_query_wait_time_ms DESC
                                           FOR  XML PATH('')
                                    ), 1, 2, ''
                            ) 
        ) w
 WHERE  rs.execution_type       =   3
--   AND  rs.first_execution_time >=   '2020-12-14 00:00:00' --DATEADD(HOUR, -12, GETDATE())
--   AND  rs.last_execution_time  <=   '2020-12-21 23:23:23' --DATEADD(HOUR, -12, GETDATE())
OPTION  (MAXDOP 1); /* To minimize the load when run in production */

SELECT  * 
  FROM  #Result
 ORDER  BY IntervalEnd DESC, LastQueryExecutionTime DESC, MaxLogicalReads DESC, StatementHandle, QueryPlanHash;

/* No statement text or plans, for easy sharing */

SELECT  ExecutionType      
        ,ObjectName            
        ,QueryHash             
        ,QueryPlanHash         
        ,QueryId               
        ,FirstExecutionTime    
        ,LastExecutionTime     
        ,LastQueryExecutionTime
        ,IntervalStart         
        ,IntervalEnd           
        ,MaxDurationSecs       
        ,AvgDurationSecs       
        ,ExecutionCount		   
        ,MaxLogicalReads       
        ,AvgLogicalReads       
        ,MaxLogicalWrites      
        ,AvgLogicalWrites      
        ,Waits
  FROM  #Result
 ORDER  BY IntervalEnd DESC, LastQueryExecutionTime DESC, MaxLogicalReads DESC, StatementHandle, QueryPlanHash;

DROP TABLE #Result;

No comments:

Post a Comment