Stairway to Server-side Tracing

Stairway to Server-side Tracing - Level 5: How to View and Manage Running Traces

,

T-SQL scripts are a must, not only to create server-side traces, but also to view existing trace definitions and manage traces. I showed earlier in this Stairway how to create server-side trace scripts with T-SQL as well with the SQL Server Profiler. But once a server-side trace is running, it must be managed using T-SQL since there is no graphical interface available that provides visibility into running traces.

Level 5 of this Stairway will show how to view and manage server-side traces using T-SQL in lieu of a GUI tool.

The sys.traces Catalog View

The sys.traces catalog view is the core one needed to manage traces. Sys.traces contains one row for each trace definition and includes both server-side and client-side (e.g. Profiler) traces. Noteworthy is the id column value, which is the trace ID needed to manage the trace via T-SQL. Figure 1 lists sys.traces columns and their meaning.

COLUMN name Description

id Trace ID.

status Trace status:

0 = NOT running (stopped OR paused)

1 = running

path Server-side trace FILE path. This value IS NULL FOR rowset (client-side) traces.

max_size Maximum trace FILE size limit IN megabytes. This value IS NULL FOR rowset (client-side) traces.

stop_time Time TO stop the trace OR NULL IF no stop time.

max_files Maximum number OF rollover files OR NULL WHEN is_rollover = 0.

is_rowset 0 = server-side trace TO FILE

1 = client-side trace TO rowset

is_rollover 1 = trace FILE rollover OPTION IS enabled.

is_shutdown 1 = shutdown OPTION IS enabled.

is_default 1 = DEFAULT trace.

buffer_count Number OF IN-memory buffers used BY the trace.

buffer_size Size OF each buffer (KB).

file_position Last trace FILE position OR NULL WHEN is_rowset = 1.

reader_spid Session id OF the rowset (client-side) trace reader. This value IS NULL WHEN is_rowset = 0.

start_time Trace start time.

last_event_time Time OF the last collected event.

event_count Total number OF events collected BY this trace.

dropped_event_count Total number OF events dropped BY a rowset (client-side) trace. This value IS NULL WITH is_rowset = 0;

Figure 1: sys.trace catalog view columns

Because SQL Trace doesn't provide a method to tie a user-friendly name to a trace, it's a good idea to use a descriptive trace file or folder name when creating server-side traces. This practice allows one to easily identify a specific server-side trace using the path column of sys.traces without the need to keep track of trace IDs manually on post-it notes, which is particularly important if you manage many traces and servers.

The query in Listing 1 reports all currently running and stopped server-side traces. Server-side traces are distinguished by is_rowset value 0, indicating that trace data are written directly to a file instead of returning a rowset to a client tracing application like Profiler. As I previously mentioned, you can examine the path column to identify the server-side trace you want to manage.

SELECT t.id
 ,CASE t.status
 WHEN 0 THEN 'Stopped'
 ELSE 'Running'
 END AS status
 ,t.path
 ,t.max_size
 ,t.stop_time
 ,t.max_files
 ,t.is_rollover
 ,t.is_shutdown
 ,t.is_default
 ,t.file_position
 ,t.start_time
 ,t.last_event_time
 ,t.event_count
FROM sys.traces AS t
WHERE t.is_rowset = 0 ;

Listing 1: List server-side traces with trace file information

The sys.traces catalog view also includes client-side traces, which are identified by is_rowset value 1. Since client-side traces return trace data as a rowset (returning one row at a time) to the client application instead of writing to a file, it is necessary to join sys.traces to sys.dm_exec_sessions in order to identify the client running the trace. The Listing 2 query displays all currently running or paused client-side traces along with session data from sys.dm_exec_sessions. If you execute this query while a Profiler trace is running, the results will include the login and hostname of the Profiler client-side trace session. The reader_spid will be NULL if the client-side trace is paused so I use a LEFT JOIN in the query to return the remainder of the trace meta-data regardless of the trace status.

SELECT t.id

,CASE t.status

WHEN 0 THEN 'Paused'

ELSE 'Running'

END AS status

,t.reader_spid

,t.start_time

