SentryOne Team Blog (blogs.sentryone.com)

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.

2 replies on “Tracing usage of trace flags”

2 Comments (Comments are now closed.)
  1. Wow. I was at that session and remember the question. What I am really impressed by is how quick you responded and how thorough your answer is. With all the time you were in the SQL Sentry booth and then at the SQL Intersection Q and A, you still found time to blog an answer. Nice.

    I did notice that the Global traceflag you turned on and then off while you were monitoring with an extended event shows a value of 0 in the 'on' column no matter if TRACEON or TRACEOFF was executed. It's something I think I will test out today.

    @AndersonGregD

    1. Hi Greg,

      No, sorry, that was my bad, sloppy copy and paste (and also removing duplicates, since the global events actually send two events, one that "kind of" represents the session event).