| 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 TracesAll 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 |
@OutputFile – nvarchar(245) Specifies the trace file name and complete @OverwriteFile – bit Specifies whether to @MaxSize – bigint Specifies the maximum @Rollover – bit Specifies that when @Shutdown – bit Defaults to 0. If you @Blackbox – Defaults to 0. If you specify 1, a blackbox trace will be @StopAt – Defaults to NULL. When NULL, the trace will run @OutputTraceID – int – This is an OUTPUT parameter and returns the Return values: -1 indicates a failure and Note: The ID of the created trace |
| AddEvent
Adds |
@TraceID – int
The ID of @EventList – varchar(1000) Used to specify a @ColumnList – Used to specify a comma separated list of data Return values: -1 indicates a |
| AddFilter
Adds filters to existing trace |
@TraceID – int
The ID of @ColumnName – Name of the column on which to apply the filter. @Value – Specifies the value on which to filter. @ComparisonOperator – varchar(8) Specifies the @LogicalOperator – Defaults to ‘OR’. You could also specify ‘AND’. Return Note: Call this procedure once for each |
| StartTrace
Starts a specified |
@TraceID – int
The ID of Return values: -1 indicates a failure and 0 indicates |
| StopTrace
Stops a specified |
@TraceID – int
The ID of Return values: -1 indicates a failure and 0 indicates |
| ClearTrace
Clears the definition of the |
@TraceID – int
The ID of Return values: -1 indicates a failure and 0 |
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 TracesLongRunningProcs’,
@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 TracesProceduresCalledInMSDB’,
@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 TracesDead 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 TracesRecompilations’,
@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:
