The sys.dm_os_wait_stats DMV provides essential metrics for diagnosing SQL Server performance problems. Returning incrementally accumulating information about all the completed waits encountered by executing threads it is a useful way to identify bottlenecks such as IO latency issues or waits on locks. The counters are reset each time SQL server is restarted, or when the following command is run:
DBCC SQLPERF ('sys.dm_os_wait_stats', CLEAR);
To make sense out of these wait values you need to know how they change over time. Suppose you are asked to troubleshoot a system and you don't know when the wait stats were last zeroed. Is there any way to find the elapsed time since this happened?
If the wait stats were not cleared using the DBCC SQLPERF command then you can simply correlate the stats with the time SQL Server was started using the sqlserver_start_time column introduced in SQL Server 2008 R2:
SELECT sqlserver_start_time from sys.dm_os_sys_info
However how do you tell if someone has run DBCC SQLPERF ('sys.dm_os_wait_stats', CLEAR) since the server was started, and if they did, when? Without this information the initial, or historical, wait_stats have less value until you can measure deltas over time.
There is a way to at least estimate when the stats were last cleared, by using the wait stats themselves and choosing a thread that spends most of its time sleeping. A good candidate is the SQL Trace incremental flush task, which mostly sleeps (in 4 second intervals) and in between it attempts to flush (if there are new events – which is rare when only default trace is running) – so it pretty much sleeps all the time. Hence the time it has spent waiting is very close to the elapsed time since the counter was reset. Credit goes to Ivan Penkov in the SQLOS dev team for suggesting this.
Here's an example (excuse formatting):
144 seconds after the server was started:
select top 10 wait_type, wait_time_ms from sys.dm_os_wait_stats order by wait_time_ms desc
wait_type wait_time_ms---------------------------------------------------------------------------------------------------------------
XE_DISPATCHER_WAIT 242273LAZYWRITER_SLEEP 146010LOGMGR_QUEUE 145412DIRTY_PAGE_POLL 145411XE_TIMER_EVENT 145216REQUEST_FOR_DEADLOCK_SEARCH 145194SQLTRACE_INCREMENTAL_FLUSH_SLEEP 144325SLEEP_TASK 73359BROKER_TO_FLUSH 73113PREEMPTIVE_OS_AUTHENTICATIONOPS 143
(10 rows affected)
Reset:
DBCC SQLPERF('sys.dm_os_wait_stats', CLEAR)"
DBCC execution completed. If DBCC printed error messages, contact your system administrator.
After 8 seconds:
select top 10 wait_type, wait_time_ms from sys.dm_os_wait_stats order by wait_time_ms desc
wait_type wait_time_ms---------------------------------------------------------------------------------------------------------------------
REQUEST_FOR_DEADLOCK_SEARCH 10013LAZYWRITER_SLEEP 8124SQLTRACE_INCREMENTAL_FLUSH_SLEEP 8017LOGMGR_QUEUE 7579DIRTY_PAGE_POLL 7532XE_TIMER_EVENT 5007BROKER_TO_FLUSH 4118SLEEP_TASK 3089PREEMPTIVE_OS_AUTHENTICATIONOPS 28SOS_SCHEDULER_YIELD 27
(10 rows affected)
After 12 seconds:
select top 10 wait_type, wait_time_ms from sys.dm_os_wait_stats order by wait_time_ms desc
wait_type wait_time_ms------------------------------------------------------------------------------------------------------
REQUEST_FOR_DEADLOCK_SEARCH 15020LAZYWRITER_SLEEP 14206LOGMGR_QUEUE 14036DIRTY_PAGE_POLL 13973SQLTRACE_INCREMENTAL_FLUSH_SLEEP 12026XE_TIMER_EVENT 10014SLEEP_TASK 7207BROKER_TO_FLUSH 7207PREEMPTIVE_OS_AUTHENTICATIONOPS 57SOS_SCHEDULER_YIELD 28
(10 rows affected)
It may not be accurate to the millisecond, but it can provide a useful data point, and give an indication whether the wait stats were manually cleared after startup, and if so approximately when.
- Guy
Originally posted at http://blogs.msdn.com/b/sqlosteam/
