Confused about sys.dm_exec_query_stats results

  • I'm running the following in order to get the top CPU-hogging queries:

    SELECT TOP 20 qt.text AS 'SPName', qs.total_worker_time AS 'TotalWorkerTime',

    qs.total_worker_time/qs.execution_count AS 'AvgWorkerTime',

    qs.execution_count AS 'ExecutionCount',

    ISNULL(qs.execution_count/DATEDIFF(Second, qs.creation_time, GetDate()), 0) AS 'CallsPerSecond',

    ISNULL(qs.total_elapsed_time/qs.execution_count, 0) AS 'AvgElapsedTime',

    qs.max_logical_reads, qs.max_logical_writes,

    DATEDIFF(Minute, qs.creation_time, GetDate()) AS 'AgeInCache'

    FROM sys.dm_exec_query_stats AS qs

    CROSS APPLY sys.dm_exec_sql_text(qs.sql_handle) AS qt

    WHERE qt.dbid = db_id()

    ORDER BY qs.total_worker_time DESC

    I'm confused about the results. One particular stored proc makes multiple appearances in the result set.

    The "duplicate" rows returned from the DMV have the same qs.text, the same plan_handle, the same sql_handle, but different statement_start_offset and statement_end_offset. Some of these rows have the same plan_generation_num, and some have different ones.

    I am clueless as to what this means/why it is happening, and am unsure what to google to find out more about it.

    Any pointers would be very much appreciated

    Thanks

    ------------------------------------------------------------------------
    Bite-sized fiction (with added teeth) [/url]

  • mazzz (6/26/2009)


    The "duplicate" rows returned from the DMV have the same qs.text, the same plan_handle, the same sql_handle, but different statement_start_offset and statement_end_offset. Some of these rows have the same plan_generation_num, and some have different ones.

    Multiple statements within the procedure. Each statement gets a different entry in query stats showing the exec stats of that statment. The start and end offset will let you calculate from the sql text which statement is which.

    Gail Shaw
    Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
    SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability

    We walk in the dark places no others will enter
    We stand on the bridge and no one may pass
  • Thanks a bunch Gail

    I should have surmised this from BOL myself, actually *blush*, I don't know why that didn't make sense when I read it earlier. Good job it's Friday

    On a cheerier note, the fact that the results are split this way should prove very useful

    ------------------------------------------------------------------------
    Bite-sized fiction (with added teeth) [/url]

  • mazzz (6/26/2009)


    I should have surmised this from BOL myself, actually *blush*, I don't know why that didn't make sense when I read it earlier.

    When I started playing with these DMVs, it took me a while to figure out what I was seeing too

    Gail Shaw
    Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
    SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability

    We walk in the dark places no others will enter
    We stand on the bridge and no one may pass
  • As Gail pointed out, each entry relates to a specific statement within the procedure. I've modified your query so that it returns the actual statement each entry relates to.

    SELECT TOP 20 object_schema_name(qt.object_id, qt.database_id) + N'.' + object_name(qt.object_id, qt.database_id) AS 'SPName', qt.query_text , qs.total_worker_time AS 'TotalWorkerTime',

    qs.total_worker_time/qs.execution_count AS 'AvgWorkerTime',

    qs.execution_count AS 'ExecutionCount',

    ISNULL(qs.execution_count/DATEDIFF(Second, qs.creation_time, GetDate()), 0) AS 'CallsPerSecond',

    ISNULL(qs.total_elapsed_time/qs.execution_count, 0) AS 'AvgElapsedTime',

    qs.max_logical_reads, qs.max_logical_writes,

    DATEDIFF(Minute, qs.creation_time, GetDate()) AS 'AgeInCache'

    FROM sys.dm_exec_query_stats AS qs

    cross apply msdb.MS_PerfDashboard.fn_QueryTextFromHandle(sql_handle, statement_start_offset, statement_end_offset) as qt

    WHERE qt.database_id = db_id()

    ORDER BY qs.total_worker_time DESC

    If you don't have performance dashboard installed you'll need to manually create the function fn_QueryTextFromHandle.

    use msdb

    go

    if not exists (select * from sys.schemas where name = 'MS_PerfDashboard')

    exec('create schema MS_PerfDashboard')

    go

    if OBJECTPROPERTY(object_id('MS_PerfDashboard.fn_QueryTextFromHandle'), 'IsTableFunction') = 1

    drop function MS_PerfDashboard.fn_QueryTextFromHandle

    go

    CREATE function MS_PerfDashboard.fn_QueryTextFromHandle(@handle varbinary(64), @statement_start_offset int, @statement_end_offset int)

    RETURNS @query_text TABLE (database_id smallint, object_id int, encrypted bit, query_text nvarchar(max))

    begin

    if @handle is not null

    begin

    declare @start int, @end int

    declare @dbid smallint, @objectid int, @encrypted bit

    declare @batch nvarchar(max), @query nvarchar(max)

    -- statement_end_offset is zero prior to beginning query execution (e.g., compilation)

    select

    @start = isnull(@statement_start_offset, 0),

    @end = case when @statement_end_offset is null or @statement_end_offset = 0 then -1

    else @statement_end_offset

    end

    select @dbid = t.dbid,

    @objectid = t.objectid,

    @encrypted = t.encrypted,

    @batch = t.text

    from sys.dm_exec_sql_text(@handle) as t

    select @query = case

    when @encrypted = cast(1 as bit) then N'encrypted text'

    else ltrim(substring(@batch, @start / 2 + 1, ((case when @end = -1 then datalength(@batch)

    else @end end) - @start) / 2))

    end

    -- Found internal queries (e.g., CREATE INDEX) with end offset of original batch that is

    -- greater than the length of the internal query and thus returns nothing if we don't do this

    if datalength(@query) = 0

    begin

    select @query = @batch

    end

    insert into @query_text (database_id, object_id, encrypted, query_text)

    values (@dbid, @objectid, @encrypted, @query)

    end

    return

    end

    go

    GRANT SELECT ON MS_PerfDashboard.fn_QueryTextFromHandle TO public

    go

  • GilaMonster (6/26/2009)


    The start and end offset will let you calculate from the sql text which statement is which.

    I find it unfortunate that the view designers decided to use -1 for the end offset in the case where the statement runs to the end of the batch. This 'magic number' means that we have to include a CASE statement every time together with a call to the DATALENGTH function. Doing that gets old really fast.

    It is also unfortunate the the column containing the batch is called 'text' in the sys.dm_exec_sql_text function. Not only is that a reserved word, it's just odd to see the column defined: text - nvarchar(max). The text datatype may be deprecated, but this could have easily been avoided.

    There, rant over - I feel slightly better. 🙂

    @SQLZ: Nice script and a useful function. 😎

  • Gail - that's made me feel a bit better 🙂

    SQLZ - thanks loads, very useful!

    Paul - heh, I was having the exact sentiments about the -1 offset until SQLZ came to the rescue!

    Thanks everyone!

    ------------------------------------------------------------------------
    Bite-sized fiction (with added teeth) [/url]

  • I run a similar query to yours but I regularly dump that data into a dba database I've created and then I've hooked reporting services into it, which allows me to run useful reports against it that enable me to run trend analysis as well as get the entire text output from query_text, which you can't do in management studio (you're limited to 8000 chars in SSMS).

    Here's another script I find useful that identifies potential missing indexes on the corresponding query when you pass through the plan_handle, which you can get from your query.

    I wouldn't blindly rely on the missing index information but it can be useful in giving you a quick pointer in the right direction.

    declare @plan_handle varbinary(128);

    --get the plan handle from sys.dm_exec_query_stats before running the query below

    select @this_showplan = convert(nvarchar(max), query_plan)

    from sys.dm_exec_query_plan(@plan_handle);

    declare @missing_index table

    ( index_impact numeric

    , target_object_name xml

    , equality_columns varchar(max)

    , inequality_columns varchar(max)

    , included_columns varchar(max)

    )

    insert into @missing_index

    exec sp_executesql @stmt=N'WITH XMLNAMESPACES (''http://schemas.microsoft.com/sqlserver/2004/07/showplan'' AS sp)

    SELECT

    index_node.value(''(../@Impact)[1]'', ''float'') as index_impact,

    index_node.query(''concat(

    string((./@Database)[1]),

    ".",

    string((./@Schema)[1]),

    ".",

    string((./@Table)[1])

    )'') as target_object_name,

    replace(convert(nvarchar(max), index_node.query(''for $colgroup in ./sp:ColumnGroup,

    $col in $colgroup/sp:Column

    where $colgroup/@Usage = "EQUALITY"

    return string($col/@Name)'')), ''] ['', ''],['') as equality_columns,

    replace(convert(nvarchar(max), index_node.query(''for $colgroup in ./sp:ColumnGroup,

    $col in $colgroup/sp:Column

    where $colgroup/@Usage = "INEQUALITY"

    return string($col/@Name)'')), ''] ['', ''],['') as inequality_columns,

    replace(convert(nvarchar(max), index_node.query(''for $colgroup in .//sp:ColumnGroup,

    $col in $colgroup/sp:Column

    where $colgroup/@Usage = "INCLUDE"

    return string($col/@Name)'')), ''] ['', ''],['') as included_columns

    from (select convert(xml, @showplan) as xml_showplan) as t

    outer apply t.xml_showplan.nodes(''//sp:MissingIndexes/sp:MissingIndexGroup/sp:MissingIndex'') as missing_indexes(index_node)'

    ,@params=N'@showplan NVarChar(max)'

    ,@showplan=@this_showplan

    select index_impact

    , convert(varchar(512), target_object_name) as target_object_name

    , equality_columns

    , inequality_columns

    , included_columns

    , @query_text as query_text

    , @last_elapsed_time as last_elapsed_time

    from @missing_index

  • SQLZ (6/26/2009)


    I run a similar query to yours but I regularly dump that data into a dba database I've created and then I've hooked reporting services into it, which allows me to run useful reports against it that enable me to run trend analysis as well as get the entire text output from query_text, which you can't do in management studio (you're limited to 8000 chars in SSMS).

    I've been vaguely planning to set up a db in which to store historical DMV data, might make a starty on that this afternoon, as there's a bit of a lull here at the moment (I'll have jinxed this now, of course).

    I haven't touched Reporting Services so far, you've inspired me to give it a go!

    Here's another script I find useful that identifies potential missing indexes on the corresponding query when you pass through the plan_handle, which you can get from your query.

    I wouldn't blindly rely on the missing index information but it can be useful in giving you a quick pointer in the right direction.

    Thanks a bunch again, that will be very useful too - seeing as most of our databases are sorely lacking in the index department *sigh*

    ------------------------------------------------------------------------
    Bite-sized fiction (with added teeth) [/url]

  • Hey mazzz,

    Take a look at the huge library of generally useful scripts also available for free on this very site - see the scripts link on the sidebar

    <--- over there!

    Paul

    P.S. My SSMS can display 64K text and 'unlimited' XML (so it says) 😛

  • mazzz (6/26/2009)


    I've been vaguely planning to set up a db in which to store historical DMV data, might make a starty on that this afternoon, as there's a bit of a lull here at the moment (I'll have jinxed this now, of course).

    I haven't touched Reporting Services so far, you've inspired me to give it a go!

    It's very handy. Nothing like having all the performance reports run overnight and be sitting waiting in your mailbox in the morning.

    Gail Shaw
    Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
    SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability

    We walk in the dark places no others will enter
    We stand on the bridge and no one may pass
  • Paul White (6/26/2009)


    Hey mazzz,

    Take a look at the huge library of generally useful scripts also available for free on this very site - see the scripts link on the sidebar

    <--- over there!

    Thanks Paul, now there's a way to spend a quiet Friday afternoon!

    ------------------------------------------------------------------------
    Bite-sized fiction (with added teeth) [/url]

  • GilaMonster (6/26/2009)


    It's very handy. Nothing like having all the performance reports run overnight and be sitting waiting in your mailbox in the morning.

    I don't doubt that for a second, now if only I could convince management that this would be a useful way to spend my time, despite not being able to charge my hours to anyone...

    ------------------------------------------------------------------------
    Bite-sized fiction (with added teeth) [/url]

Viewing 13 posts - 1 through 12 (of 12 total)

You must be logged in to reply to this topic. Login to reply