SQLServerPedia

In part 2 of this series, we looked at applying the query pattern concept to the procedure cache. This allows us to aggregate “semi” historical data to help guide us in the best direction in our tuning efforts. Sometimes we would want to do something similar with DMV’s that contain real time data.

We will be looking at summarizing data from the DMV, sys.dm_os_memory_grants over time. In SQL 2000 this information was only available through the integer column of the DOP event class. You can still do this in 2005. It is not easy. If you have a large amount of data, set aside hours for analysis. Anything is possible but I can think of a way to automate this easily.

We can go into a WHILE loop with a WAITFOR and monitor sys.dm_os_memory_grants for a period of time to get a trend. This can be huge compared to just eyeballing this DMV. First, let’s eyeball it. Keep in mind, it may not even return any rows.

--Find queries that have granted memory or waiting on memory.

--An xml showplan is important so we can see the cause of large memory needs like hash or sorts.

select text, query_plan, granted_memory_kb, used_memory_kb, wait_time_ms

from sys.dm_exec_query_memory_grants mg

CROSS APPLY sys.dm_exec_sql_text(mg.sql_handle)  t

CROSS APPLY sys.dm_exec_query_plan(mg.plan_handle) q

Now let’s look at the query pattern method. This would be use full in optimizing the memory subsystem or in trying to resolve memory grant and resource semaphore waits.

--Now let's create the work table.

--Create work table

CREATE TABLE [dbo].[#mg_sig](

       [sig] [nvarchar](max) COLLATE Latin1_General_CI_AI NULL,

       [text] [nvarchar](max) COLLATE Latin1_General_CI_AI NULL,

       [query_plan] [xml] NULL,

       [granted_memory_kb] [bigint] NULL,

       [used_memory_kb] [bigint] NULL,

       [wait_time_ms] [bigint] NULL,

       [csum] [bigint] NULL

)

--begin loop

--Arbitrary @ctr and delay. Adjust as you see fit.

declare @ctr int

select @ctr = 100

while @ctr > 0

begin

       insert into #mg_sig (sig, text, query_plan, granted_memory_kb, used_memory_kb, wait_time_ms, csum)

       select dbo.fn_SQLSigTSQL(text, 4000) as sig

              , text

              , query_plan

              , granted_memory_kb

              , used_memory_kb

              , wait_time_ms

              , checksum(dbo.fn_SQLSigTSQL(text, 4000)) as csum

       from sys.dm_exec_query_memory_grants mg

       CROSS APPLY sys.dm_exec_sql_text(mg.sql_handle)  t

       CROSS APPLY sys.dm_exec_query_plan(mg.plan_handle)

select @ctr = @ctr-1

waitfor delay '00:00:30'

end

--Now let's roll it up and include the xml plan

select dt1.sig, dt1.total_granted_memory_kb, dt1.total_wait_time_ms, convert(xml,dt2.query_plan)

from

(

select iq.sig

       , iq.csum

       , sum(iq.granted_memory_kb) as total_granted_memory_kb

       , sum(iq.wait_time_ms)  as total_wait_time_ms

from #mg_sig as iq

group by iq.sig, iq.csum

) as dt1

inner join

(

select s2.csum, convert(varchar(max),query_plan) as query_plan

from #mg_sig s2

group by csum, convert(varchar(max),query_plan)

) as dt2

on dt1.csum = dt2.csum

Note: This is a bug with the xml datatype that is supposed to be resolved in SP2 so sometimes you may get an error.

I am posting up a tool I commonly use. It shows recent historically execution stats.

pExecStats – Displays historic execution data based on what is in the procedure cache. Limitation include plans that are not reused return multiple rows.

Parameters:

@Sort CHAR(1) – C =CPU(Default), R =Reads, D = Duration, E = Execution Count

@xml BIT – not null = returns xml plan. Null(default) = no xml plan

Usage example:

exec pexecstats --Order by CPU

exec pexecstats 'r' --order by reads

exec pexecstats 'd' -- order by duration

exec pexecstats 'c', 1 -- order by execution count and include xml plan

Download here.

I have two complaints about the documentation. Incomplete BOL and little info on the myriad of trace flags that is growing with every other QFE. From my understanding, the documentation for SQL 2005 was locked down in April of 2005 and the product went RTM in November of 2005. They obviously had more important things....

In part 1 of this series, I described the concept of tuning query pattern instead of single queries. You would use these techniques when you have already identified where the bottlenecks are. Going backwards, that will be the topic of a future blog.

In part 2, we will use this technique to identify which queries are chewing up procedure cache resources, both CPU cycles and memory consumption. We will be using sys.dm_exec_query_stats along with a support cast of DMV’s and a few compatibility views.

Please be sure you have already ready created fn_tsqlsig() as described in  part 1. To illustrate the need for working with patterns, let’s start off with this modified query from the SQL Tips Blog.

