Part 2 of this series is going to focus on Query Store and the execution statistics available to analyse performance. Without going into too much about query store, think of it as a flight recorder for the database its enabled on.
The quickest way to take a look inside query store (when its enabled) is to use the built in ssms reports :
Straight off the bat Top Resource Consuming Queries is a great report as it shows duration over time as well as execution plans involved.
Very simple to use, and quite flexible in the fact you can sort my numerous resource consumption criteria.
You can see object_name is present. That’s how you can link the query to the stored proc. The problem however is there is no way to search query store for the object name via the gui.
Via extended events you can quickly grab the t-sql behind these reports. The TSQL XEvent Profiler session is good enough here. Enable it and then open the report Top Resource Consuming Queries. Return back to the XE Live data screen and you can find the t-sql behind this report:
Copy the cell text and you have the t-sql driving these reports.
I will now demonstrate below how you can query the query store DMV’s effectively with an example proc using the StackOVerflow2013 database and show how to spot plan changes and force good plans.
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 |
–Table Setup IF OBJECT_ID(‘[dbo].[Posts_test]’) IS NOT NULL DROP TABLE [dbo].[Posts_test] CREATE TABLE [dbo].[Posts_test]( [Id] [int] NOT NULL, [AcceptedAnswerId] [int] NULL, [AnswerCount] [int] NULL, [Body] [nvarchar](max) NOT NULL, [ClosedDate] [datetime] NULL, [CommentCount] [int] NULL, [CommunityOwnedDate] [datetime] NULL, [CreationDate] [datetime] NOT NULL, [FavoriteCount] [int] NULL, [LastActivityDate] [datetime] NOT NULL, [LastEditDate] [datetime] NULL, [LastEditorDisplayName] [nvarchar](40) NULL, [LastEditorUserId] [int] NULL, [OwnerUserId] [int] NULL, [ParentId] [int] NULL, [PostTypeId] [int] NOT NULL, [Score] [int] NOT NULL, [Tags] [nvarchar](150) NULL, [Title] [nvarchar](250) NULL, [ViewCount] [int] NOT NULL ) create clustered index CIX_POSTS_TEST_ID on dbo.posts_test (ID) GO INSERT INTO dbo.posts_test ([id], [acceptedanswerid], [answercount], [body], [closeddate], [commentcount], [communityowneddate], [creationdate], [favoritecount], [lastactivitydate], [lasteditdate], [lasteditordisplayname], [lasteditoruserid], [owneruserid], [parentid], [posttypeid], [score], [tags], [title], [viewcount]) SELECT TOP (10) [id], –5000000 [acceptedanswerid], [answercount], [body], [closeddate], [commentcount], [communityowneddate], [creationdate], [favoritecount], [lastactivitydate], [lasteditdate], [lasteditordisplayname], [lasteditoruserid], [owneruserid], [parentid], [posttypeid], [score], [tags], [title], [viewcount] FROM dbo.posts |
Stored Proc
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 |
–Example Proc IF OBJECT_ID(‘dbo.Qs_test’) IS NOT NULL DROP procedure dbo.Qs_test go CREATE PROC dbo.Qs_test @top INT AS SELECT * FROM dbo.posts_test pt join dbo.Posts p on pt.Id = p.id WHERE pt.id < @top –Execute with 10 rows exec dbo.QS_Test @top = 10 |
Table Stats pre execution:
I can see from the proc cache the query executes in 1.34 ms :
Query store shows the same and 1 plan :
Insert more rows into dbo.posts:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 |
INSERT INTO dbo.posts_test ([id], [acceptedanswerid], [answercount], [body], [closeddate], [commentcount], [communityowneddate], [creationdate], [favoritecount], [lastactivitydate], [lasteditdate], [lasteditordisplayname], [lasteditoruserid], [owneruserid], [parentid], [posttypeid], [score], [tags], [title], [viewcount]) SELECT TOP (500000) 100 as [id], –5000000 [acceptedanswerid], [answercount], [body], [closeddate], [commentcount], [communityowneddate], [creationdate], [favoritecount], [lastactivitydate], [lasteditdate], [lasteditordisplayname], [lasteditoruserid], [owneruserid], [parentid], [posttypeid], [score], [tags], [title], [viewcount] FROM dbo.posts where Id > 20 |
Table Stats are the same, although sys.dm_db_stats_properties is showing row modifications:
Now i execute the proc with a different parameter value
|
1 |
exec dbo.QS_Test @top = 50000 |
Auto Statistics update is enabled on the database, hence the update stats operation happening before execution. It is important to note a statistics update is triggered when cost-based optimization finds that interesting statistics for the query are stale only.
We can now see the second execution in the cache and query store:
Over on the right you can see two Plan ID’s. This makes it really easy to spot plan regression. Once you have found the ‘optimal plan’, simply click the button force plan and that plan will be used in subsequent executions, unless plan forcing is prevented. This example only shows plan variation and how to force a good plan. Don’t assume Plan 3 is more optimal based on the example.
Moving back to the DMV’s, using a filter on object_id is the best way to find all executions with a given proc name
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 |
SELECT OBJECT_NAME(object_id) ‘Proc’, query_store_plan.query_id, DATEADD(hh, DATEDIFF(hh, GETUTCDATE(), GETDATE()), query_store_runtime_stats.last_execution_time) AS last_execution_time, count_executions, last_rowcount, max_rowcount, –,last_compile_batch_sql_handle last_query_max_used_memory, last_compile_memory_kb, last_logical_io_reads, last_log_bytes_used, last_tempdb_space_used, max_tempdb_space_used, query_sql_text, query_store_plan.plan_id, TRY_CONVERT(XML, query_plan) AS [PLAN] FROM sys.query_store_query LEFT JOIN sys.query_store_query_text ON query_store_query.query_text_id = query_store_query_text.query_text_id LEFT JOIN sys.query_store_plan ON query_store_query.query_id = query_store_plan.query_id LEFT JOIN sys.query_store_runtime_stats ON query_store_plan.plan_id = query_store_runtime_stats.plan_id LEFT JOIN sys.query_store_runtime_stats_interval ON query_store_runtime_stats.runtime_stats_interval_id = query_store_runtime_stats_interval.runtime_stats_interval_id WHERE OBJECT_NAME(object_id) LIKE ‘%ReportPack%’ AND query_store_runtime_stats.last_execution_time > GETDATE() – 6 ORDER BY query_store_runtime_stats.max_duration / 1000 DESC; |
You can also see different plans are involved here due to multiple plan_id’s for the same query_id.
From 2017 sys.query_store_wait_stats became available. Incredibly useful as you it allows you to see which category your queries are waiting on:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 |
DECLARE @StartDate DATETIME = GETDATE()–7 DECLARE @EndtDate DATETIME = GETDATE() SELECT TOP (10) ws.wait_category_desc ,ws.avg_query_wait_time_ms/60000. avg_wait_mins ,ws.total_query_wait_time_ms/60000. total_wait_mins ,ws.plan_id ,rs.count_executions ,qt.query_sql_text ,rsi.start_time ,rsi.end_time ,OBJECT_SCHEMA_NAME(q.object_id) sch ,OBJECT_NAME(q.object_id) obj ,TRY_CONVERT(XML, qp.query_plan) AS qplan FROM sys.query_store_query_text qt JOIN sys.query_store_query q ON qt.query_text_id = q.query_text_id JOIN sys.query_store_plan qp ON q.query_id = qp.query_id JOIN sys.query_store_runtime_stats rs ON qp.plan_id = rs.plan_id JOIN sys.query_store_runtime_stats_interval rsi ON rs.runtime_stats_interval_id = rsi.runtime_stats_interval_id JOIN sys.query_store_wait_stats ws ON ws.runtime_stats_interval_id = rs.runtime_stats_interval_id AND ws.plan_id = qp.plan_id WHERE rsi.start_time > @StartDate AND rsi.end_time < @EndtDate AND ws.execution_type = 0 — Successful execution. AND OBJECT_NAME(q.object_id) = ‘QS_Test’ ORDER BY ws.avg_query_wait_time_ms DESC; |
On a final note, grouping the query’s by object name and date, you can start to see a daily picture of how your procs are performing.
|
1 2 3 4 5 6 7 8 9 10 11 12 |
FROM sys.query_store_query LEFT JOIN sys.query_store_query_text ON query_store_query.query_text_id = query_store_query_text.query_text_id LEFT JOIN sys.query_store_plan ON query_store_query.query_id = query_store_plan.query_id LEFT JOIN sys.query_store_runtime_stats rs1 ON query_store_plan.plan_id = rs1.plan_id LEFT JOIN sys.query_store_runtime_stats_interval ON rs1.runtime_stats_interval_id = query_store_runtime_stats_interval.runtime_stats_interval_id WHERE OBJECT_NAME(object_id) LIKE @proc AND rs1.last_execution_time > GETDATE() – @days GROUP BY OBJECT_NAME(object_id),CONVERT(DATE,DATEADD(hh, DATEDIFF(hh, GETUTCDATE(), GETDATE()), rs1.last_execution_time)) |
I liker to play around with this stuff. Aggregating query store isn’t the most intuitive. I am constantly updating these to see how I can get the most out of QS. Hopefully you can use these too.