,s.HOST_NAME

,s.program_name

,s.login_name

FROM sys.traces AS t

LEFT JOIN sys.dm_exec_sessions AS s ON s.session_id = reader_spid

WHERE t.is_rowset = 1 ;

Listing 2: List client-side traces with session information

Client-side traces are typically managed using the Profiler GUI but, in a pinch, you can stop a client-side trace using T-SQL. For example, if your colleague has a Profiler trace running that is negatively impacting server performance and has left his workstation locked, you can identify the problem trace with this query and stop it using sp_trace_setstatus with a @status value 0 (discussed previously in this Stairway). This method is a bit more graceful than killing the reader SPID, or powering off his or her computer!

Altering Existing Traces

Level 2 of this Stairway showed how to use sp_trace_setevent and sp_trace_setfilter to create new server-side traces. These same stored procedures may be used to add or remove columns and filters from existing server-side traces, but the trace must first be stopped using sp_trace_setstatus before any changes to columns or filters are made. Figure 2 summarizes the sp_trace_setevent parameter values that are used along with @traceid to modify an existing trace definition.

To add an event column to a stopped trace, execute sp_trace_setevent with the desired trace, event and column id values along with @on parameter value 1. You can similarly remove a column from a trace by specifying value 0 for the sp_trace_setevent @on parameter value.

@on @columnid Result

ON (1) NULL Event IS turned ON AND ALL columns are cleared.

NOT NULL COLUMN IS turned ON FOR the specified Event.

OFF (0) NULL Event IS turned OFF AND ALL Columns are cleared.

NOT NULL COLUMN IS turned OFF FOR the specified Event.

Figure 2: @on and @columnid parameter values for sp_trace_setevent

So let's say you are running a server-side trace of long-running TSQL:Batch Completed and RPC:Completed events and find that DatabaseName is useful for your analysis but wasn't included in the trace. Rather than recreate the trace (which requires that the trace be stopped, deleted, recreated and started) you can instead stop the trace, turn on the column for each event desired and restart the trace. The query in listing 3 performs these tasks to add DatabaseName to both TSQL:Batch Completed and RPC:Completed events. Events collected before the column was added will have a NULL DatabaseName while DatabaseName will be included in events captured after the trace is restarted. The @traceid value used in this script was obtained from a previous query of sys.traces.

--stop trace

EXEC sp_trace_setstatus

@traceid = 2

,@status = 0 ;

--add DatabaseName to RPC:Completed event

EXEC sp_trace_setevent

@traceid = 2

,@eventid = 10

,@columnid = 35

,@on = 11 ;

--add DatabaseName to SQL:BatchCompleted event

EXEC sp_trace_setevent

@traceid = 2

,@eventid = 12

,@columnid = 35

,@on = 1 ;

--restart trace

EXEC sp_trace_setstatus

@traceid = 2

,@status = 1 ;

Listing 3: Add database name column to RPC:Completed and SQL:BatchCompleted events

One advantage of changing an existing trace definition with sp_trace_setevent instead of recreating the trace is that SQL Trace will append to the existing file after the trace is restarted instead of creating a new trace file. This avoids premature removal of rollover trace files or, in the case of no rollover, manual intervention to move or rename the existing file before recreating the trace with the same file name. It's still a good idea to retain a complete trace definition script so that traces can be easily reused or recreated after SQL Server restarts. I mentioned previously in this Stairway that keeping trace definition scripts in stored procedures facilitates this.

Filters can also be added or removed from a stopped trace using sp_trace_setfilter. Using the same long-running query trace as an example, let's say you want to lower the bar on the Duration column filter from 10 seconds down to 1 after you've tuned OLTP queries that ran excessively long. This is accomplished by removing the existing Duration filter and adding it back with a new Duration value as shown in Listing 4.

--stop trace

EXEC sp_trace_setstatus

@traceid = 2

,@status = 0 ;

--remove old duration filter

EXEC sp_trace_setfilter

@traceid = 2

,@columnid = NULL

,@logical_operator = 0

,@comparison_operator = 4

,@value = NULL ;

--add the new duration filter (>= one second)

