About myself
My technical
skills
My favorites
My picture album
Shortcut keys
My code library
VB resources
SQLServer
resources
SQLServer books
Replication FAQ
Scripting
resources
ASP resources
Search my site
Sign my
guestbook
Contact
information
SQL Server Articles New
Featured Book:
Book of the month:
|
|
NEW!!! Subscribe to my
newsletter:
Want to keep in touch with the
latest in SQL Server world? Email vyaskn@hotmail.com with
'subscribe' in the subject line |
Automating Server Side Tracing in SQL Server (See also: How to identify SQL Server performance issues, by analyzing Profiler output?)
Note: Information & code samples from this article are tested on SQL Server 2005 RTM (Yukon) and found to be working. Will update the article in case of any compatibility issues. |
Experts from within and outside Microsoft have always said that running Profiler on a production environment is not a recommended practice, as it could degrade the performance of the server. Instead they suggest doing server side tracing via SQL Trace system stored procedures. But DBAs often questioned this by asking, what if I profile the production server, from a different PC? Well, I haven't heard a convincing answer to this whole thing about Profiler vs. server side tracing yet, but I attended SQL PASS 2003 in Seattle (between 11th and 14th of November, 2003). More than once during the event, some of the big wigs from Microsoft PSS recommended server side tracing over Profiler. Well, they definitely know their stuff, so I decided to start using server side tracing, instead of Profiler. Not to mention, I personally heard about incidents where DBAs brought down SQL Servers by running Profiler (especially in version 7.0).
Prior to attending PASS, I've never used SQL Trace system stored procedures to set up a server side trace. So, I started off by reading SQL Server Books Online. There are a bunch of SQL Trace system stored procedures, that you can use to set up a server side trace. There are also a few system functions to query and get information about currently running traces.
Here is a list of SQL Trace system stored procedures and functions:
SQL Trace system stored procedures
sp_trace_create | Creates a trace definition |
sp_trace_generateevent | Creates a user-defined event |
sp_trace_setevent | Adds or removes an event or event column to a trace |
sp_trace_setfilter | Applies a filter to a trace |
sp_trace_setstatus | Used to start, stop and close traces |
SQL Trace system functions
fn_trace_geteventinfo | Returns information about the events traced by a specified trace |
fn_trace_getfilterinfo | Returns information about the filters applied to a specified trace |
fn_trace_getinfo | Returns information about a specified trace or existing traces |
fn_trace_gettable | Returns trace file information in a table format, for querying purposes |
If you look at the documentation for above stored procedures in SQL Server Books Online, you will realize that they accept about four input parameters each, on an average. If you ever used Profiler, you'll know there are numerous events and data columns. It is a bit cumbersome To specify all those events and data columns using these stored procedures. Because, every event has a number associated with it, and so do the data columns. You cannot remember all those numbers and repeatedly call the above procedures by specifying various EventIDs and ColumnIDs. No wonder many DBAs prefer to use the point-and-click Profiler. But hey, Microsoft is not really recommending Profiler on a production server, and I must trace production SQL Servers for various troubleshooting and tuning purposes while working on bugs.
So, I decided to write my own wrapper stored procedures, that wrap the trace system stored procedures and make it easier to setup traces. In this article, I'll provide you with downloadable stored procedures, that you could use to setup your own server side traces, without much effort. These stored procedures make the job almost as easier as using Profiler.
For example, using my wrapper stored procedures, you could setup and start trace, to record all stored procedures that are called in a specified database (with database ID = 37), along with the following information: Actual stored procedure call, start time, end time, duration, application name and host name. As you will see below, we called four different friendly stored procedures. To setup the same trace directly, using trace system stored procedures, you'll have to call at least 10 stored procedures, one for each event traced, and one for each data column captured. A massive saving on the number of stored procedures called :-) and I am definitely finding these wrappers much easier to setup and quicker too. The more complex the trace definition gets, the more savings on the number of stored procedure calls.
DECLARE @TraceID int
EXEC CreateTrace
'C:\My SQL Traces\All Procedure Calls',
@OutputTraceID = @TraceID OUT
EXEC AddEvent
@TraceID,
'SP:Starting',
'TextData, StartTime, EndTime, ApplicationName, ClientHostName, DatabaseID'
EXEC AddFilter
@TraceID,
'DatabaseID',
37
EXEC StartTrace
@TraceID
GO
The massive saving in the number of stored procedure calls to setup the trace, comes from the fact that the main wrapper stored procedure accepts a list of all events and data columns in a comma delimited string format. So, how many ever events and data columns you want to capture in your trace, you'll only make one call to the wrapper stored procedure.
Better yet, all the above wrapper procedures handle errors gracefully, and return meaningful and helpful error messages, instead of throwing some cryptic return code back.
An important note: Only members of the sysadmin fixed server role can execute the SQL Trace system stored procedures. So, even if you manage to call my wrapper stored procedures, they will fail to invoke SQL Trace system procedures, if you are not a sysadmin.
Deployment Instructions:
Click here to download the complete set of scripts in a zip file. Run all the scripts inside a database of your choice. But make sure the tables and stored procedures are created in the same database. I tend to create them in a utilities/tools database created for use by the DBA team.
Now let me introduce you to all the wrapper stored procedures I created:
Stored procedure name | Parameter usage |
CreateTrace
Creates an empty trace definition, ready for use.
Click here to download
|
@OutputFile - nvarchar(245)
Specifies the trace file name and complete path. Do not provide a .trc extension to the file name, as SQL Trace automatically adds the .trc extension to the output file.
@OverwriteFile - bit
Specifies whether to overwrite the trace file, if it already exists. Default is 0, in which case if the file already exists, an error will be raised and trace will not be created. Specify 1 to overwrite an existing trace file.
@MaxSize - bigint
Specifies the maximum size in megabytes (MB) a trace file can grow upto. Default is 5 MB. This stored procedure code restricts the maximum trace file size to 512 MB (half Giga Byte (GB)) as a safety measure, but can be overridden by setting the variable @MaxAllowedSize to a bigger value. You will find @MaxAllowedSize in the body of the stored procedure.
@Rollover - bit
Specifies that when the trace file reaches the maximum specified size, a new trace file will be created. Default is 1, meaning new file will be created when the current trace file reaches the maximum size. If you specify 0, tracing will stop when the file reaches its size limit. The new file will get the same name, but will be postfixed with a number, to indicate the sequence. For example, when the file MyTrace.trc reaches its maximum size, MyTrace_1.trc will be created.
@Shutdown - bit
Defaults to 0. If you specify 1, SQL Server will shut down, if the trace cannot be written to the file for whatever reason. Use this option with caution, and only when absolutely needed.
@Blackbox - bit
Defaults to 0. If you specify 1, a blackbox trace will be created. A black box trace stores a record of the last 5 MB of trace information produced by the server. When 1 is specified, all other parameters will be ignored. To learn more about how black box trace works, consult SQL Server 2000 Books Online.
@StopAt - datetime
Defaults to NULL. When NULL, the trace will run until it is manually stopped or until the server shuts down. If you specify a valid date and time, the trace will stop automatically at that specified date and time.
@OutputTraceID - int - OUTPUT parameter
This is an OUTPUT parameter and returns the ID for the trace that is created. This ID is needed for adding events and filters to the trace, as well as for querying the trace definition.
Return values: -1 indicates a failure and 0 indicates success
Note: The ID of the created trace will also be returned as a resultset for convenience.
|
AddEvent
Adds events and columns to the trace definition.
Click here to download
|
@TraceID - int
The ID of the trace, created by CreateTrace, and is used to identify the trace to which to add the events and columns.
@EventList - varchar(1000)
Used to specify a comma separated list of events to capture. You can see a list of all valid events in the SQL Server Books Online page titled "sp_trace_setevent". Alternatively, you will find a list of all the events and their descriptions, in this script.
@ColumnList - varchar(1000)
Used to specify a comma separated list of data columns to capture. You can see a list of all valid column names in the SQL Server Books Online page titled "sp_trace_setevent". Alternatively, you will find a list of all the data columns and their descriptions, in this script.
Return values: -1 indicates a failure and 0 indicates success
|
AddFilter
Adds filters to existing trace definitions
Click here to download
|
@TraceID - int
The ID of the trace, created by CreateTrace, and is used to identify the trace to which to add the filter.
@ColumnName - varchar(50)
Name of the column on which to apply the filter. You can only filter on a column, after adding that column to the trace definition, using AddEvent
@Value - sql_variant
Specifies the value on which to filter.
@ComparisonOperator - varchar(8)
Specifies the type of comparison to be made. Defaults to '=', meaning 'Equals' comparison. Other valid comparison operators are: '<>' (Not Equal) ,
'>' (Greater Than) , '<' (Less Than) , '>=' (Greater Than Or Equal), '<=' (Less Than Or Equal), 'LIKE' and 'NOT LIKE'.
@LogicalOperator - varchar(3)
Defaults to 'OR'. You could also specify 'AND'. Useful for filtering a column for multiple values.
Return values: -1 indicates a failure and 0 indicates success
Note: Call this procedure once for each filter. If you want to filter a column for a range of values (similar to BETWEEN operator), call this procedure once with '>=' comparison operator and again with '<=' comparison operator.
|
StartTrace
Starts a specified trace.
Click here to download
|
@TraceID - int
The ID of the trace (created by CreateTrace), to be started.
Return values: -1 indicates a failure and 0 indicates success
|
StopTrace
Stops a specified trace.
Click here to download
|
@TraceID - int
The ID of the trace (created by CreateTrace), to be stopped.
Return values: -1 indicates a failure and 0 indicates success
|
ClearTrace
Clears the definition of the trace from memory.
Click here to download
|
@TraceID - int
The ID of the trace (created by CreateTrace), to be cleared from memory.
Return values: -1 indicates a failure and 0 indicates success
|
Now that we know what the stored procedures are called and how to use their parameters, let me show you, how to use these stored procedures to setup traces for specific requirements. Before we go any further, here is a quick tip. Once you setup a specific trace using my wrapper stored procedures, you could save all those stored procedure calls in a file. Now this file will serve you as a template, just like the Profiler templates.
Scenario 1: Identifying long running stored procedures
In this scenario, we will trace for all stored procedures, that took more than 15 Seconds to complete. The output trace file 'LongRunningProcs.trc' will be saved to 'C:\My SQL Traces\' (Note that this is the location on the SQL Server machine, not the client machine).
DECLARE @TraceID int
EXEC CreateTrace
'C:\My SQL Traces\LongRunningProcs',
@OutputTraceID = @TraceID OUT
EXEC AddEvent
@TraceID,
'SP:Completed',
'TextData, Duration'
EXEC AddFilter
@TraceID,
'Duration',
15000,
'>='
EXEC StartTrace @TraceID
GO
Once you are done, you could stop the trace by calling the following stored procedures. Important Note: You can only view the trace file, after successfully stopping the trace and clearing it from memory: (Lets assume that the ID of the trace created above was 1)
EXEC StopTrace 1
EXEC ClearTrace 1
Scenario 2: Get a list of all the stored procedures called within a specific database:
In this scenario, I will show you, how to get a list of all the stored procedures called, from within a specific database. In this example, we will look for all stored procedure calls from msdb database. We will also capture the start time, end time, application name, client host name, NT user name and the domain name.
DECLARE @TraceID int, @DB_ID int
EXEC CreateTrace
'C:\My SQL Traces\ProceduresCalledInMSDB',
@OutputTraceID = @TraceID OUT
EXEC AddEvent
@TraceID,
'SP:Completed',
'TextData, StartTime, EndTime, ApplicationName, ClientHostName, NTUserName, NTDomainName, DatabaseID'
SET @DB_ID = DB_ID('msdb')
EXEC AddFilter
@TraceID,
'DatabaseID',
@DB_ID
EXEC StartTrace @TraceID
GO
Scenario 3: Tracing for specific errors:
Let us imagine a scenario, where you deployed a brand new application and database. Now the old database is not needed anymore. So, you took the old database offline, but you want to make sure no user or application is trying to access the old database. As you probably know, when somebody or some application tries to open an offline database, you get the following error: 942: Database 'OldDatabase' cannot be opened because it is offline. In the following example, we will setup a trace that looks for error 942 and captures the time of the request, application name, NT user name and the client machine name from which the request originated. We will also specify that if the trace file already exists, it'll be overwritten.
DECLARE @TraceID int
EXEC CreateTrace
'C:\Trapping942s',
@OverwriteFile = 1,
@OutputTraceID = @TraceID OUTPUT
EXEC AddEvent
@TraceID,
'Exception',
'Error, StartTime, ApplicationName, NTUserName, ClientHostName'
EXEC AddFilter
@TraceID,
'Error',
942
EXEC StartTrace @TraceID
Scenario 4: Troubleshooting deadlocks:
In this scenario, I will show you how to setup a trace to identify the connections (SPIDs) involved in a deadlock, using the Deadlock and Deadlock Chain events.
DECLARE @TraceID int
EXEC dbo.CreateTrace
'C:\My SQL Traces\Dead Locks',
@OutputTraceID = @TraceID OUT
EXEC dbo.AddEvent
@TraceID,
'Lock:Deadlock, Lock:Deadlock Chain, RPC:Starting, SQL:BatchStarting',
'TextData'
EXEC dbo.StartTrace
@TraceID
Scenario 5: Identifying stored procedure recompilations:
Stored procedure recompiles have a potential to hinder the performance of your application. So it is important to identify those procedures that are recompiling repeatedly, and fix them, if the recompilation is not beneficial. The following template creates a trace that logs the stored procedures that are recompiling along with the database ID in which they are running. It also captures EventSubClass. From SQL Server 2000 SP3 and above, EventSubClass tells you the exact reason for the stored procedure recompilation. For more information search Microsoft Knowledge Base (KB) for article 308737.
DECLARE @TraceID int
EXEC dbo.CreateTrace
'C:\My SQL Traces\Recompilations',
@OutputTraceID = @TraceID OUT
EXEC dbo.AddEvent
@TraceID,
'SP:Recompile',
'ObjectID, ObjectName, EventSubClass, DatabaseID'
EXEC dbo.StartTrace
@TraceID
Scenario 6: Starting a Blackbox trace:
A black box trace stores a record of the last 5 MB of trace information produced by the server. This is very useful for troubleshooting nasty problems, bugs and access violation errors, that cause the SQL Server to shutdown. Consult SQL Server 2000 Books Online and Microsoft Knowledge Base for more information on Blackbox traces.
DECLARE @TraceID int
EXEC CreateTrace
@Blackbox = 1,
@OutputTraceID = @TraceID OUT
EXEC StartTrace
@TraceID
Conclusion:
The above scenarios, will just get you started, but you can really use these stored procedures to setup complicated traces with various columns, events and different types of filters. I hope you find my work useful. For the sake of completeness, I'll mention the fact that, you could even schedule the above stored procedures, as SQL Agent jobs, in order to start the traces at a desired date and time.
In the process of learning the SQL Trace system stored procedures, I did stumble upon few bugs. For example, when you set a filter on ObjectID, and then query the trace definition using fn_trace_getfilterinfo function, the ObjectID reported will be incorrect when the ObjectID is greater than 255 (SELECT value FROM ::fn_trace_getfilterinfo(@TraceID)).
One thing I observed with Profiler is that, though the trace system stored procedures support the comparison operators > and <, Profiler only shows >= and <=.
Before we end, here are the links to some of the best SQL Server performance tuning related books. I personally, read some of these books and found them extremely useful and enlightening. Hope you find them useful too:
Top
|