When was sys.dm_os_wait_stats last cleared?
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 242273
LAZYWRITER_SLEEP 146010
LOGMGR_QUEUE 145412
DIRTY_PAGE_POLL 145411
XE_TIMER_EVENT 145216
REQUEST_FOR_DEADLOCK_SEARCH 145194
SQLTRACE_INCREMENTAL_FLUSH_SLEEP 144325
SLEEP_TASK 73359
BROKER_TO_FLUSH 73113
PREEMPTIVE_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 10013
LAZYWRITER_SLEEP 8124
SQLTRACE_INCREMENTAL_FLUSH_SLEEP 8017
LOGMGR_QUEUE 7579
DIRTY_PAGE_POLL 7532
XE_TIMER_EVENT 5007
BROKER_TO_FLUSH 4118
SLEEP_TASK 3089
PREEMPTIVE_OS_AUTHENTICATIONOPS 28
SOS_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 15020
LAZYWRITER_SLEEP 14206
LOGMGR_QUEUE 14036
DIRTY_PAGE_POLL 13973
SQLTRACE_INCREMENTAL_FLUSH_SLEEP 12026
XE_TIMER_EVENT 10014
SLEEP_TASK 7207
BROKER_TO_FLUSH 7207
PREEMPTIVE_OS_AUTHENTICATIONOPS 57
SOS_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