DECLARE @bigintfilter bigint ;

SET @bigintfilter = 1000000 ;

EXEC sp_trace_setfilter

@traceid = 2

,@columnid = 13

,@logical_operator = 0

,@comparison_operator = 4

,@value = @bigintfilter ;

--restart trace

EXEC sp_trace_setstatus

@traceid = 2

,@status = 1 ;

 

Listing 4: Replace existing Duration column filter

Reverse Engineering an Existing Trace

Unfortunately, there is no out-of-the-box method to script or reverse engineer an existing trace definition; one must keep trace definitions scripts to avoid recreating the trace from scratch later. Should you find yourself in a situation where you have a running trace but failed to save the T-SQL definition script, you can use the script in Listing 5 to generate the T-SQL code needed to recreate the trace. Change the @current_trace_id variable value to the id of the existing trace and then run the script from SQL Server Management Studio with the query results to text option. After generating the script, you may need to tweak the generated @tracefile value, which is the current file name of the running trace with no extension.

SET NOCOUNT ON ;

DECLARE @current_trace_id INT ;

--set @current_trace_id to the id of the trace you want to script

SET @current_trace_id = 1 ;

DECLARE @tracefile NVARCHAR(245) ;

DECLARE @options INT ;

DECLARE @maxfilesize bigint ;

DECLARE @stoptime DATETIME ;

DECLARE @filecount INT ;

DECLARE @sp_trace_create VARCHAR(MAX) ;

SET @sp_trace_create = '

DECLARE @TraceID int ;

DECLARE @maxfilesize bigint ;

DECLARE @bigintfilter bigint ;

DECLARE @datetimefilter datetime ;

DECLARE @varbinaryfilter varbinary(256) ;

DECLARE @intfilter int ;

DECLARE @nvarcharfilter nvarchar(256) ;

DECLARE @varcharfilter varchar(256) ;

DECLARE @uniqueidentifierfilter uniqueidentifier ;

DECLARE @return_code int ;

SET @maxfilesize = <%maxfilesize%>

EXEC @return_code = sp_trace_create

@traceid OUTPUT

, @options = <%options%>

, @tracefile = N''<%tracefile%>''

, @maxfilesize = @maxfilesize

, @stoptime = <%stoptime%>

, @filecount = <%filecount%> ;

IF @return_code <> 0 GOTO finish ;'

SELECT @maxfilesize = max_size

,@tracefile = SUBSTRING(path, 1, LEN(path) - 4)

,@stoptime = stop_time

,@filecount = max_files

,@options = CASE is_rollover

WHEN 1 THEN 2

ELSE 0

END + CASE is_shutdown

WHEN 1 THEN 4

ELSE 0

END

FROM sys.traces

WHERE id = @current_trace_id ;

SET @sp_trace_create = REPLACE(@sp_trace_create, '<%tracefile%>',

CONVERT(NVARCHAR(245), @tracefile)) ;

SET @sp_trace_create = REPLACE(@sp_trace_create, '<%options%>',

CONVERT(CHAR(1), @options)) ;

SET @sp_trace_create = REPLACE(@sp_trace_create, '<%maxfilesize%>',

CONVERT(VARCHAR(19), @maxfilesize)) ;

