Knowing just how long an event takes is a common requirement when troubleshooting. Sometimes, figuring out the unit of time is a bit troublesome. Is it milliseconds, seconds or microseconds?
It is really easy to mistakenly use milliseconds when microseconds is required. It is also really easy to forget that one event is measured in seconds while another might be measured in milliseconds. To add to the confusion, what if the unit of measure changes between one version of SQL Server and the next?
While none could think it should be easy and consistent to figure out time, sometimes it just takes a little more effort. The same unit of time just isn’t applicable for every type of event. That is not just true in SQL Server but in life in general. You wouldn’t want to use hours when timing muzzle velocity, but hours could be entirely applicable to a surgery or training seminar.
Where does that leave us SQL Geeks when looking at timing of internal events inside of SQL Server? Well, we either need to do a little digging or we could simply read the rest of this article to find a simple script that can do the bulk of the work for us.
When dealing with events inside of SQL Server, the tool of choice to use is Extended Events (XE). If you are unfamiliar with XE, I really encourage you to take a look at these resources to become more familiar with the tool.
Time
None of us want to translate or interpret time incorrectly. Imagine the CIO looming over your shoulder asking how long before the database is back online. If you miscalculate the time and tell him 30 seconds when it really is 5 hours, the level of frustration and anger probably becomes exponentially worse.
While that may seem like a bit of an exaggeration, it’s not an experience any DBA likes to encounter. On a slightly smaller scale, when a developer asks how long a piece of code is running in production, you do want to be as accurate as possible. If the code takes 5 minutes to execute, the developer needs to know it was 5 minutes and not a miscalculated 3.9 seconds. 3.9 seconds may be entirely within the realm of acceptable for the project and thus be dismissed by the development team.
While trapping the precise time and calculating it may seem trivial, it is important (as previously mentioned) to use the correct time unit. There are many events within XE that provide a time unit of measure. The unit of measure is different through most of the events so a different calculation may be required depending on what you are troubleshooting at the moment.
Thankfully, there is some means to figure out if the time measurement is in seconds, milliseconds, microseconds or something different. We just need to pull it all out from the metadata views. Here is how we get to that data.
DECLARE @ServerMajorVersion DECIMAL(4, 2)
SELECT @ServerMajorVersion = CONVERT(DECIMAL(4, 2), PARSENAME(dt.fqn, 4) + '.'
+ PARSENAME(dt.fqn, 3))
FROM ( SELECT CONVERT(VARCHAR(20), SERVERPROPERTY('ProductVersion'))
) dt ( fqn );
SELECT CASE WHEN @ServerMajorVersion = 15.00 THEN 'SQL Server 2019'
WHEN @ServerMajorVersion = 14.00 THEN 'SQL Server 2017'
WHEN @ServerMajorVersion = 13.00 THEN 'SQL Server 2016'
WHEN @ServerMajorVersion = 12.00 THEN 'SQL Server 2014'
WHEN @ServerMajorVersion = 11.00 THEN 'SQL Server 2012'
END AS SQLVer
, @ServerMajorVersion AS SvrVersion
, xp.name package_name
, xo.name event_name
, xoc.name event_field
, DurationUnit =
CASE WHEN xoc.description LIKE '%milliseconds%'
THEN 'MilliSeconds'
WHEN xoc.description LIKE '%microseconds%'
THEN 'MicroSeconds'
WHEN xoc.description LIKE '%seconds%'
THEN 'Seconds'
ELSE NULL
END
, xoc.type_name AS DataType
, xoc.description AS DurationDesc
, xo.description AS PayloadDesc
, ch.Channel
, ca.map_value AS SearchKeyword
FROM sys.dm_xe_objects xo
INNER JOIN sys.dm_xe_packages xp
ON xo.package_guid = xp.guid
INNER JOIN sys.dm_xe_object_columns xoc
ON xo.name = xoc.object_name
OUTER APPLY (SELECT TOP 1 mv.map_value
FROM sys.dm_xe_object_columns occ
INNER JOIN sys.dm_xe_map_values mv
ON occ.type_name = mv.name
AND occ.column_value = mv.map_key
WHERE occ.name = 'KEYWORD'
AND occ.object_name = xoc.object_name) ca
INNER JOIN (SELECT c.object_name AS EventName,c.object_package_guid AS PkgGuid, v.map_value AS Channel
FROM sys.dm_xe_object_columns c
INNER JOIN sys.dm_xe_map_values v
ON c.type_name = v.name
AND c.column_value = CAST(v.map_key AS NVARCHAR)
WHERE c.name = 'channel') ch
ON ch.EventName = xoc.object_name
AND ch.PkgGuid = xoc.object_package_guid
WHERE xo.object_type = 'event'
AND xoc.name = 'duration'
ORDER BY xp.name,xo.name;Holy crap! That doesn’t look easy. That is a ton more code than you might have expected. True. However, I like to have as much information as possible at my finger tips. In this case, I want to know the SQL Server version, channels, and search terms (keywords) related to the event.
Why have the extra data? When troubleshooting, it is nice to know if there are other events that might be related in nature that could shed a bit more light on the problem from a different angle. The use of keywords (think google search) and channels is perfect for helping me find those other events.
Here is what a snippet of that data might look like.
With this snippet, I can see there are multiple different units of measure but there are also multiple different keywords. These keywords can be essential to the troubleshooting process.
You will also see from that image that there are some events that don’t define the time unit very clearly. In fact it is just a null value for the description. That is a bit of a problem – but significantly less troublesome than not knowing the unit of measure for any of the events.
Conclusion
Figuring out the correct unit of time measurement can mean the difference between accurate troubleshooting or leaping down the wrong path. Figuring out the time units is made easier when you are able to query the metadata efficiently and have all of the pertinent details at your fingertips.
Extended Events is a powerful tool to help in troubleshooting and tuning your environment. I recommend investing a little time in reading the 60 day series about Extended Events. This is not a short series but is designed to provide an array of topics to help learn the tool over time. Don’t forget to go back and read the companion article showing how to audit these events via the default trace.
