dans.blog: Find the longest running queries on your MSSQL 2005 Server

[UPDATED: Wednesday, January 21, 2009 at 8:19:25 AM]

I was reading the SQL SERVER - 2008 - 2005 - Find Longest Running Query - TSQL on Pinal Dave's blog and thought I'd run the query on my development machine to see what interesting things I'd fine.

However, right off the bat I was seeing something I thought was odd—my execution times looked way too high. After some quick searching, I confirmed my initial thought that MSSQL reports time in microseconds (which is one millionth of a second or one thousandth of a millisecond.)

For my needs reporting in milliseconds is more than enough, so I revised the query to report the time in milliseconds instead of microseconds. I also made some other modifications so that the query breaks the actual SQL statement and extra parameters into 2 columns (I derived this code from the an article on MSSQLTips.com.) I also added last execution time and minimum elapsed times for the query. I also changed the query to show the results by the average elapsed time—since I occasionally you'll see a single query spike with a high maximum elapsed time that might be due to external circumstances (although this is good to know too.)

Here's my revised version:

select distinct top 10
    substring(t.text, (s.statement_start_offset/2)+1, (((case s.statement_end_offset when -1 then datalength(t.text) else s.statement_end_offset end) - s.statement_start_offset)/2) + 1) as SqlText
    , (case when s.statement_start_offset > 0 then substring(t.text, 0, (s.statement_start_offset/2)+1) else '' end) as SqlParameters
    , s.execution_count as ExecutionCount
    , (s.max_elapsed_time/1000) as MaxElapsedTimeMs
    , (s.min_elapsed_time/1000) as MinElapsedTimeMs
    , isnull((s.total_elapsed_time/1000) / nullif(s.execution_count, 0), 0) as AvgElapsedTimeMs
    , s.creation_time as LogCreatedOn
    , s.last_execution_time as LastExecutionTime
    , isnull(s.execution_count / nullif(datediff(s, s.creation_time, getdate()), 0), 0) as FrequencyPerSec
from
    sys.dm_exec_query_stats as s
        cross apply
    sys.dm_exec_sql_text(s.sql_handle) as t
order by
    isnull((s.total_elapsed_time/1000) / nullif(s.execution_count, 0), 0) desc

UPDATE:
I added another nullif() statement to further prevent divide by zero errors.

One thing to keep in mind is that the DBCC FREEPROCCACHE will clear the cache and reset the log (obviously a reboot of the server or restart of the services would do the same thing.) You may have some maintenance scripts that might issue the DBCC FREEPROCCACHE command, so just keep this in mind when looking at the results.

You can use the query above for lots of purposes. With a little refactoring, you could change the ORDER BY clause to return queries that had executed recently—which can be useful if you're trying to debug a slow running template.

Categories: SQL

5 Comments

Aaron West
Jan 2, 2009 @ 2:12 PM

Dan, this is great stuff. I did not know SQL Server reported execution times in microseconds which makes me wonder if some of the performance conversations between developers and SQL folks at my office didn't have any common ground. Thanks for posting this, I've sent my dev team the posting URL.
Dan G. Switzer, II
Jan 2, 2009 @ 2:38 PM

Aaron:

If the numbers you were passing seemed to be off by a multiple of thousand, then very possible. I knew immediately the numbers looked off to me because it was getting numbers that looked like 2 seconds for a few queries--which I new was wrong. That when I confirmed the numbers were in microseconds, so it was actually 2ms--which seemed much more realistic. :)

Also, this query information is really useful in development. If you change the order by clause to "order by s.last_execution_time desc", then you'll see the last queries run on the box. This can help you find performance issues on a particular query on a page--or just to see the queries that actually ran.
Bill
Jan 20, 2009 @ 10:48 PM

just ran your sql stmt and error occurred..

Msg 8134, Level 16, State 1, Line 1
Divide by zero error encountered.
Dan G. Switzer, II
Jan 21, 2009 @ 8:15 AM

@Bill:

Change the statement:

isnull(s.execution_count / datediff(s, s.creation_time, getdate()), 0) as FrequencyPerSec

to:

nullif(isnull(s.execution_count / datediff(s, s.creation_time, getdate()), 0) as FrequencyPerSec , 0)

That should prevent the error. If you run the query while a query is running for the first time, then that error may occur. Usually refreshing right away resolves the issue.
Dan G. Switzer, II
Jan 21, 2009 @ 8:21 AM

@Bill:

Sorry about that, I screwed that line up, it should be:

, isnull(s.execution_count / nullif(datediff(s, s.creation_time, getdate()), 0), 0) as FrequencyPerSec

I've updated the blog entry with a revised query.

Comments for this entry have been disabled.