First published on MSDN on Oct 20, 2010
I was posed a good question today about how the wait_info* event works in SQL Server 2008. The easiest way for me to answer the question was to prove the behavior. using WAITFOR DELAY it shows the behavior nicely.
From:
Robert Dorr
Sent:
Wednesday, October 20, 2010 2:07 PM
Subject:
RE: Extended Events
The wait types are similar to those exposed in sys.dm_os_wait_stats.
The code shows me that: completed_count = Number of times the action has been completed. In this case of something like (NETWORK_IO) SQL checked and made sure lots have completed. The wait time for many of these could have been 0 (already completed).
You can use the WAITFOR action to determine the behavior. You can see below that I waited for 5 seconds and the outputs show the MS values.
select * from sys.dm_os_wait_stats
where wait_type = 'WAITFOR'
go
waitfor delay '00:00:05'
go
select * from sys.dm_os_wait_stats
where wait_type = 'WAITFOR'
go
create event session WaitTest on server
add event sqlos.wait_info
add target package0.asynchronous_file_target
(set filename=N'c:tempWait.xel')
with (max_dispatch_latency=1 seconds)
go
alter event session WaitTest on server state = start
alter event session WaitTest on server state = stop
select * from fn_xe_file_target_read_file('c:temp*.xel', 'c:temp*.xem', NULL, NULL)
where event_data like '%5000%'
go
<event name="wait_info" package="sqlos" id="48" version="1" timestamp="2010-10-20T19:02:31.797Z">
<data name="wait_type">
<value>189</value><text><![CDATA[WAITFOR]]></text></data>
<data name="opcode"><value>1</value>
<text><![CDATA[End]]></text></data>
<data name="duration"><value>5000</value><text></text></data>
<data name="max_duration"><value>5000</value><text></text></data>
<data name="total_duration"><value>20001</value><text></text></data>
<data name="signal_duration"><value>0</value><text></text></data>
<data name="completed_count"><value>4</value><text></text></data>
</event>
Bob Dorr - Principal SQL Server Escalation Engineer