SET @sp_trace_create = REPLACE(@sp_trace_create, '<%stoptime%>',

COALESCE(QUOTENAME(CONVERT(VARCHAR(23),

@stoptime, 121), ''''), 'NULL')) ;

SET @sp_trace_create = REPLACE(@sp_trace_create, '<%filecount%>',

CONVERT(VARCHAR(10), @filecount)) ;

SELECT SqlStatement

FROM ( SELECT 1 AS Seq

,@sp_trace_create AS SqlStatement

UNION ALL

SELECT 2

,REPLACE(REPLACE('EXEC sp_trace_setevent

@traceid = @TraceID

, @eventid = <%EventID%>

, @columnid = <%ColumnID%>

, @on = 1 ;', '<%EventID%>', CAST(tevent.eventid AS VARCHAR(5))),

'<%ColumnID%>',

CAST(tevent.columnid AS VARCHAR(5))) AS

seteventcommand

FROM sys.traces t

CROSS APPLY fn_trace_geteventinfo(@current_trace_id) AS tevent

WHERE t.id = 2

UNION ALL

SELECT 3

,CASE tcol.type_name

WHEN 'bigint'

THEN 'SET @bigintfilter = '

+ COALESCE(CONVERT(NVARCHAR(19), tf.value), 'NULL')

+ ' ;'

WHEN 'datetime'

THEN 'SET @datetimefilter = '

+ COALESCE(QUOTENAME(CONVERT(NVARCHAR(23), tf.value, 121),

''''), 'NULL') + ' ;'

WHEN 'image'

THEN 'SET @varbinaryfilter = '

+ COALESCE(CONVERT(NVARCHAR(1000), tf.value, 1),

'NULL') + ' ;'

WHEN 'int'

THEN 'SET @intfilter = '

+ COALESCE(CONVERT(NVARCHAR(10), tf.value), 'NULL')

+ ' ;'

WHEN 'nvarchar'

THEN 'SET @nvarcharfilter = '

+ COALESCE(QUOTENAME(CONVERT(NVARCHAR(1000), tf.value),

''''), 'NULL') + ' ;'

WHEN 'text'

THEN 'SET @nvarcharfilter = '

+ COALESCE(QUOTENAME(CONVERT(NVARCHAR(1000), tf.value),

''''), 'NULL') + ' ;'

WHEN 'uniqueidentifier'

THEN 'SET @uniqueidentifierfilter = '

+ COALESCE(QUOTENAME(CONVERT(NVARCHAR(39), tf.value),

''''), 'NULL') + ' ;'

ELSE 'SET @nvarcharfilter = NULL ;'

END + CHAR(13) + CHAR(10) + 'EXEC sp_trace_setfilter'

+ CHAR(13) + CHAR(10) + CHAR(9) + '@traceid = @TraceID'

+ CHAR(13) + CHAR(10) + CHAR(9) + ', @columnid = '

+ CONVERT(VARCHAR(10), tf.columnid) + CHAR(13)

+ CHAR(10) + CHAR(9) + ', @logical_operator = '

+ CONVERT(VARCHAR(10), tf.logical_operator) + CHAR(13)

+ CHAR(10) + CHAR(9) + ', @comparison_operator = '

+ CONVERT(VARCHAR(10), tf.comparison_operator)

+ CHAR(13) + CHAR(10) + CHAR(9) + ', @value = '

+ CASE tcol.type_name

WHEN 'bigint' THEN '@bigintfilter ;'

WHEN 'datetime' THEN '@datetimefilter ;'

WHEN 'image' THEN '@varbbinaryfilter ;'

WHEN 'int' THEN '@intfilter ;'

WHEN 'nvarchar' THEN '@nvarcharfilter ;'

WHEN 'text' THEN '@nvarcharfilter = ;'

WHEN 'uniqueidentifier'

THEN '@uniqueidentifierfilter ;'

ELSE '@nvarcharfilter ;'

END

FROM fn_trace_getfilterinfo(@current_trace_id) AS tf

JOIN sys.trace_columns tcol ON tcol.trace_column_id = tf.columnid

UNION ALL

SELECT 4

,'EXEC sp_trace_setstatus @TraceID, 1 ;' + CHAR(13)

+ CHAR(10)

+ 'RAISERROR(''TraceID is %d'', 0, 1, @TraceID)'

+ CHAR(13) + CHAR(10) + 'finish: ;'

) AS script

ORDER BY Seq ;

Listing 5: Reverse engineer existing trace definition

Summary

A good understanding of the sys.traces catalog view is invaluable in viewing and managing server-side traces. DBAs who are familiar with sp_trace_setevent and sp_trace_setfilter can leverage their knowledge to tweak trace definitions without recreating server-side traces from scratch. Using these stored procedures, you can even build your own custom tools to control and edit server-side traces.

This article is part of the parent stairway Stairway to Server-side Tracing

Rate

You rated this post out of 5. Change rating

Share

Share

Rate

You rated this post out of 5. Change rating