Friday, August 5, 2016

Top 10 SQL Server queries in Graphical form


My latest Spatial-Data post SQL Server CPU utilization in Graphical form was pretty popular and I've decided to continue doing SQL Server reporting using spatial capabilities of SSMS.

This time I want to show a query to report top 10 SQL Serve queries in your system.
Will start with a diagram:


At first there is nothing interesting until you learn how to interpret the diagram.
The diagram is reporting three main parameters of SQL Server queries stored in the query plan cache:

1. Horizontal coordinate reports amount of CPU used by particular query. It goes from Left to Right. On this diagram the winner is query #1. It's execution time is way higher than for any other query. Obviously, Query #1 is my CPU eater.

2. Vertical coordinate reports amount of I/O used by particular query.It goes from Bottom to a Top. On this diagram the winner by I/O is query #2. It's I/O usage is higher than for any other query. That is my biggest I/O consumer.

3. Size of a circle indicates number of query executions. Her my winner is query #3. That parameter might not represent well the usage of my resources, but it is something I have to be aware of.

Now, here is a query to produce that diagram:

;WITH total_worker_time as (
 SELECT TOP 10 WITH TIES query_hash
  , execution_count
  , total_worker_time
  , total_logical_reads + total_logical_writes as Total_IO
  , total_elapsed_time
  , total_logical_reads
  , total_logical_writes
  , total_physical_reads
  , max_worker_time
  , max_logical_reads
  , max_logical_writes
  , max_physical_reads
  , max_elapsed_time
  , max_rows
 FROM sys.dm_exec_query_stats qs WITH (NOLOCK)
 ORDER BY total_worker_time DESC
), Total_IO as (
 SELECT TOP 10 WITH TIES query_hash
  , execution_count
  , total_worker_time
  , total_logical_reads + total_logical_writes as Total_IO
  , total_elapsed_time
  , total_logical_reads
  , total_logical_writes
  , total_physical_reads
  , max_worker_time
  , max_logical_reads
  , max_logical_writes
  , max_physical_reads
  , max_elapsed_time
  , max_rows
 FROM sys.dm_exec_query_stats qs WITH (NOLOCK)
 ORDER BY total_logical_reads + total_logical_writes DESC
), CPlans AS (
 SELECT *, ROW_NUMBER() over(order by total_worker_time ) as Weight FROM total_worker_time  UNION ALL
 SELECT *, ROW_NUMBER() over(order by Total_IO ) as Weight FROM Total_IO
), PlanRadius as (
SELECT DISTINCT query_hash
 , execution_count as exec_count
 , total_worker_time/1000000. AS total_worker_time
 , total_elapsed_time/1000000. AS total_elapsed_time
 , Total_IO/128. as Total_IO
 , total_logical_reads/128. as total_logical_reads
 , total_logical_writes/128. as total_logical_writes
 , total_physical_reads/128. as total_physical_reads
 , max_worker_time/1000000. AS max_worker_time
 , max_logical_reads/128. as max_logical_reads
 , max_logical_writes/128. as max_logical_writes
 , max_physical_reads/128. as max_physical_reads
 , max_elapsed_time/1000000. as max_elapsed_time
 , max_rows
FROM CPlans as cp
WHERE cp.query_hash in (SELECT TOP 10 WITH TIES query_hash FROM CPlans GROUP BY query_hash ORDER BY SUM(Weight) DESC)
)
SELECT ROW_NUMBER() over(order by total_worker_time DESC) as Plan_ID
 , exec_count as [# of Executions]
 , CAST(total_worker_time as DECIMAL(9,3)) as [Worker time, Sec]
 , CAST(Total_IO/1024. as DECIMAL(9,3)) as [Total IO, Gb]
  , CAST(max_worker_time as DECIMAL(9,3)) as [Max Worker time, Sec]
 , CAST(total_worker_time/exec_count as DECIMAL(9,3)) as[Avg Worker time, Sec]
 , CAST(total_elapsed_time as DECIMAL(9,3)) as [Elapsed time, Sec]
 , CAST(max_elapsed_time as DECIMAL(9,3)) as [Max Elapsed time, Sec]
 , CAST(total_elapsed_time/exec_count as DECIMAL(9,3)) as [Elapsed time, Sec]
 , CAST(Total_IO/1024./exec_count as DECIMAL(9,3)) as [Average IO, Gb]
 , CAST(total_logical_reads/1024. as DECIMAL(9,3)) as [Logical Reads, Gb]
 , CAST(max_logical_reads/1024. as DECIMAL(9,3)) as [Max Logical Reads, Gb]
 , CAST(total_logical_reads/1024./exec_count as DECIMAL(9,3)) as [Avg Logical Reads, Gb]
 , CAST(total_logical_writes/1024. as DECIMAL(9,3)) as [Logical Writes, Gb]
 , CAST(max_logical_writes/1024. as DECIMAL(9,3)) as [Max Logical Writes, Gb]
 , CAST(total_logical_writes/1024./exec_count as DECIMAL(9,3)) as [Avg Logical Writes, Gb]
 , CAST(total_physical_reads/1024. as DECIMAL(9,3)) as [Physical Reads, Gb]
 , CAST(max_physical_reads/1024. as DECIMAL(9,3)) as [Max Physical Reads, Gb]
 , CAST(total_physical_reads/1024./exec_count as DECIMAL(9,3)) as [Avg Physical Reads, Gb]
 , query_hash
 , Diagram = CONVERT(GEOMETRY,'CURVEPOLYGON(CIRCULARSTRING('
 + CONVERT(VARCHAR,LOG(total_worker_time+1)*500 + LOG(exec_count+10)*5) + ' ' + CONVERT(VARCHAR,LOG(Total_IO+1)*100) + ','
 + CONVERT(VARCHAR,LOG(total_worker_time+1)*500) + ' ' + CONVERT(VARCHAR,LOG(Total_IO+1)*100 + LOG(exec_count+10)*5) + ','
 + CONVERT(VARCHAR,LOG(total_worker_time+1)*500 - LOG(exec_count+10)*5) + ' ' + CONVERT(VARCHAR,LOG(Total_IO+1)*100) + ','
 + CONVERT(VARCHAR,LOG(total_worker_time+1)*500) + ' ' + CONVERT(VARCHAR,LOG(Total_IO+1)*100 - LOG(exec_count+10)*5) + ','
 + CONVERT(VARCHAR,LOG(total_worker_time+1)*500 + LOG(exec_count+10)*5) + ' ' + CONVERT(VARCHAR,LOG(Total_IO+1)*100) + '))')
FROM PlanRadius as p
OPTION (RECOMPILE);

Besides of the diagram that query produces a list of most crucial query characteristics:
As you can see query #1 consumed more than 12.5 seconds of my CPU, query #2 used more than 2Gb of I/O and query #3 has been executed more than 1K times.

As you can guess and see in the query, all parameters are presented in Logarithmic scale to keep sizes and coordinates in manageable format.

What Next?

When we identified the most annoying queries in our system we can run another query to get actual queries' texts and plans. You just have to use value from "query_hash" column to identify the query you want to do a research on:

SELECT DB_NAME(st.dbid) DatabaseNm, st.objectid,
 qs.creation_time,
 cp.cacheobjtype,
 cp.objtype,
 qs.last_execution_time,
 OBJECT_NAME(st.objectid,st.dbid) AS ObjectName, st.TEXT AS SQLBatch,
 SUBSTRING(st.text,1+qs.statement_start_offset/2,
 (CASE qs.statement_end_offset WHEN -1 THEN DATALENGTH(st.text) ELSE qs.statement_end_offset END
 - qs.statement_start_offset)/2) as Query_Text,
 CAST(qp.query_plan as XML) AS query_plan,
 qs.execution_count,
 cp.usecounts AS UseCounts,
 cp.refcounts AS ReferenceCounts,
 qs.max_worker_time,
 qs.last_worker_time,
 qs.total_worker_time,
 qs.total_elapsed_time/1000000 total_elapsed_time_in_S,
 qs.last_elapsed_time/1000000 last_elapsed_time_in_S,
 cp.size_in_bytes/1048576. AS SizeMb,
 qs.total_logical_reads, qs.last_logical_reads,
 qs.total_logical_writes, qs.last_logical_writes,
 qs.[plan_handle]
FROM sys.dm_exec_query_stats qs WITH (NOLOCK)
LEFT JOIN sys.dm_exec_cached_plans AS cp WITH (NOLOCK)
 on qs.[plan_handle] = cp.[plan_handle]
CROSS APPLY sys.dm_exec_sql_text(qs.[plan_handle]) AS st
CROSS APPLY sys.dm_exec_text_query_plan(qs.[plan_handle],qs.statement_start_offset,qs.statement_end_offset) AS qp
WHERE qs.query_hash = 0x52b3b6cede6fc57a
OPTION (RECOMPILE);

Here is the result:

I can click on Query plan XML to get query plan in graphical form:
Or I can copy/paste a query text in SSMS window:

SELECT target_data           
FROM sys.dm_xe_session_targets xet WITH(nolock)           
JOIN sys.dm_xe_sessions xes WITH(nolock)           
ON xes.address = xet.event_session_address           
WHERE xes.name = 'telemetry_xevents'           
AND xet.target_name = 'ring_buffer'

Hope you find it useful for troubleshooting SQL Server performance.

No comments:

Post a Comment