Lessons Learned #557: Investigating an unexpected query slowdown
While working on a support case, our customer told us that the application was performing very poorly. We identified the affected query and found two execution plans in Query Store. When we compared them, we saw a clear difference: one plan used the CustomerId index, while the other scanned the table's clustered index. That led us to investigate why the query was no longer using that index. The following example reproduces this scenario with 100,000 fictional orders in an existing test database in Azure SQL Database. Follow the execution history In the example, query_id 231 has two captured plans, 243 and 251. Comparing their XML revealed the following differences: Access operator property With the CustomerId index Without the CustomerId index PhysicalOp Index Seek Clustered Index Scan Object / Index IX_TmpOrdersExample_MS_CustomerId Clustered primary key Filter placement SeekPredicates on CustomerId Predicate evaluated during the scan EstimatedRowsRead 10 100,000 EstimateRows after the filter 10 11.6601 ParameterCompiledValue 42 42 The scan references PK__TmpOrder__C3905BCF2BEADCD8. It still uses an index, but it no longer uses the nonclustered CustomerId index. The most useful difference for our investigation was EstimatedRowsRead: 10 for the seek and 100,000 for the scan, with the same compiled parameter value of 42. The XML also identifies each plan through QueryPlanHash: 0xA9A905E8788F2826 for the seek and 0xD122865CD758CA3C for the scan. Investigate why the index was no longer used The plan comparison showed a change from an Index Seek to a Clustered Index Scan, but it did not explain why that change occurred. I therefore reviewed the Query Store metadata for both plans to check. DECLARE @QueryId bigint = 231; SELECT * FROM sys.query_store_plan WHERE query_id = @QueryId ORDER BY plan_id; The results were: Plan 243 had is_forced_plan = 1, force_failure_count = 1 and last_force_failure_reason_desc = NO_INDEX. Plan 251 was not marked as forced. This is where we discovered that the earlier plan had been configured as forced and that an attempt to apply it had failed. NO_INDEX identifies an unavailable index dependency. The forcing flag records configuration, while the failure fields record unsuccessful attempts. The counter increments on recompilation failures and resets when forcing changes from off to on. This gives us a specific explanation. The expected plan references an index that was removed. The engine could not apply that plan and could optimize the query normally instead. The query can therefore continue returning the correct result while its execution strategy changes. Check the actual index definition and the deployment changes, then inspect the alternative plan. The NO_INDEX result explains the forcing failure; demonstrating that the alternative caused the reported slowdown still requires the runtime comparison. This is one possible cause of a regression, not an explanation for every slow query. Review forcing failures during maintenance This case also gave us a useful maintenance check. Instead of looking only for NO_INDEX, we can review the other forcing failures recorded by sys.query_store_plan. The following query groups affected plans by their last reported reason. Run it in the database being reviewed. DECLARE @SinceUtc datetimeoffset = DATEADD(day, -7, SYSUTCDATETIME()); SELECT last_force_failure_reason_desc AS LastFailureReason, COUNT_BIG(*) AS PlansWithFailures, COUNT(DISTINCT query_id) AS AffectedQueries, SUM(CASE WHEN is_forced_plan = 1 THEN CONVERT(bigint, 1) ELSE 0 END) AS CurrentlyForcedPlans, SUM(force_failure_count) AS CumulativeFailureCount FROM sys.query_store_plan WHERE force_failure_count > 0 AND (@SinceUtc IS NULL OR last_execution_time >= @SinceUtc) GROUP BY last_force_failure_reason_desc ORDER BY PlansWithFailures DESC; Use @SinceUtc to focus on plans with execution activity since a date, or set it to NULL to review all retained plans with failures. The date filters activity, not the time of the forcing failure. The counters are cumulative and may include older failures or failures with a different earlier reason. Identify queries that reference an index before removing it Before removing an index, we can ask a related question: which captured query plans read from it, and how often have those plans executed recently? The following query searches the retained plan XML for the index and returns one row per matching plan. Change the schema, table, index and UTC dates. This example looks for the CustomerId index used in my labs. DECLARE @SchemaName sysname = N'dbo'; DECLARE @TableName sysname = N'TmpOrdersExample_MS'; DECLARE @IndexName sysname = N'IX_TmpOrdersExample_MS_CustomerId'; DECLARE @SinceUtc datetimeoffset = DATEADD(day, -7, SYSUTCDATETIME()); DECLARE @UntilUtc datetimeoffset = SYSUTCDATETIME(); DECLARE @XmlDatabase nvarchar(258) = QUOTENAME(DB_NAME()); DECLARE @XmlSchema nvarchar(258) = QUOTENAME(@SchemaName); DECLARE @XmlTable nvarchar(258) = QUOTENAME(@TableName); DECLARE @XmlIndex nvarchar(258) = QUOTENAME(@IndexName); ;WITH XMLNAMESPACES (DEFAULT 'http://schemas.microsoft.com/sqlserver/2004/07/showplan'), Plans AS ( SELECT query_id, plan_id, is_forced_plan, TRY_CONVERT(xml, query_plan) AS PlanXml FROM sys.query_store_plan ) SELECT p.query_id, p.plan_id, p.is_forced_plan, COALESCE(r.Executions, 0) AS CapturedExecutions, r.FirstIntervalStartUtc, r.LastIntervalEndUtc FROM Plans AS p OUTER APPLY ( SELECT SUM(rs.count_executions) AS Executions, MIN(i.start_time) AS FirstIntervalStartUtc, MAX(i.end_time) AS LastIntervalEndUtc FROM sys.query_store_runtime_stats AS rs JOIN sys.query_store_runtime_stats_interval AS i ON i.runtime_stats_interval_id = rs.runtime_stats_interval_id WHERE rs.plan_id = p.plan_id AND rs.execution_type = 0 AND i.start_time >= @SinceUtc AND i.end_time <= @UntilUtc ) AS r WHERE p.PlanXml.exist(' //RelOp/IndexScan/Object[ @Database = sql:variable("@XmlDatabase") and Schema = sql:variable("@XmlSchema") and @Table = sql:variable("@XmlTable") and @Index = sql:variable("@XmlIndex") ]') = 1 ORDER BY CapturedExecutions DESC, p.query_id, p.plan_id; Read the output in three steps: query_id and plan_id identify the captured plans to inspect. The same query can appear with several plans. CapturedExecutions counts successful executions of those plans in intervals fully inside the requested window. is_forced_plan = 1 highlights a current forcing dependency, even when the plan has no executions in that window. These are plan execution counts, not exact counts of index operator executions: an operator in a conditional branch may not run every time. A missing result does not prove that an index is unused. Check Query Store capture and retention, infrequent jobs, read replicas, index hints and constraints before deciding to remove it. Compare with index usage counters We can also check the current index usage counters. This query provides a second view of the same index: SELECT i.name AS IndexName, u.user_seeks, u.user_scans, u.user_lookups, u.user_updates, u.last_user_seek, u.last_user_scan, u.last_user_lookup, u.last_user_update FROM sys.indexes AS i LEFT JOIN sys.dm_db_index_usage_stats AS u ON u.database_id = DB_ID() AND u.object_id = i.object_id AND u.index_id = i.index_id WHERE i.object_id = OBJECT_ID(N'dbo.TmpOrdersExample_MS') AND i.name = N'IX_TmpOrdersExample_MS_CustomerId'; These counters describe index operations, not distinct queries, and they have their own reset history. They are not limited to the Query Store date window. For a maintenance review, save two snapshots and compare them only after checking for resets or index changes. Use Query Store to identify the queries and these counters to understand the recorded read and write activity. Neither source alone proves that removing an index is safe. Lessons learned A forced plan is a configuration that still has dependencies. In this example, NO_INDEX explains why the intended index could not be used. Query Store shows the latest forcing status and counters, while an event capture provides dated evidence. Before removing an index, inspect recent captured plans and current forcing dependencies, then assess whether the observation period represents the workload that matters. Public references sys.query_store_plan sp_query_store_force_plan Query Store monitoring best practices Extended Events in Azure SQL Create an event session with a ring buffer target sys.query_store_runtime_stats sys.query_store_runtime_stats_interval sys.dm_db_index_usage_stats sys.query_store_query sys.query_context_settingsLessons Learned #556: Finding the SQL Statement Behind a Query Hash in Azure SQL Database
Recently, I worked on a performance investigation in which several queries were identified by their query hashes. The hashes helped us discuss the workload, but the customer still needed to answer a practical question: which SQL statements were behind them? A value such as 0x0123456789ABCDEF does not tell an application developer which statement to review. Fortunately, if Query Store captured the query and still retains it, the customer can use that hash to find the SQL text and the query ID in their own database. In this article, I will show that lookup and explain what to do with the result. The hash used below is a placeholder; replace it with a hash from your investigation. A hash is a lookup key rather than the SQL text A query hash is an eight-byte value derived from the shape of a query. It cannot be decoded back into the original statement. We need a source that stores the relationship between the hash and the text. Query Store provides that relationship through two catalog views. sys.query_store_query contains the query hash and query ID. Its query_text_id links to sys.query_store_query_text, where we can retrieve the SQL text. That gives us a small, read-only query to answer the customer’s question. Find the statement in the correct database Connect directly to the Azure SQL Database that executed the workload, rather than master or another database on the same logical server. Use an account with the permissions required to read Query Store information. Then run the following query, replacing the example hash: DECLARE @QueryHash binary(8) = 0x0123456789ABCDEF; SELECT CONVERT(varchar(18), q.query_hash, 1) AS query_hash, q.query_id, q.context_settings_id, qt.query_sql_text FROM sys.query_store_query AS q JOIN sys.query_store_query_text AS qt ON qt.query_text_id = q.query_text_id WHERE q.query_hash = @QueryHash ORDER BY q.query_id; Use the hexadecimal value with its 0x prefix, as shown, without quotation marks. The returned hash is formatted in the same hexadecimal notation so you can compare it with the original value. This lookup does not need a date filter: it searches the query records that Query Store currently retains. Reviewing performance during a particular incident is the next step, after identifying the matching queries. One hash can return more than one query ID Suppose the lookup returns query IDs 125 and 206. Those are illustrative IDs, but they show an important point: we should inspect both rows rather than select the first one automatically. Each query ID can also have more than one execution plan. This simple lookup intentionally returns query records without joining the plan table, so multiple plans do not repeat the SQL text in the results. Use the query ID to continue in SSMS Once the text is identified, the hash has done its job. In SQL Server Management Studio, expand the database, open Query Store, and select Tracked Queries. Enter a returned query ID and choose the period you want to investigate. From there, review the available execution plans and compare CPU, duration, reads, and execution frequency. Repeat the review for other matching query IDs where necessary. Finding the statement does not prove that it caused a particular resource spike. That conclusion still requires performance statistics and an appropriate time correlation. The useful outcome here is that the customer now knows which SQL statement to review. What if the lookup returns no rows An empty result does not prove that the query never ran. First confirm the database and the hash. Then check whether Query Store captured the query and whether its history remains available. Capture policy, cleanup, or Query Store being disabled during execution can explain a missing record. Enabling Query Store now cannot recreate a statement that was never captured. If the workload runs again, capture it and repeat the lookup after verifying that Query Store is collecting the relevant activity. References sys.query_store_query and the query hash. sys.query_store_query_text and SQL text. Monitor performance using Query Store.