select qs.sql_handle, qs.execution_count

     , qs.total_elapsed_time, qs.last_elapsed_time

     , qs.min_elapsed_time, qs.max_elapsed_time

     , qs.total_clr_time, qs.last_clr_time

     , qs.min_clr_time, qs.max_clr_time

     , substring(st.text, (qs.statement_start_offset/2)+1

                        , ((case qs.statement_end_offset

                              when -1 then datalength(st.text)

                              else qs.statement_end_offset

                           end - qs.statement_start_offset)/2) + 1) as statement_text

  from sys.dm_exec_query_stats as qs

  cross apply sys.dm_exec_sql_text(qs.sql_handle) as st

where qs.execution_count = 1

It is all fine and dandy but what if you 30,000 rows returned. You could sort by qs.text and eye ball it or you could LEFT and GROUP BY. You have to create query signatures.

Now let’s get everything we could need and dump it into a temp table because it is expensive and time consuming to do all of the string manipulation in tsql.

--dbo.fn_SQLSigTSQL replaces the literals with #.

select dbo.fn_SQLSigTSQL(substring(st.text, (qs.statement_start_offset/2)+1

                        , ((case qs.statement_end_offset

                              when -1 then datalength(st.text)

                              else qs.statement_end_offset

                           end - qs.statement_start_offset)/2) + 1), 4000) as statement_signature

,      SUM(cp.usecounts) as TotalExec--How many times am I in cache with one execution count

,      SUM(qs.total_worker_time) as TotalCPU--How much CPU? Note: This contains execution ticks only.

,      SUM(qs.total_physical_reads+qs.total_logical_reads) as TotalReadIO--You may want to break these up.

,      SUM(cp.size_in_bytes) as TotalPlanMemory --The memory footprint on the query pattern

into #proccache_sig –This is our work table.

from sys.dm_exec_query_stats as qs

inner join sys.dm_exec_cached_plans as cp on qs.plan_handle = cp.plan_handle

cross apply sys.dm_exec_sql_text(qs.sql_handle) as st

where cp.usecounts = 1

group by dbo.fn_SQLSigTSQL(substring(st.text, (qs.statement_start_offset/2)+1

                        , ((case qs.statement_end_offset

                              when -1 then datalength(st.text)

                              else qs.statement_end_offset

                           end - qs.statement_start_offset)/2) + 1), 4000)

Now that we have everything into a work table, we can easily report on it without having to do expensive string manipulations again.

--Which queries need to be converted to a stored proc?

--Do we need to identify why it is recompiling?

select statement_signature, TotalExec

from #proccache_sig

order by 2 desc

--Which plan is taking up the most memory in proc cache?

--Is it due to the size of the plan or number of entries?

select statement_signature, TotalPlanMemory, TotalExec

from #proccache_sig

order by 2 desc

--Which query is using the most CPU?

select statement_signature, TotalCPU

from #proccache_sig

order by 2 desc

--Which query is using the most Read IO?

select statement_signature, TotalReadIO

from #proccache_sig

order by 2 desc

There are limitations of this method. They are explained in detail in Bart Duncan’s Chapter of SQL Server 2005 Practical Troubleshooting: The Database Engine. They included the fact that the procedure cache does not cache everything, plans can churn at anytime and if constrained, the proc cache may only contain a short period of stats due to the high churn. Both of these can be overcomed by applying the query pattern concept to a huge trace covering hours or a day’s worth of data. Another workaround is putting the above query in a loop with a delay and grabbing a sample every 30 minutes(or more or less). We will see an example of this in the next blog when we work with DMV's containing "right now" data.

Not only can some of this be applied to syscacheobjects, if you are just looking at execution count, I have found that to be less intensive on the server.

Itzik Ben-Gan describes a method of analyzing trace files in his book "Inside Microsoft SQL Server 2005: T-SQL Querying" He provides a couple functions for stripping the literals from queries in the TextData column. If you do not use one of these functions or one of your own similar tools, you are not being very effective in your trace analyisis. The first one is from Microsoft PSS and can be downloaded here. The second one is a CLR function that uses regex. It performs much better. His book is worth it just for this function.

Here is the concept: Tuning single queries can be insane ineffective for multiple reasons. When facing a performance problem, you should be looking at query patterns that way to can get the biggest bang in the shortest amount of time.

Here is a simple trace analysis query using the PSS function.

-- Generate pattern and order by highest CPU

-- This is long running so you may want to dump it into a table.

--http://statisticsio.com/files/patterns/fn_tsqlsig.sql

SELECT dbo.fn_SQLSigTSQL(textdata, 4000)

, SUM(CPU)

, COUNT(*)

FROM dbo.trace_table

GROUP BY dbo.fn_SQLSigTSQL(textdata, 4000)

order by CPU DESC

Check out Itzak's book for more info on trace analysis. In this series on blog's, we will look at applying this concept to data in the DMV.