There are many useful targets within SQL Server’s Extended Events. Of all of the targets, the most daunting is probably the Event Tracing for Windows (ETW) target. The ETW target represents doing something that is new for most DBAs which means spending a lot of time trying to learn the technology and figure out the little nuances and the difficulties that it can present.
With all of that in mind, I feel this is a really cool feature and it is something that can be useful in bringing the groups together that most commonly butt heads in IT (Ops, DBA, Devs) by creating a commonality in trace data and facts. There may be more on that later!
Target Rich
The ETW target is a trace file that can be merged with other ETW logs from Windows or applications (if they have enabled this kind of logging). You can easily see many default ETW traces that are running or can be run in Windows via Perfmon or from the command line with the following command.
logman -ets
And from the gui…
Finding the traces is not really the difficult part with this type of trace. The difficult parts (I believe) come down to learning something new and different, and that Microsoft warns that you should have a working knowledge of it first (almost like a big flashing warning that says “Do NOT Enter!”). Let’s try to establish a small knowledgebase about this target to ease some of the discomfort you may now have.
One can query the DMVs to get a first look at what some of the configurations may be for this target (optional and most come with defaults already set).
SELECTxo.name AS TargetName , xoc.name AS Attribute , xoc.type_name , xoc.column_type , xoc.column_value AS DefaultValue , xoc.description FROMsys.dm_xe_objects xo INNER JOIN sys.dm_xe_object_columns xoc ON xo.name = xoc.object_name AND xo.package_guid = xoc.object_package_guid WHERE xo.name = 'etw_classic_sync_target';
Six configurations in total are available for the ETW target. In the query results (just above) you will see that the default value for each configuration option is displayed. For instance, the default_xe_session_name has a default value of XE_DEFAULT_ETW_SESSION. I like to change default names and file paths, so when I see a name such as that, rest assured I will change it. (Contrary to popular belief, the path and session name default values can certainly be changed.)
As I go forward into creating an XE session using the ETW target, it is important to understand that only 1 ETW session can exist. This isn’t a limitation of SQL Server per se, rather a combination of the use of the ETW Classic target (for backwards compatibility) and Windows OS constraints. If the ETW target is used in more than one XE session on the server (even in a different SQL Server instance), then all of them will use the same trace target in windows (consumer). This can cause a bit of confusion if several sessions are running concurrently.
My recommendation here is to use a very precise and targeted approach when dealing with the ETW target. Only run it for a single XE session at a time. This will make your job of correlating and translating the trace much easier.
The ETW target is a synchronous target and does NOT support asynchronous publication. With the synchronous consumption of events by the target, and if you have multiple sessions with the same event defined, the event will be consumed just a single time by the ETW target. This is a good thing!
Two more tidbits about the ETW target before creating an event session and looking at more metadata. The default path for the target is %TEMP%<filename>.etl. This is not defined in the configuration properties but is hardwired. Any ideas why one might want to specify a different path? I don’t like to use the temp directory for anything other than transient files that are disposable at any time!
Whether you change the directory from the default or leave it be, understand that it cannot be changed after the session starts – even if other sessions use the same target and are started later. However, if you flush the session and stop it, then you can change it. I do recommend that it be changed!
Second tidbit is that other than the classic target, ETW does have a manifest based provider. Should Extended Events (XE) be updated to use the manifest based provider then some of the nuances will disappear with translating some of the trace data (future article to include ntrace and xperf – stay tuned). For now, understand that viewing the ETW trace data is not done via SQL Server methods. Rather, you need to view it with another tool. This is due to the fact that the ETW is an OS level trace and not a SQL Server trace.
Session Building
If it is not clear at this point, when creating an XE session that utilizes the ETW target, two traces are, in essence, created. One trace is a SQL server (XE) trace that can be evaluated within SQL Server. The second trace is an ETW trace that is outside the realm of SQL Server and thus requires new skills in order to review it. Again, this second trace can be of extreme help because it is more easily merged with other ETW traces (think merging perfmon with sql trace).
When I create a session with an ETW target, it would not be surprising to see that I have two targets defined. One target will be the ETW target and a second may be a file target or any of the others if it makes sense. The creation of two targets is not requisite for the XE session to be created. The XE data will still be present in the livestream target even without a SQL related target.
Before creating a session, I need to cover a couple of possible errors that won’t be easy to find on google.
Msg 25641, Level 16, State 0, Line 101 For target, “5B2DA06D-898A-43C8-9309-39BBBE93EBBD.package0.etw_classic_sync_target”, the parameter “default_etw_session_logfile_path” passed is invalid.
The operating system returned error 5 (ACCESS_DENIED) while creating an ETW tracing session.
ErrorFormat: Ensure that the SQL Server startup account is a member of the ‘Performance Log Users’ group and then retry your command.
I received this error message even with my service account being a member of the “Performance Log Users” windows group. I found that I needed to grant explicit permissions to the service account to the logging directory that I had specified.
Msg 25641, Level 16, State 0, Line 105 For target, “5B2DA06D-898A-43C8-9309-39BBBE93EBBD.package0.etw_classic_sync_target”, the parameter “default_xe_session_name” passed is invalid.
The default ETW session has already been started with the name ‘unknown‘.
Either stop the existing ETW session or specify the same name for the default ETW session and try your command again.
This error was more difficult than the first and probably should have been easier. I could not find the session called ‘unknown’ hard as I might have tried. Then it occurred to me (sheepishly) that the path probably wanted a file name too. If you provide a path and not a filename for the trace file, then this error will nag you.
I found both error cases to be slightly misleading but resolvable quickly enough.
USE master;
GO
-- Create the Event Session
IF EXISTS ( SELECT *
FROM sys.server_event_sessions
WHERE name = 'SVRLoginAudit_etw' )
DROP EVENT SESSION SVRLoginAudit_etw
ON SERVER;
GO
EXECUTE xp_create_subdir 'C:DatabaseXE';
GO
CREATE EVENT SESSION [SVRLoginAudit_etw]
ON SERVER
ADD EVENT sqlserver.login
( SET collect_database_name = ( 1 )
, collect_options_text = ( 1 )
ACTION ( package0.collect_system_time
, package0.event_sequence
, sqlserver.client_app_name
, sqlserver.client_connection_id
, sqlserver.client_hostname
, sqlserver.context_info
, sqlserver.database_id
, sqlserver.database_name
, sqlserver.nt_username
, sqlserver.server_principal_name
, sqlserver.session_id
, sqlserver.session_nt_username
, sqlserver.sql_text
, sqlserver.username ))
ADD TARGET package0.event_file
( SET filename = N'C:DatabaseXESVRLoginAudit_etw.xel'
, max_file_size = ( 5120 ), max_rollover_files = ( 6 )),
ADD TARGET package0.etw_classic_sync_target ( --keeping mostly default values
SET default_etw_session_logfile_path = 'C:DatabaseXESVRLoginAudit_etw.etl'
, default_xe_session_name = 'NotYourETWXESession' -- changed from XE_DEFAULT_ETW_SESSION
, default_etw_session_buffer_size_kb = 128
, default_etw_session_logfile_size_mb = 20
, retries = 0
, deferred_etw_creation = 0
)
WITH ( MAX_MEMORY = 4096KB
, EVENT_RETENTION_MODE = ALLOW_SINGLE_EVENT_LOSS
, MAX_DISPATCH_LATENCY = 30 SECONDS
, MAX_EVENT_SIZE = 0KB
, MEMORY_PARTITION_MODE = NONE
, TRACK_CAUSALITY = ON
, STARTUP_STATE = OFF );
GOThe session is pretty straight forward here. I am just auditing logins that occur on the server and sending them to both the ETW and event_file targets. To validate the session is created and that indeed the ETW session is not present in SQL Server, I have the following script.
SELECT ISNULL(ses.name,xse.name) AS SessionName
, CASE
WHEN ISNULL(ses.name,'') = ''
THEN 'Private'
ELSE 'Public'
END AS SessionVisibility
, CASE
WHEN ISNULL(xse.name,'') = ''
THEN 'NO'
ELSE 'YES'
END AS SessionRunning
, CASE
WHEN ISNULL(xse.name,'') = ''
AND ISNULL(ses.name,'') = ''
THEN 'NO'
ELSE 'YES'
END AS IsDeployed
FROM sys.server_event_sessions ses
FULL OUTER JOIN sys.dm_xe_sessions xse
ON xse.name =ses.name
WHERE ses.name IN ('NotYourETWXESession','XE_DEFAULT_ETW_SESSION','SVRLoginAudit_etw')
OR xse.name IN ('NotYourETWXESession','XE_DEFAULT_ETW_SESSION','SVRLoginAudit_etw')
ORDER BY ses.event_session_id;
GO
ALTER EVENT SESSION SVRLoginAudit_etw ON SERVER
STATE = START;
SELECT ISNULL(ses.name,xse.name) AS SessionName
, CASE
WHEN ISNULL(ses.name,'') = ''
THEN 'Private'
ELSE 'Public'
END AS SessionVisibility
, CASE
WHEN ISNULL(xse.name,'') = ''
THEN 'NO'
ELSE 'YES'
END AS SessionRunning
, CASE
WHEN ISNULL(xse.name,'') = ''
AND ISNULL(ses.name,'') = ''
THEN 'NO'
ELSE 'YES'
END AS IsDeployed
FROM sys.server_event_sessions ses
FULL OUTER JOIN sys.dm_xe_sessions xse
ON xse.name =ses.name
WHERE ses.name IN ('NotYourETWXESession','XE_DEFAULT_ETW_SESSION','SVRLoginAudit_etw')
OR xse.name IN ('NotYourETWXESession','XE_DEFAULT_ETW_SESSION','SVRLoginAudit_etw')
ORDER BY ses.event_session_id;
GO
Despite the absence of the ETW session from SQL Server, I can still easily find it (again either shell or from the perfmon gui). Here is what I see when checking for it from a shell.
Even though the session (or session data) is not visible from SQL Server, I can still find out a tad more about the target from the XE related DMVs and catalog views.
SELECT xse.name AS SessionName, xse.buffer_policy_desc, xse.flag_desc,est.name AS Targetname
,CASE WHEN est.name = 'event_file'
THEN sesfo.filename
ELSE NULL END AS filename
,CASE WHEN est.name = 'event_file'
THEN sesfo.max_file_size
ELSE NULL END AS max_file_size
,CASE WHEN est.name = 'event_file'
THEN sesfo.max_rollover_files
ELSE NULL END AS max_rollover_files
,CASE WHEN est.name = 'event_file'
THEN NULL
ELSE sesfo.default_etw_session_logfile_path END AS default_etw_session_logfile_path
,CASE WHEN est.name = 'event_file'
THEN NULL
ELSE sesfo.default_xe_session_name END AS default_xe_session_name
,CASE WHEN est.name = 'event_file'
THEN NULL
ELSE sesfo.default_etw_session_buffer_size_kb END AS default_etw_session_buffer_size_kb
,CASE WHEN est.name = 'event_file'
THEN NULL
ELSE sesfo.default_etw_session_logfile_size_mb END AS default_etw_session_logfile_size_mb
FROM sys.server_event_sessions ses
INNER JOIN sys.dm_xe_sessions xse
ON xse.name =ses.name
INNER JOIN sys.server_event_session_targets est
ON ses.event_session_id = est.event_session_id
INNER JOIN (
SELECT *
FROM (
SELECT sesf.event_session_id, sesf.name AS FieldName, sesf.value AS FieldValue
FROM sys.server_event_session_fields sesf
) fields
PIVOT (
max(FieldValue)
FOR FieldName IN (begin_event
,begin_matching_actions
,begin_matching_columns
,collect_cached_text
,collect_call_stack
,collect_column_list
,collect_data
,collect_database_name
,collect_feature_data
,collect_object_name
,collect_options_text
,collect_plan_handle
,collect_resource_description
,collect_statement
,end_event
,end_matching_actions
,end_matching_columns
,filename
,filtering_event_name
,max_events_limit
,max_file_size
,max_memory
,max_rollover_files
,metadatafile
,occurrence_number
,source
,source_type
,default_etw_session_logfile_path
,default_etw_session_buffer_size_kb
,default_etw_session_logfile_size_mb
,retries
,default_xe_session_name
,deferred_etw_creation)
) PVT
) sesfo
ON est.event_session_id = sesfo.event_session_id
WHERE ses.name IN ('NotYourETWXESession','XE_DEFAULT_ETW_SESSION','SVRLoginAudit_etw');Running that query will result in something similar to this:
The Wrap
I have just begun to scratch the surface of the ETW target. This target can provide plenty of power for troubleshooting when used in the right way. The difficulty may seem to be getting to that point of knowing what the right way is. This target may not be suitable for most troubleshooting issues – unless you really need to correlate real windows metrics to SQL metrics and demonstrate to Joe Sysadmin that what you are seeing in SQL truly does correlate to certain conditions inside of windows. Try it out and try to learn from it and figure out the right niche for you. In the interim, stay tuned for a follow-up article dealing with other tools and ETW.
For more uses of Extended Events, I recommend my series of articles designed to help you learn XE little by little.
Interested in seeing the power of XE over Profiler? Check this one out!
This has been the tenth article in the 2018 “12 Days of Christmas” series. For a full listing of the articles, visit this page.
