Tracing Usage of Trace Flags
Published On: May 21, 2015
Categories: System Configuration, Trace, Extended Events, Monitoring 2
This morning at SQLintersection, I delivered my session "SQL Server Trace Flags : A Practical Guide" for the first time. I wanted to include the three core links I talked about for getting more information about trace flags (including all of the undocumented ones that have even been uttered outside of Redmond):
- Trace Flags in Books Online (click "Other Versions" to switch to the relevant version)
- Trace Flags in SQL Server (Wiki)
- Aaron Morelli's exhaustive list of all trace flags, documented or not (latest PDF, v4, January 2015)
I also had an excellent question from the audience: "How can I tell when another session has turned a trace flag on?"
One way is to review the event log for
DBCC TRACEON events:
EXEC sys.sp_readerrorlog 0, 1, N'DBCC TRACEON';
You will see something like this for each event:
2015-05-21 17:22:19.400 spid63 DBCC TRACEON 1200, server process ID (SPID) 63. This is an informational message only; no user action is required.
Another is to use Extended Events (and you can customize the session to include a lot more additional information that is not included in the error log, especially if you are on 2012+):
CREATE EVENT SESSION TraceFlags ON SERVER ADD EVENT sqlserver.trace_flag_changed ( ACTION ( sqlserver.session_id, sqlserver.sql_text ) ) ADD TARGET package0.ring_buffer; GO ALTER EVENT SESSION TraceFlags ON SERVER STATE = START;
Now, turn a couple of trace flags on and off, e.g.:
DBCC TRACEON(1118); GO DBCC TRACEON(1200,-1); GO WAITFOR DELAY '00:00:01'; GO DBCC TRACEOFF(1200,-1); GO DBCC TRACEOFF(1118);
Then we can query the ring buffer for information (don't expect this to return sub-second):
SELECT dt = d.value(N'(@timestamp)', N'datetime2'), flag = d.value(N'(data[@name="flag"]/value)', N'int'), [type] = d.value(N'(data[@name="type"]/text)', N'sysname'), [on] = CASE d.value(N'(data[@name="new_value"]/value)', N'sysname') WHEN 1 THEN 0 ELSE 1 END, [sql] = d.value(N'(action[@name="sql_text"]/value)', N'nvarchar(max)'), [spid] = d.value(N'(action[@name="session_id"]/value)', N'int') FROM ( SELECT x = CONVERT(XML, t.target_data) FROM sys.dm_xe_sessions AS s INNER JOIN sys.dm_xe_session_targets AS t ON s.[address] = t.event_session_address WHERE s.name = N'TraceFlags' AND t.target_name = N'ring_buffer' ) AS t CROSS APPLY x.nodes(N'RingBufferTarget/event') AS x(d) ORDER BY dt DESC;
Results will look something like this:
dt flag type on text spid ------------------- ---- ------- -- ----------------------- ---- 2015-05-21 21:18:42 1118 Session 0 DBCC TRACEOFF(1118); 63 2015-05-21 21:18:42 1200 Global 0 DBCC TRACEOFF(1200,-1); 63 2015-05-21 21:18:41 1200 Global 1 DBCC TRACEON(1200,-1); 63 2015-05-21 21:18:41 1118 Session 1 DBCC TRACEON(1118); 63
It's important to note that, whether you look in the error log or extended events, you won't always see closure statements - a session could turn on a trace flag, then close the query window. SQL Server doesn't issue a
TRACEOFF event, and eventually (or immediately) that
session_id will get reused - so be careful not to make assumptions about the trace flags currently enabled for a session - check
sys.dm_exec_sessions and discard any earlier events associated with that spid.
Aaron (@AaronBertrand) is a Data Platform MVP with industry experience dating back to Classic ASP and SQL Server 6.5. He is editor-in-chief of the performance-related blog, SQLPerformance.com. Aaron's blog focuses on T-SQL bad habits and best practices, as well as coverage of updates and new features in Plan Explorer, SentryOne, and SQL Server.