Identifying Queries Running Slower Than Normal

  • mirza.baig

    Grasshopper

    Points: 11

    It would be nice if the Main Article has a line or Item which says" This Application is not for SQL 2000"

  • sginn

    SSC Rookie

    Points: 31

    I've been playing around with it this morning and have already found it helpful. We run massive matching (fuzzy) and deduping jobs that can run for days so tuning for ET is high on our list.

    Thanks.

    Steve

  • jfcarmo

    SSC Enthusiast

    Points: 101

    Hey all..

    Does this work on SqlExpress 2005 ?

    if so, i got the error

    Msg 102, Level 15, State 1, Procedure dba_QueryTimeDelta, Line 49

    Sintaxe incorreta próxima a '.'.

    (incorrect sintax near to '.'.)

    the line is CROSS APPLY sys.dm_exec_sql_text(qs.plan_handle) qt

    looks like sys.dm_exec_sql_text cant be executed or something like that,

    it is on my master, functions and all..

    but still can't run it.

    thx.

  • joelau@toledoblade.com

    Valued Member

    Points: 57

    -- reformat original code from author's Word document.

    -- Hope this help.

    CREATE PROC [dbo].[dba_QueryTimeDelta]

    AS

    /*----------------------------------------------------------------------

    Purpose: Identify queries that are running slower than normal

    , when taking into account IO volumes.

    ------------------------------------------------------------------------

    Parameters: None.

    Revision History:

    13/01/2008 Ian_Stirk@yahoo.com Initial version

    Example Usage:

    1. exec YourServerName.master.dbo.dba_QueryTimeDelta

    ----------------------------------------------------------------------*/

    BEGIN

    -- Do not lock anything, and do not get held up by any locks.

    SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED

    -- Identify queries running slower than normal.

    SELECT TOP 100

    [Runs] = qs.execution_count

    --, [Total time] = qs.total_worker_time - qs.last_worker_time

    , [Avg time] = (qs.total_worker_time - qs.last_worker_time) / (qs.execution_count - 1)

    , [Last time] = qs.last_worker_time

    , [Time Deviation] = (qs.last_worker_time - ((qs.total_worker_time - qs.last_worker_time) / (qs.execution_count - 1)))

    , [% Time Deviation] = CASE WHEN qs.last_worker_time = 0 THEN 100

    ELSE (qs.last_worker_time - ((qs.total_worker_time - qs.last_worker_time) / (qs.execution_count - 1))) * 100

    END / (((qs.total_worker_time - qs.last_worker_time) / (qs.execution_count - 1)))

    , [Last IO] = last_logical_reads + last_logical_writes + last_physical_reads

    , [Avg IO] = ((total_logical_reads + total_logical_writes + total_physical_reads)

    - (last_logical_reads + last_logical_writes + last_physical_reads))

    / (qs.execution_count - 1)

    , [Individual Query] = SUBSTRING (qt.text,qs.statement_start_offset/2,

    (CASE WHEN qs.statement_end_offset = -1

    THEN LEN(CONVERT(NVARCHAR(MAX), qt.text)) * 2

    ELSE qs.statement_end_offset END - qs.statement_start_offset)/2)

    , [Parent Query] = qt.text

    , [DatabaseName] = DB_NAME(qt.dbid)

    INTO #SlowQueries

    FROM sys.dm_exec_query_stats qs

    CROSS APPLY sys.dm_exec_sql_text(qs.plan_handle) qt

    WHERE qs.execution_count > 1

    ORDER BY [% Time Deviation] DESC

    -- Calculate the [IO Deviation] and [% IO Deviation].

    -- Negative values means we did less I/O than average.

    SELECT TOP 100 [Runs]

    , [Avg time]

    , [Last time]

    , [Time Deviation]

    , [% Time Deviation]

    , [Last IO]

    , [Avg IO]

    , [IO Deviation] = [Last IO] - [Avg IO]

    , [% IO Deviation] =

    CASE WHEN [Avg IO] = 0

    THEN 0

    ELSE ([Last IO]- [Avg IO]) * 100 / [Avg IO]

    END

    , [Individual Query]

    , [Parent Query]

    , [DatabaseName]

    INTO #SlowQueriesByIO

    FROM #SlowQueries

    ORDER BY [% Time Deviation] DESC

    -- Extract items where [% Time deviation] less [% IO deviation] is 'large'

    -- These queries are slow running, even when we take into account IO deviation.

    SELECT TOP 100 [Runs]

    , [Avg time]

    , [Last time]

    , [Time Deviation]

    , [% Time Deviation]

    , [Last IO]

    , [Avg IO]

    , [IO Deviation]

    , [% IO Deviation]

    , [Impedance] = [% Time Deviation] - [% IO Deviation]

    , [Individual Query]

    , [Parent Query]

    , [DatabaseName]

    FROM #SlowQueriesByIO

    WHERE [% Time Deviation] - [% IO Deviation] > 20

    ORDER BY [Impedance] DESC

    -- Tidy up.

    DROP TABLE #SlowQueries

    DROP TABLE #SlowQueriesByIO

    END

  • Steve Jones - SSC Editor

    SSC Guru

    Points: 716331

    My apologies for the formatting. I'm not sure what the text editor did to the article, but it has been reformatted to fit on the screen.

  • Anipaul

    SSC-Insane

    Points: 24681

    Thanks for the modification. It was a good article.:)

  • Atif-ullah Sheikh

    SSChampion

    Points: 12495

    Very Helpful Article.

    Will work on it in detail in near future to use it according to my own requirements...

    Atif Sheikh

    ----------------------------------------------------------------------------------------------------------------------------------------------------------------------
    Sometimes, winning is not an issue but trying.
    You can check my BLOG
    [font="Arial Black"]here[/font][/url][/right]

  • Sylvia Moestl Vasilik

    Old Hand

    Points: 384

    This looks like it could be really interesting, but there's bugs in the code. Lots of spaces are missing and cause syntax errors. Also, it needs to be coded to be aware of divide by zero errors.

    I look forward to seeing an updated version of this.

  • Atif-ullah Sheikh

    SSChampion

    Points: 12495

    No error found to me. I copied the code from the attached doc file and it executed well...

    Atif Sheikh

    ----------------------------------------------------------------------------------------------------------------------------------------------------------------------
    Sometimes, winning is not an issue but trying.
    You can check my BLOG
    [font="Arial Black"]here[/font][/url][/right]

  • Jonathan AC Roberts

    SSCoach

    Points: 16964

    I've added a NullIf function to prevent the divide by zero error:-------------------------------------------------------------------------- ----------------------------------------------------------------------------------
    -- Purpose: Identify queries that are running slower than normal,
    -- when taking into account IO volumes.
    --------------------------------------------------------------------------
    ALTER PROC [dbo].[dba_QueryTimeDelta]
    AS
    BEGIN
    -- Do not lock anything, and do not get held up by any locks.
    SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED

    -- Identify queries running slower than normal.
    SELECT TOP(100)
    [Runs] = qs.execution_count,
    -- [Total time] = qs.total_worker_time - qs.last_worker_time,
    [Avg time] = (qs.total_worker_time - qs.last_worker_time) / (qs.execution_count - 1),
    [Last time] = qs.last_worker_time,
    [Time Deviation] = (qs.last_worker_time - ((qs.total_worker_time - qs.last_worker_time) / (qs.execution_count - 1))),
    [% Time Deviation] = CASE WHEN qs.last_worker_time = 0 THEN 100
    ELSE (qs.last_worker_time - ((qs.total_worker_time - qs.last_worker_time) / (qs.execution_count - 1))) * 100
    END / NullIf((((qs.total_worker_time - qs.last_worker_time) / (qs.execution_count - 1))), 0),
    [Last IO] = last_logical_reads + last_logical_writes + last_physical_reads,
    [Avg IO] = ((total_logical_reads + total_logical_writes + total_physical_reads) - (last_logical_reads + last_logical_writes + last_physical_reads)) / (qs.execution_count - 1),
    [Individual Query] = Substring (qt.text,qs.statement_start_offset / 2,
    (CASE WHEN qs.statement_end_offset = -1
    THEN Len(Convert(nvarchar(Max), qt.text)) * 2
    ELSE qs.statement_end_offset
    END - qs.statement_start_offset)/2),
    [Parent Query] = qt.text,
    [DatabaseName] = DB_NAME(qt.dbid)
    INTO #SlowQueries
    FROM sys.dm_exec_query_stats qs
    CROSS APPLY sys.dm_exec_sql_text(qs.plan_handle) qt
    WHERE qs.execution_count > 1
    ORDER BY [% Time Deviation] DESC

    -- Calculate the [IO Deviation] and [% IO Deviation].
    -- Negative values means we did less I/O than average.
    SELECT TOP 100 [Runs],
    [Avg time],
    [Last time],
    [Time Deviation],
    [% Time Deviation],
    [Last IO],
    [Avg IO],
    [IO Deviation] = [Last IO] - [Avg IO],
    [% IO Deviation] = CASE WHEN [Avg IO] = 0 THEN 0
    ELSE ([Last IO]- [Avg IO]) * 100 / [Avg IO]
    END,
    [Individual Query],
    [Parent Query],
    [DatabaseName]
    INTO #SlowQueriesByIO
    FROM #SlowQueries
    ORDER BY [% Time Deviation] DESC

    -- Extract items where [% Time deviation] less [% IO deviation] is 'large'
    -- These queries are slow running, even when we take into account IO deviation.
    SELECT TOP(100)
    [Runs],
    [Avg time],
    [Last time],
    [Time Deviation],
    [% Time Deviation],
    [Last IO],
    [Avg IO],
    [IO Deviation],
    [% IO Deviation],
    [Impedance] = [% Time Deviation] - [% IO Deviation],
    [Individual Query],
    [Parent Query],
    [DatabaseName]
    FROM #SlowQueriesByIO
    WHERE [% Time Deviation] - [% IO Deviation] > 20
    ORDER BY [Impedance] DESC

    -- Tidy up.
    DROP TABLE #SlowQueries
    DROP TABLE #SlowQueriesByIO

    END
    GO

  • Akash Agarwal

    SSC Veteran

    Points: 273

    I m getting ther error on the line

    CROSS APPLY sys.dm_exec_sql_text(qs.plan_handle) qt

    while creating the Proc

    The error is

    Msg 102, Level 15, State 1, Procedure dba_QueryTimeDelta1, Line 49

    Incorrect syntax near '.'.

    Please Guide

    Thanks

    Akash

  • dan.holmes

    SSC Enthusiast

    Points: 124

    This being a proc makes it less usable than it could be. Here is a version that is a view. As a view it can be sorted as necessary and the deviation can be change at invocation as well. I think i moved it around and it is still accurate.

    CREATE VIEW LastExecutionQueryStatsComparedToAvg

    AS

    SELECT [Runs]

    , [Avg time]

    , [Last time]

    , [Time Deviation]

    , [% Time Deviation]

    , [Last IO]

    , [Avg IO]

    , [IO Deviation] = [Last IO] - [Avg IO]

    , [Individual Query]

    , [Parent Query]

    , [DatabaseName]

    , [Last Execution Time]

    , [% IO Deviation] =

    CASE WHEN ([Total IO] - [Last IO]) / (Runs - 1) = 0 THEN 0

    ELSE ([Last IO]- (([Total IO] - [Last IO])

    / (Runs - 1))) * 100 / ([Total IO] - [Last IO])

    / (Runs - 1)

    END

    , [Impedance] = [% Time Deviation] -

    CASE WHEN ([Total IO] - [Last IO]) / (Runs - 1) = 0 THEN 0

    ELSE ([Last IO]- (([Total IO] - [Last IO])

    / (Runs - 1))) * 100 / ([Total IO] - [Last IO])

    / (Runs - 1)

    END

    FROM (

    SELECT

    qs.execution_count Runs

    , [Avg time] = (qs.total_worker_time - qs.last_worker_time) /(qs.execution_count - 1)

    , [Last time] = qs.last_worker_time

    , [Time Deviation] = (qs.last_worker_time - ((qs.total_worker_time - qs.last_worker_time) /(qs.execution_count - 1)))

    , [% Time Deviation] =

    CASE WHEN qs.last_worker_time = 0

    THEN 100

    ELSE (qs.last_worker_time - ((qs.total_worker_time - qs.last_worker_time) /(qs.execution_count - 1)))* 100

    END

    /(((qs.total_worker_time - qs.last_worker_time) /(qs.execution_count - 1)))

    , [Total IO] = (total_logical_reads + total_logical_writes + total_physical_reads)

    , [Last IO] = last_logical_reads + last_logical_writes + last_physical_reads

    , [Avg IO] = ((total_logical_reads + total_logical_writes + total_physical_reads)

    - (last_logical_reads + last_logical_writes + last_physical_reads))

    / (qs.execution_count - 1)

    , [Individual Query] = SUBSTRING (qt.text,qs.statement_start_offset/2,

    (CASE WHEN qs.statement_end_offset = -1

    THEN LEN(CONVERT(NVARCHAR(MAX), qt.text)) * 2

    ELSE qs.statement_end_offset END - qs.statement_start_offset)/2)

    , [Parent Query] = qt.text

    , [DatabaseName] = DB_NAME(qt.dbid)

    , [Last Execution Time] = qs.last_execution_time

    FROM sys.dm_exec_query_stats qs

    CROSS APPLY sys.dm_exec_sql_text(qs.plan_handle) qt

    WHERE qs.execution_count > 1

    ) SlowQueries

  • Jonathan AC Roberts

    SSCoach

    Points: 16964

    Akash Agarwal (8/13/2008)


    I m getting ther error on the line

    CROSS APPLY sys.dm_exec_sql_text(qs.plan_handle) qt

    while creating the Proc

    The error is

    Msg 102, Level 15, State 1, Procedure dba_QueryTimeDelta1, Line 49

    Incorrect syntax near '.'.

    Please Guide

    Thanks

    Akash

    Are you using SQL server 2005?

    It won't work on lower versions.

  • adicks

    SSC Journeyman

    Points: 91

    Thanks for the code, Ian. Really useful.

  • Andy Holliday

    SSC Enthusiast

    Points: 174

    Hi, Very useful script thanks. We're just looking at the results table. Any chance of an explanation of what all the values mean?

    I know it's sorted by impedance by default, but I'm not really sure what this means! It would be useful to know what is considered a high/bad value so we can investigate further.

Viewing 15 posts - 31 through 45 (of 58 total)

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