Friday, 3 August 2012

Server Side Tracing Microsoft SQL Server Events

Consider a situation where you must find out about user error messages on your production server. You can use profiler, but overhead is not welcomed. Solution is server side tracing whose overhead is significantly reduced (in fact one such trace is running by default). Server side tracing can collect the same data as profiler can.

Example of creating server-side trace can be found here. So here is the script that enables tracing "User Error Message" events (script has been slightly modified):

/*****************************************************************************
This script starts server-side trace.
******************************************************************************/
-- Declare variables 
DECLARE @rc INT 
DECLARE @TraceID INT 
DECLARE @maxFileSize bigint 
DECLARE @fileName NVARCHAR(128) 
DECLARE @on bit 

-- Set values 
SET @maxFileSize = 5 -- in MB 
SET @fileName = N'D:\UserErrorMessageTrace' -- location must be writeable for SQL server
SET @on = 1 

-- Create trace 
EXEC @rc = sp_trace_create @TraceID output, 0, @fileName, @maxFileSize, NULL  

-- If error end process 
IF (@rc != 0) 
 SELECT 'Could not create trace. Error code: ' + CAST(@rc as varchar(10))
ELSE BEGIN
 -- Declare event ID to trace
 DECLARE @EventId int = 162 -- 'User Error Message'

 -- Set columns to collect
 EXEC sp_trace_setevent @TraceID, @EventId,  1, @on 
 EXEC sp_trace_setevent @TraceID, @EventId,  4, @on 
 EXEC sp_trace_setevent @TraceID, @EventId,  6, @on 
 EXEC sp_trace_setevent @TraceID, @EventId,  7, @on 
 EXEC sp_trace_setevent @TraceID, @EventId,  8, @on 
 EXEC sp_trace_setevent @TraceID, @EventId, 11, @on 
 EXEC sp_trace_setevent @TraceID, @EventId, 12, @on 
 EXEC sp_trace_setevent @TraceID, @EventId, 14, @on 
 EXEC sp_trace_setevent @TraceID, @EventId, 20, @on 
 EXEC sp_trace_setevent @TraceID, @EventId, 27, @on 
 EXEC sp_trace_setevent @TraceID, @EventId, 30, @on 
 EXEC sp_trace_setevent @TraceID, @EventId, 31, @on 
 EXEC sp_trace_setevent @TraceID, @EventId, 35, @on 
 EXEC sp_trace_setevent @TraceID, @EventId, 51, @on 
 EXEC sp_trace_setevent @TraceID, @EventId, 64, @on 

 -- Set Filters 
 EXEC sp_trace_setfilter @TraceID, 31, 0, 1, 5701 -- exclude language change messages
 EXEC sp_trace_setfilter @TraceID, 31, 0, 1, 5703 -- exclude context change messages

 -- Start the trace 
 EXEC sp_trace_setstatus @TraceID, 1 
   
 -- Report success
 SELECT 'Started trace with ID = ' + cast(@TraceID as varchar(10))
END

Trace events and columns

So... which events can you trace and what columns those events support? There are some system views that contain all required info. All traceable events can be found by querying sys.trace_events view, columns are stored in sys.trace_columns view and event column configuration is in sys.trace_event_bindings view. In order not to write all those sp_trace_setevent one by one, use this query that returns all columns for particular event and corresponding EXEC statement (replace "164" with event ID of your interest):

SELECT 'EXEC sp_trace_setevent @TraceID, @EventId, ' 
  + cast(c.trace_column_id AS VARCHAR(10)) 
  + ', @on'
 ,*
FROM sys.trace_event_bindings AS b
INNER JOIN sys.trace_columns AS c ON c.trace_column_id = b.trace_column_id
WHERE b.trace_event_id = 164

Check active traces

In order to check currently active traces, you can use sys.fn_trace_getinfo system function (refer to the "Tables Returned" section for explanation of returned values). Enabled columns can be retrieved using fn_trace_geteventinfo system function. In order to retrieve more human-understandable data (with column names), execute this query:

SELECT DISTINCT c.*
FROM fn_trace_geteventinfo(1) AS i
INNER JOIN sys.trace_columns AS c ON c.trace_column_id = i.columnid

Start/Stop/Close trace and load data

Manage trace lifecycle with sp_trace_setstatus system function and load trace data using sys.fn_trace_gettable function. See examples here