Tracing Usage of Trace Flags

Aaron Bertrand

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)[1]', N'datetime2'),
  flag   = d.value(N'(data[@name="flag"]/value)[1]', N'int'),
  [type] = d.value(N'(data[@name="type"]/text)[1]', N'sysname'),
  [on]   = CASE d.value(N'(data[@name="new_value"]/value)[1]', 
           N'sysname') WHEN 1 THEN 0 ELSE 1 END,
  [sql]  = d.value(N'(action[@name="sql_text"]/value)[1]', 
           N'nvarchar(max)'),
  [spid] = d.value(N'(action[@name="session_id"]/value)[1]', 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 connect_time in sys.dm_exec_connections or login_time in sys.dm_exec_sessions and discard any earlier events associated with that spid.

Aaron Bertrand

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.

Tracing Usage of Trace Flags

Aaron Bertrand

Aaron Bertrand

Comments

Related Posts: