This topic has been written about many times. I am writing this post with a focus on Sage 500 ERP. The reason I am focusing on this as an example is that I have done quite a bit of work recently with some Sage 500 ERP customers and partners only to discover that most of them were using SQL Profiler on a system already experiencing severe pressures. Yet it needed to be done to satisfy the needs of Sage Support in order to provide more information on a support case.
SQL Profiler, also know as a Client-Side Trace, only adds to the pressure. An article by Andrew Kelly from 2008 does a nice job of explaining some the differences between the two and why you would choose over the other.
We are now going to concentrate on Server-Side Trace for the rest of this post. This is still relevant with most of the Sage 500 ERP and Sage X3 ERP implementations and would most likely be a benefit to you, at least that has been my experience over the past few months. I say that because we will discuss another technology feature that was introduced in SQL Server 2008 is Extended Events. This feature has been greatly expanded in the upcoming version, SQL Server 2012. If you want to read more about this feature this is a good starting point http://msdn.microsoft.com/en-us/library/dd822788(v=SQL.100).aspx. Jonathan Kehayias has many blog posts on this subject matter and is probably the industry expert on this topic in my opinion.
We will cover some foundation related to Trace Events and Trace Columns. This will provide you with resources and knowledge you will need to work with Server-Side Trace.
One way to approach this is to use SQL Profiler to configure your trace then you can do a File->Export->Script Trace Definition to write out the SQL Script that you can use to perform a Server-Side Trace. This can be a great way to get familiar with and transition from what you have been doing for probably many years.
Complete list of events
http://msdn.microsoft.com/en-us/library/ms186265.aspx
You can also select the Trace Events with the following syntax.
-- Trace Events
SELECT e.trace_event_id,
e.category_id,
e.name as traceeventname,
cat.name as categoryname,
cat.type
FROM sys.trace_events e
INNER JOIN sys.trace_categories AS cat
ON e.category_id = cat.category_id
ORDER BY e.category_id, e.trace_event_id
Complete list of columns
http://msdn.microsoft.com/en-us/library/ms190762.aspx
You can also select the Trace Columns by Trace Event with the following syntax.
SELECT e.Trace_Event_ID,
e.name AS Event_Descr,
c.trace_column_id,
c.name AS Column_Descr,
c.type_name,
c.is_filterable
FROM sys.trace_events e
INNER JOIN sys.trace_event_bindings b
ON b.trace_Event_ID = e.Trace_Event_ID
INNER JOIN sys.trace_columns c
ON b.trace_column_id = c.trace_column_id
The Server-Side Trace consists, for the most part, of four components to get a trace running. The four components are:
- sp_trace_create - http://msdn.microsoft.com/en-us/library/ms190362.aspx
The procedure takes 5 parameters. One of which is an Output. It is used to create the trace definition.
TraceID – ID of the trace, this is an Output parameter and will provide the TraceID
Options – several different options that can be set (refer to the link above for more details)
TraceFile – physical file name of the trace file you will write to
MaxFileSize – size of the file, once the file reaches this size it will close the file and create subsequent files
StopTime – used to specify a time to stop the trace
FileCount – used to specify the maximum number of trace files (optional0
- sp_trace_setevent - http://msdn.microsoft.com/en-us/library/ms186265.aspx
The procedure takes 4 parameters. It is used to specify what event and what column to capture.
TraceID – ID of the trace
EventID – ID of the event you wish to capture
ColumnID – ID of the column you wish to capture
On – this will set the event on or off
- sp_trace_setfilter - http://msdn.microsoft.com/en-us/library/ms174404.aspx
This procedure takes 5 parameters. It is used to determine what to include and/or exclude from the collection.
TraceID – ID of the trace
ColumnID – ID of the column you wish to set the filter on
LogicalOperator – specify the type of operation, AND or OR
ComparisonOperator – specify the operand type (e.g. =, <>, >, <, >=, <=, like, not like)
Value – value used for the comparison
- sp_trace_setstatus - http://msdn.microsoft.com/en-us/library/ms176034.aspx
This procedure takes 2 parameters. It is used to change the status of the trace event. The close will also delete the trace definition. This delete does not delete the trace files that were created.
TraceID – ID of the trace
Status - stop(0), start(1) and close(2) trace, you must stop a trace in order to close a trace
So how do we use these commands. Well let’s answer some questions that I had while I was first starting out.
How do I create a trace?
You need to make sure that the folder exists for the tracefile and the SQL Server Service account user has permissions to write to that folder. It goes without saying but you should also make sure that you have ample disk space where the tracefile is about to write as well.
First you need to declare your variables.
-- Declare variables
DECLARE @rc INT
DECLARE @TraceID INT
DECLARE @maxFileSize bigint
DECLARE @fileName NVARCHAR(128)
DECLARE @on bit
DECLARE @stoptime DATETIME
Then you need to provide default values for these variables. Remember TraceID is an OUTPUT during the create phase so it will be assigned later.
-- Set values
SET @maxFileSize = 5
SET @fileName = N'C:PerflogsMyTrace'
SET @on = 1
SET @stoptime = DATEADD(hour,3,GETDATE())
Create the trace definition and verify that it was successful.
-- Create trace
EXEC @rc = sp_trace_create @TraceID output, 2, @fileName,
@maxFileSize, @stoptime
-- If error end process
IF (@rc != 0) GOTO error
/*
THIS WILL BE WHERE YOU PLACE YOUR CODE
THAT WILL SET THE EVENTS TO COLLECT AND
FILTER DATA FOR YOUR TRACE
*/
-- Start the trace
EXEC sp_trace_setstatus @TraceID, 1
-- display trace id for future references
SELECT TraceID=@TraceID
GOTO finish
-- error trap
error:
SELECT ErrorCode=@rc
-- exit
finish:
GO
Define the events and data to collect. Here are few that you would normally configure in SQL Profiler that Sage always requests. In the example below, using the first execution line from row 3, this is basically asking for the Event “RPC:Completed” which is event 10, column 1 which is “TextData” and set the event definition to 1 meaning on. See Image 1 below for how to discover this information.
-- RPC:Completed
exec sp_trace_setevent @TraceID, 10, 1, @on
exec sp_trace_setevent @TraceID, 10, 6, @on
exec sp_trace_setevent @TraceID, 10, 9, @on
exec sp_trace_setevent @TraceID, 10, 10, @on
exec sp_trace_setevent @TraceID, 10, 11, @on
exec sp_trace_setevent @TraceID, 10, 12, @on
exec sp_trace_setevent @TraceID, 10, 13, @on
exec sp_trace_setevent @TraceID, 10, 14, @on
exec sp_trace_setevent @TraceID, 10, 15, @on
exec sp_trace_setevent @TraceID, 10, 16, @on
exec sp_trace_setevent @TraceID, 10, 17, @on
exec sp_trace_setevent @TraceID, 10, 18, @on
exec sp_trace_setevent @TraceID, 10, 27, @on
-- SQL:BatchCompleted
exec sp_trace_setevent @TraceID, 12, 1, @on
exec sp_trace_setevent @TraceID, 12, 6, @on
exec sp_trace_setevent @TraceID, 12, 9, @on
exec sp_trace_setevent @TraceID, 12, 10, @on
exec sp_trace_setevent @TraceID, 12, 11, @on
exec sp_trace_setevent @TraceID, 12, 12, @on
exec sp_trace_setevent @TraceID, 12, 13, @on
exec sp_trace_setevent @TraceID, 12, 14, @on
exec sp_trace_setevent @TraceID, 12, 15, @on
exec sp_trace_setevent @TraceID, 12, 16, @on
exec sp_trace_setevent @TraceID, 12, 17, @on
exec sp_trace_setevent @TraceID, 12, 18, @on
exec sp_trace_setevent @TraceID, 12, 27, @on
-- SP:Completed
exec sp_trace_setevent @TraceID, 43, 1, @on
exec sp_trace_setevent @TraceID, 43, 6, @on
exec sp_trace_setevent @TraceID, 43, 9, @on
exec sp_trace_setevent @TraceID, 43, 10, @on
exec sp_trace_setevent @TraceID, 43, 11, @on
exec sp_trace_setevent @TraceID, 43, 12, @on
exec sp_trace_setevent @TraceID, 43, 13, @on
exec sp_trace_setevent @TraceID, 43, 14, @on
exec sp_trace_setevent @TraceID, 43, 15, @on
exec sp_trace_setevent @TraceID, 43, 16, @on
exec sp_trace_setevent @TraceID, 43, 17, @on
exec sp_trace_setevent @TraceID, 43, 18, @on
exec sp_trace_setevent @TraceID, 43, 27, @on
exec sp_trace_setevent @TraceID, 43, 34, @on
exec sp_trace_setevent @TraceID, 43, 35, @on
-- SP:StmtStarting
exec sp_trace_setevent @TraceID, 44, 1, @on
exec sp_trace_setevent @TraceID, 44, 3, @on
exec sp_trace_setevent @TraceID, 44, 12, @on
exec sp_trace_setevent @TraceID, 44, 14, @on
exec sp_trace_setevent @TraceID, 44, 22, @on
exec sp_trace_setevent @TraceID, 44, 26, @on
exec sp_trace_setevent @TraceID, 44, 27, @on
exec sp_trace_setevent @TraceID, 44, 34, @on
exec sp_trace_setevent @TraceID, 44, 35, @on
-- SQL:BatchStarting
exec sp_trace_setevent @TraceID, 13, 1, @on
exec sp_trace_setevent @TraceID, 13, 3, @on
exec sp_trace_setevent @TraceID, 13, 12, @on
exec sp_trace_setevent @TraceID, 13, 14, @on
exec sp_trace_setevent @TraceID, 13, 26, @on
exec sp_trace_setevent @TraceID, 13, 27, @on
exec sp_trace_setevent @TraceID, 13, 35, @on
-- Exec Prepared SQL
exec sp_trace_setevent @TraceID, 72, 1, @on
exec sp_trace_setevent @TraceID, 72, 6, @on
exec sp_trace_setevent @TraceID, 72, 9, @on
exec sp_trace_setevent @TraceID, 72, 10, @on
exec sp_trace_setevent @TraceID, 72, 11, @on
exec sp_trace_setevent @TraceID, 72, 12, @on
exec sp_trace_setevent @TraceID, 72, 13, @on
exec sp_trace_setevent @TraceID, 72, 14, @on
exec sp_trace_setevent @TraceID, 72, 15, @on
exec sp_trace_setevent @TraceID, 72, 16, @on
exec sp_trace_setevent @TraceID, 72, 17, @on
exec sp_trace_setevent @TraceID, 72, 18, @on
exec sp_trace_setevent @TraceID, 72, 27, @on
exec sp_trace_setevent @TraceID, 72, 34, @on
exec sp_trace_setevent @TraceID, 72, 35, @on
-- Execution Warnings
exec sp_trace_setevent @TraceID, 67, 1, @on
exec sp_trace_setevent @TraceID, 67, 8, @on
exec sp_trace_setevent @TraceID, 67, 10, @on
exec sp_trace_setevent @TraceID, 67, 11, @on
exec sp_trace_setevent @TraceID, 67, 12, @on
exec sp_trace_setevent @TraceID, 67, 14, @on
exec sp_trace_setevent @TraceID, 67, 27, @on
exec sp_trace_setevent @TraceID, 67, 31, @on
exec sp_trace_setevent @TraceID, 67, 35, @on
Image 1 – This shows you how to select information for the event and column.
-- Get trace Event and Column details for event 10 RPC:Completed
SELECT e.Trace_Event_ID,
e.name AS Event_Descr,
c.trace_column_id,
c.name AS Column_Descr,
c.type_name,
c.is_filterable
FROM sys.trace_events e
INNER JOIN sys.trace_event_bindings b
ON b.trace_Event_ID = e.Trace_Event_ID
INNER JOIN sys.trace_columns c
ON b.trace_column_id = c.trace_column_id
WHERE e.Trace_Event_ID = 10
Now if you wish to set filters on the information you wish to collect would do that next. I have some specific filters created plus there are a few commented out just for examples. Make sure to visit the setfilter link above to get a more detailed understanding on this subject as you may not get the results you were hoping just because of how this is configured.
-- Set Filters
DECLARE @DB_ID int
SET @DB_ID = DB_ID('MAS500_app')
-- Creates a filter for only the database MAS500_app
EXEC sp_trace_setfilter @TraceID, 3, 0, 0, @DB_ID -- 3 : DatabaseID
-- Creates a filter to include only if column TextData contains tsoSalesOrder
EXEC sp_trace_setfilter @TraceID, 1, 0, 6, N'%tsoSalesOrder%' -- 1 : TextData, The 6 means LIKE
-- Creates a filter to exclude application SQL Profiler and SQL Agent
EXEC sp_trace_setfilter @TraceID, 10, 0, 7, N'SQL Profiler%' -- The 7 means NOT LIKE
EXEC sp_trace_setfilter @TraceID, 10, 0, 7, N'SQL Agent%' -- The 7 means NOT LIKE
-- Some addtional filter examples that might be useful
-- To set a filter at the Server level instead of or in addtition to the database
--EXEC sp_trace_setfilter @TraceID, 8, 0, 0, 'SERVERNAME' -- 8 : HostName
-- This means to include if the ObjectName is equal to the passed in value
--EXEC sp_trace_setfilter @TraceID, 34, 0, 0, 'spsoCreateSalesOrder' -- 34 : ObjectName
-- This means that TextData will = the value passed in
--EXEC sp_trace_setfilter @TraceID, 1, 0, 0, 'Timeout getting Lock' -- 1 : TextData
Now start the Trace.
-- Start the trace
EXEC sp_trace_setstatus @TraceID, 1
I already covered the error trap and exit logic in the Create Trace segment above but I will provide you with this code again just for clarity sake.
-- display trace id for future references
SELECT TraceID=@TraceID
GOTO finish
-- error trap
error:
SELECT ErrorCode=@rc
-- exit
finish:
GO
How do I find out about my traces(s)?
To get a list of all the running traces on the server use the following statement. This will also show the SQL Server Default trace which is always traceid 1.
SELECT * FROM :: fn_trace_getinfo(default)
To look at the filters that are applied to a trace.
SELECT * FROM :: fn_trace_getfilterinfo(default)
To look at information about the events being traced by a trace use the following select.
SELECT * FROM :: fn_trace_geteventinfo(default)
We covered this already but I am providing these commands again just for clarity sake and a simple point of reference for you related to the setstatus procedure.
-- To start a trace
sp_trace_setstatus traceid, 1 -- TraceId would be the value of the trace
-- To stop a trace
sp_trace_setstatus traceid, 0 -- TraceId would be the value of the trace
-- To close and delete a trace
sp_trace_setstatus traceid, 2 -- TraceId would be the value of the trace
What do I do with my trace now that I am done?
Well you have several options available to you. You can simply open the trace file with SQL Profiler and scroll through it like you might have done in the past or you can load it into a SQL table so you can run queries against it.
The following code snippets show you how you can load data into a new table or an existing table from a trace file.
-- Load into a new table (need to type in the name created above)
SELECT * INTO master..TraceTable_RKL
FROM ::fn_trace_gettable('c:PerflogsMyTrace.trc', DEFAULT)
-- Load into an existing table (need to type in the name created above)
INSERT INTO master..TraceTable_RKL
SELECT * FROM ::fn_trace_gettable('C:PerflogsMyTrace.trc', DEFAULT)
Once you have the data loaded into a table you can look at it just like it is any other table.
-- Look at data in table
SELECT * FROM master..TraceTable_RKL
Don’t forget to cleanup the table when you are finished.
-- cleanup the table
drop table master..TraceTable_RKL
Can I look at the details/contents of the Trace File?
Well yes you can.
-- View the contents of the trace file without loading into a table
-- or using SQL Profiler
SELECT * FROM ::fn_trace_gettable('C:PerflogsMyTrace.trc', DEFAULT)
I hope you found this useful. Thanks for stopping by. Until next time…
