Tracing Usage of Trace Flags

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):

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 (@AaronBertrand) is a Product Manager at SentryOne, 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, and serves as a community moderator for the Database Administrators Stack Exchange. 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.


Comments

SentryOne Monitor Ad