Take the 2-minute tour ×
Database Administrators Stack Exchange is a question and answer site for database professionals who wish to improve their database skills and learn from others in the community. It's 100% free, no registration required.

When I exec a SQL statement after setting set statistics time on and running dbcc freeproccache and dbcc dropcleanbuffers I get the following output:

DBCC execution completed. If DBCC printed error messages, contact your system administrator.
DBCC execution completed. If DBCC printed error messages, contact your system administrator.
SQL Server parse and compile time: 
   CPU time = 0 ms, elapsed time = 17 ms.

SQL Server Execution Times:
   CPU time = 0 ms,  elapsed time = 1 ms.

SQL Server Execution Times:
   CPU time = 0 ms,  elapsed time = 1 ms.

SQL Server Execution Times:
   CPU time = 0 ms,  elapsed time = 1 ms.

SQL Server Execution Times:
   CPU time = 0 ms,  elapsed time = 1 ms.
SQL Server parse and compile time: 
   CPU time = 796 ms, elapsed time = 891 ms.

SQL Server Execution Times:
   CPU time = 0 ms,  elapsed time = 1 ms.

(0 row(s) affected)

SQL Server Execution Times:
   CPU time = 0 ms,  elapsed time = 9 ms.

SQL Server Execution Times:
   CPU time = 796 ms,  elapsed time = 900 ms.

SQL Server Execution Times:
   CPU time = 0 ms,  elapsed time = 1 ms.

SQL Server Execution Times:
   CPU time = 796 ms,  elapsed time = 917 ms.

I then query the the sys.dm_exec_query_stats table using the following query:

select  
    OBJECT_NAME(q.objectid,q.dbid) AS ProcedureName,  
    highest_cpu_queries.creation_time,
    highest_cpu_queries.total_worker_time,
    highest_cpu_queries.total_elapsed_time,
    highest_cpu_queries.last_worker_time,
    BlockTime = highest_cpu_queries.total_elapsed_time - highest_cpu_queries.total_worker_time,
    highest_cpu_queries.execution_count,
    highest_cpu_queries.total_worker_time / highest_cpu_queries.execution_count AS avg_time,
    highest_cpu_queries.min_worker_time,
    highest_cpu_queries.max_worker_time,
    highest_cpu_queries.max_elapsed_time,
    DB_NAME(q.dbid),
    q.dbid,
    q.objectid, 
    q.number, 
    q.encrypted, 
    q.[text]
from  
    (select top 50  
        qs.plan_handle,  
        qs.creation_time,
        qs.total_worker_time, 
        qs.total_elapsed_time,
        qs.last_worker_time,
        qs.min_worker_time,
        qs.max_worker_time,
        qs.max_elapsed_time,
        qs.execution_count
    from  
        sys.dm_exec_query_stats qs 
    order by qs.total_worker_time desc) as highest_cpu_queries 
    cross apply sys.dm_exec_sql_text(plan_handle) as q 
order by highest_cpu_queries.total_worker_time desc

This returns 1 row as expected (since the dbcc commands reset the view). The total_elapsed_time column shows 8830 (946 total_worker_time + 7884 blocktime).

Total_elapsed_time according to msdn is in microseconds but only accurate to milliseconds.

So this should be 8-9ms. Set Statistics time above is showing 917ms.

My understanding was the dm_exec_query_stats view captures the same numbers as Set Statistics Time. Why are the elapsed times reported different?

share|improve this question
add comment

migrated from stackoverflow.com Oct 27 '11 at 0:45

This question came from our site for professional and enthusiast programmers.

1 Answer

up vote 1 down vote accepted

What version of SQL Server are you using? This is/was a known issue and was fixed in SQL 2008 SP1 but wasn't ported back to SQL 2005.

http://connect.microsoft.com/SQLServer/feedback/details/487838/cpu-time-sys-dm-exec-query-stats-vs-set-statistics-time-on

share|improve this answer
    
yep I'm using SQL 2005. Glad to see this is a bug that was resolved. –  Equixor Dec 25 '11 at 20:09
add comment

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

Not the answer you're looking for? Browse other questions tagged or ask your own question.