A Guide To Building and Running A Replayable Trace File In SQL Server
Running a SQL Trace in SQL Server is a great way to get a snapshot of the activity occurring in a database at any given time. It can be used to determine and analyze what procedure is being called or capture activity for a particular user or users. There are a host of configuration options within both SQL Profiler and when running a trace manually through a script.
One often overlooked feature of SQL tracing is the ability to create a replayable trace. A replayable trace allows you to capture the activity on one server and, using the saved trace file(s), replay it on another server. This can be used for debugging or if you want to test a particular data load on a different server.
In a recent case I ran a 2 hour replayable trace against a production database running on SQL Server 2012 and restored a recent backup of that database to a SQL Server 2016 environment. I then replayed the trace to get a better understanding of any issues that might arise if we were to upgrade to SQL Server 2016. Though this was just a first step in the overall analysis of that project, it gave me a huge jump start on knowing how tedious an upgrade might be.
There are two solid methods for running a replayable trace. First, you can run it within SQL Server Profiler using the TSQL_Replay template. The screenshot below demonstrates this.
As you can see I have given the trace a name and updated the template being used to show TSQL_Replay. I also chose to save the trace as a file to my H:\ drive.
It is also important to make sure you set the max file size for each trace file. In the screenshot above I have it set to 100MB. If exceeded, a new trace file will be created. If the total size of the trace was 350MB I would have three 100MB files and a single 50MB file for a total of 4 files.
I’m not a fan of using SQL Server Profiler to run large production traces.
With that said, I will now discuss the second method for running a replayable trace in SQL Server. Though it may appear slightly more complicated, it is much less resource intensive than SQL Profiler and provides the same level of customization.
To begin with you’ll need to copy/paste the following dbo.runtrace
stored procedure into SQL Server Management Studio. Don’t execute the script quite yet as you’ll want to make some changes before pushing it to your database. The procedure is essentially what SQL Server Profiler calls when running a trace. There are a host of parameters provided which can be used to further customize your trace. For the purposes of this post I will only be focusing on a few of these options.
USE [master]
GO
IF EXISTS (SELECT 1 FROM sysobjects WHERE ID = OBJECT_ID('dbo.runtrace') AND TYPE = 'P')
DROP PROCEDURE dbo.runtrace
GO
CREATE PROCEDURE dbo.runtrace (@trace_file_folder varchar(1000) = 'S:\TraceFiles',
@trace_runtime_in_min int = 120, --RUNTIME IN MINUTES
@trace_filter_duration_in_ms int = 2000,
@completed_events int = 1,
@started_events int = 0,
@errors_warnings int = 0,
@locking_info int = 0,
@auto_stats int = 0,
@transaction_info int = 0,
@showplan_xml int = 0,
@filter_spid int = 0,
@filter_loginname nvarchar(50) = '',
@filter_application nvarchar(300) = '',
@filter_hostname nvarchar(100) = '',
@logins_logouts int = 0,
@deadlocks int = 0,
@objects_changed int = 0,
@blocking int = 0, --if you turn this ON will only capture dbid > 4
@replayable int = 0)
AS
SET NOCOUNT ON
declare @rc int
declare @TraceID int
declare @maxfilesize bigint
declare @stop datetime
declare @tracefilename nvarchar(1000)
declare @tbl_eventclass table(eventclass int)
declare @eventclass int
declare @tbl_columns table(colid int)
declare @columns int
declare @on bit
-----------------------------------------
--Declare & Set Columns we will collect for each eventclass
-----------------------------------------
insert @tbl_columns values (1) -- textdata
insert @tbl_columns values (3) -- databaseid
insert @tbl_columns values (4) -- transactionid
insert @tbl_columns values (5) -- linenumber
insert @tbl_columns values (6) -- ntusername
insert @tbl_columns values (8) -- hostname
insert @tbl_columns values (10) -- applicationname
insert @tbl_columns values (11) -- loginname
insert @tbl_columns values (12) -- spid
insert @tbl_columns values (13) -- duration
insert @tbl_columns values (14) -- starttime
insert @tbl_columns values (15) -- endtime
insert @tbl_columns values (16) -- reads
insert @tbl_columns values (17) -- writes
insert @tbl_columns values (18) -- cpu
insert @tbl_columns values (20) -- severity
insert @tbl_columns values (21) -- eventsubclass
insert @tbl_columns values (22) -- objectid
insert @tbl_columns values (24) -- indexid
insert @tbl_columns values (25) -- integerdata
insert @tbl_columns values (26) -- servername
insert @tbl_columns values (27) -- eventclass
insert @tbl_columns values (28) -- objecttype
insert @tbl_columns values (29) -- nestlevel
insert @tbl_columns values (30) -- state
insert @tbl_columns values (31) -- error
insert @tbl_columns values (32) -- mode
insert @tbl_columns values (34) -- objectname
insert @tbl_columns values (35) -- databasename
insert @tbl_columns values (48) -- rowcounts
insert @tbl_columns values (56) -- objectid2
insert @tbl_columns values (59) -- parentname
if @replayable = 1
begin
insert @tbl_columns values (2) -- BinaryData
insert @tbl_columns values (7) -- NTDomainName
insert @tbl_columns values (9) -- ClientProcessID
insert @tbl_columns values (19) -- Permissions
insert @tbl_columns values (33) -- Handle
insert @tbl_columns values (51) -- EventSequence
insert @tbl_columns values (60) -- IsSystem
end
if @blocking = 1
begin
insert @tbl_columns values (51)
insert @tbl_columns values (60)
end
-----------------------------------------
--replace duration, server and share name
-----------------------------------------
set @on = 1
set @maxfilesize = 100 --MAX FILE SIZE IN MB
set @stop = dateadd(mi, @trace_runtime_in_min, getdate())
if right(@trace_file_folder, 1) = '\'
begin
set @tracefilename = @trace_file_folder + 'trace~'
end
else
begin
set @tracefilename = @trace_file_folder + '\trace~'
end
set @tracefilename = @tracefilename + replace(isnull(@@SERVERNAME, ''),'\','~') + '~' +
REPLACE(replace(convert(varchar(50),getdate(),120),':',''),' ','-')
set @tracefilename = @tracefilename + '~dur-' +
CONVERT(varchar(5),@trace_filter_duration_in_ms) + '~'
set @tracefilename = @tracefilename + convert(char(1),@completed_events)
set @tracefilename = @tracefilename + convert(char(1),@started_events)
set @tracefilename = @tracefilename + convert(char(1),@errors_warnings)
set @tracefilename = @tracefilename + convert(char(1),@locking_info)
set @tracefilename = @tracefilename + convert(char(1),@auto_stats)
set @tracefilename = @tracefilename + convert(char(1),@transaction_info)
set @tracefilename = @tracefilename + convert(char(1),@showplan_xml)
set @tracefilename = @tracefilename + convert(char(1),@logins_logouts)
set @tracefilename = @tracefilename + convert(char(1),@deadlocks)
set @tracefilename = @tracefilename + convert(char(1),@objects_changed)
set @tracefilename = @tracefilename + convert(char(1),@blocking)
if @filter_spid > 0
set @tracefilename = @tracefilename + '~spid-' + convert(varchar(5),@filter_spid)
if @filter_loginname <> ''
set @tracefilename = @tracefilename + '~login-' + @filter_loginname
--if @filter_application <> ''
--set @tracefilename = @tracefilename + '~appl-' + @filter_application
exec @rc = sp_trace_create @TraceID output, 2, @tracefilename, @maxfilesize, @stop
if (@rc != 0) goto error
-----------------------------------------
-- COMPLETED EVENTS
-----------------------------------------
if @completed_events = 1
begin
insert @tbl_eventclass values (10) -- RPC:Completed
insert @tbl_eventclass values (12) -- SQL:BatchCompleted
insert @tbl_eventclass values (41) -- SQL:StmtCompleted
insert @tbl_eventclass values (45) -- SP:StmtCompleted
--insert @tbl_eventclass values (37) -- SP: Recompile
end
-----------------------------------------
-- STARTED EVENTS
-----------------------------------------
if @started_events = 1
begin
insert @tbl_eventclass values (11) -- RPC:Started
insert @tbl_eventclass values (13) -- SQL:BatchStarted
insert @tbl_eventclass values (42) -- SP:Starting
insert @tbl_eventclass values (44) -- SP:StmtStarted
end
-----------------------------------------
-- ERRORS AND WARNINGS
-----------------------------------------
if @errors_warnings = 1
begin
insert @tbl_eventclass values (16) -- Attention
insert @tbl_eventclass values (20) -- Audit Login Failed
insert @tbl_eventclass values (21) -- EventLog
insert @tbl_eventclass values (22) -- ErrorLog
--insert @tbl_eventclass values (25) -- Deadlock
insert @tbl_eventclass values (33) -- Exception
--insert @tbl_eventclass values (34) -- SP:CacheMiss
--insert @tbl_eventclass values (59) -- Deadlock Chain
--insert @tbl_eventclass values (37) -- SP: Recompile
--insert @tbl_eventclass values (54) -- Transaction Log Backup
insert @tbl_eventclass values (55) -- Hash Warning
insert @tbl_eventclass values (61) -- OLEDB Error
insert @tbl_eventclass values (67) -- Execution Warning
insert @tbl_eventclass values (69) -- Sort Warnings
insert @tbl_eventclass values (79) -- Missing Column Statistics
insert @tbl_eventclass values (80) -- Missing Join Predicate
insert @tbl_eventclass values (92) -- Data File Autogrow
insert @tbl_eventclass values (93) -- Log File Autogrow
insert @tbl_eventclass values (94) -- Data File Autoshrink
insert @tbl_eventclass values (95) -- Log File Autoshrink
insert @tbl_eventclass values (115) -- Backup/Restore
insert @tbl_eventclass values (116) -- DBCC Event
insert @tbl_eventclass values (166) -- SP:StmtRecompile
end
-----------------------------------------
-- LOCKING INFO
-----------------------------------------
if @locking_info = 1
begin
insert @tbl_eventclass values (24) -- Lock Acquired
insert @tbl_eventclass values (60) -- Lock Escalation
end
-----------------------------------------
-- AUTO STATISTICS
-----------------------------------------
if @auto_stats = 1
begin
insert @tbl_eventclass values (58) -- Auto Update Statistics
end
-----------------------------------------
-- TRANSACTION OPEN/CLOSE INFO
-----------------------------------------
if @transaction_info = 1
begin
insert @tbl_eventclass values (50) -- Transaction Open/Close Events
end
-----------------------------------------
-- EXECUTION PLANS
-----------------------------------------
if @showplan_xml = 1
begin
insert @tbl_eventclass values (122) -- ShowPlan XML Event
end
-----------------------------------------
-- LOGINS AND LOGOUTS
-----------------------------------------
if @logins_logouts = 1
begin
insert @tbl_eventclass values (14) -- Audit Login
insert @tbl_eventclass values (15) -- Audit Logout
end
-----------------------------------------
-- DEADLOCKS
-----------------------------------------
if @deadlocks = 1
begin
insert @tbl_eventclass values (148) -- Deadlock
insert @tbl_eventclass values (25) -- Deadlock Graph
insert @tbl_columns values (2) -- binarydata
insert @tbl_columns values (7)
insert @tbl_columns values (9)
insert @tbl_columns values (41)
insert @tbl_columns values (49)
insert @tbl_columns values (51)
insert @tbl_columns values (52)
insert @tbl_columns values (55)
insert @tbl_columns values (57)
insert @tbl_columns values (58)
insert @tbl_columns values (60)
insert @tbl_columns values (64)
--insert @tbl_columns values (66)
end
-----------------------------------------
-- OBJECTS CHANGED
-----------------------------------------
if @objects_changed = 1
begin
insert @tbl_eventclass values (164) -- Object Altered
insert @tbl_eventclass values (46) -- Object Created
insert @tbl_columns values (47) -- Object Deleted
--only get user databases.
exec sp_trace_setfilter @TraceID, 3, 0, 4, 5
end
-----------------------------------------
-- BLOCKING
-----------------------------------------
if @blocking = 1
insert @tbl_eventclass values (137)
-----------------------------------------
-- REPLAYABLE TRACE
-----------------------------------------
if @replayable = 1
begin
insert @tbl_eventclass values (10) -- RPC:Completed
insert @tbl_eventclass values (11) -- RPC:Starting
insert @tbl_eventclass values (12) -- SQL:BatchCompleted
insert @tbl_eventclass values (13) -- SQL:BatchStarting
insert @tbl_eventclass values (14) -- Audit Login
insert @tbl_eventclass values (15) -- Audit Logout
insert @tbl_eventclass values (16) -- Attention
insert @tbl_eventclass values (17) -- ExistingConnection
insert @tbl_eventclass values (53) -- CursorOpen
insert @tbl_eventclass values (70) -- CursorPrepare
insert @tbl_eventclass values (71) -- Prepare SQL
insert @tbl_eventclass values (72) -- Exec Prepared SQL
insert @tbl_eventclass values (74) -- CursorExecute
insert @tbl_eventclass values (77) -- CursorUnprepare
insert @tbl_eventclass values (78) -- CursorClose
insert @tbl_eventclass values (100) -- RPC Output Parameter
end
-----------------------------------------
-- Setup EventClasses & Columns to Capture in Trace
-----------------------------------------
DECLARE cur_eventclass CURSOR FORWARD_ONLY STATIC FOR
SELECT eventclass
FROM @tbl_eventclass
ORDER BY eventclass
OPEN cur_eventclass
FETCH NEXT FROM cur_eventclass INTO @eventclass
WHILE @@FETCH_STATUS = 0
BEGIN
DECLARE cur_columns CURSOR FORWARD_ONLY STATIC FOR
SELECT colid
FROM @tbl_columns
order by colid
OPEN cur_columns
FETCH NEXT FROM cur_columns INTO @columns
WHILE @@FETCH_STATUS = 0
BEGIN
exec sp_trace_setevent @TraceID, @eventclass, @columns, @on
FETCH NEXT FROM cur_columns INTO @columns
END
CLOSE cur_columns
DEALLOCATE cur_columns
-- Get the next vendor.
FETCH NEXT FROM cur_eventclass INTO @eventclass
END
CLOSE cur_eventclass
DEALLOCATE cur_eventclass
-- Set the Filters
declare @intfilter int
declare @bigintfilter bigint
--exec sp_trace_setfilter @TraceID, 10, 0, 7, N'SQL Profiler'
--set @bigintfilter = @trace_filter_duration_in_ms
--exec sp_trace_setfilter @TraceID, 10, 0, 7, N'SQL Server Profiler%'
set @bigintfilter = @trace_filter_duration_in_ms
set @bigintfilter = @bigintfilter * 1000 --after SQL2000 had to do this.
/*
Enumerations for the sp_trace_setfilter procedure below
The 2nd parameter is the columnID
The 3rd parameter - 0 means AND, 1 means OR
The 4th parameter is the logical operand
0 = (Equal)
1 <> (Not Equal)
2 > (Greater Than)
3 < (Less Than)
4 >= (Greater Than Or Equal)
5 <= (Less Than Or Equal)
6 LIKE
7 NOT LIKE
*/
--Set Duration >= a Value
exec sp_trace_setfilter @TraceID, 13, 0, 4, @bigintfilter
-- Filter for LoginName if it was supplied
-- Set LoginName = a Value
If @filter_loginname <> ''
exec sp_trace_setfilter @TraceID, 11, 0, 0, @filter_loginname
-- Filter for HostName if it was supplied
-- Set HostName = a Value
If @filter_hostname <> ''
exec sp_trace_setfilter @TraceID, 8, 0, 0, @filter_hostname
-- Filter for ApplicationName if it was supplied
-- Set ApplicationName LIKE a Value
If @filter_application <> ''
exec sp_trace_setfilter @TraceID, 10, 0, 6, @filter_application
-- Filter for Spid if it was supplied
-- Set Spid LIKE a Value
If @filter_spid > 0
exec sp_trace_setfilter @TraceID, 12, 0, 0, @filter_spid
-- Set the trace status to start
exec sp_trace_setstatus @TraceID, 1
-- display trace id for future references
select TraceID=@TraceID, @tracefilename + '.trc', 'started at ' +
CONVERT(varchar(40),getdate()), 'will stop at ' + convert(varchar(40), @stop)
goto finish
error:
select ErrorCode=@rc, case @rc
when 1 then 'ERROR: Unknown error.'
when 10 then 'ERROR: Invalid options. Returned when options specified are incompatible.'
when 12 then 'ERROR: File could not be created. Make sure folder pre-exists.'
when 13 then 'ERROR: Out of memory. Returned when there is not enough memory to perform the specified action.'
when 14 then 'ERROR: Invalid stop time. Returned when the stop time specified has already happened.'
when 15 then 'ERROR: Invalid parameters. Returned when the user supplied incompatible parameters.'
else '' end
finish:
GO
Once you’ve copied the contents of the script to a query window you’ll want to take note and likely modify several items before pushing the procedure to the database. Though this is not technically necessary as you can pass new parameters to the script when calling it, it’s good to set a baseline so you won’t need to pass as many parameters to the procedure when calling it.
The first item you may want to change will be the very first line of the script. USE [master]
will push the procedure to the master system database. I prefer to update this to publish the procedure to the desired user database.
The next piece of the script that you will want to modify concerns the file path location. At the top of the script where the CREATE PROCEDURE
code resides you will see the parameter @trace_file_folder
being called. In the example above it is set to S:\TraceFiles
. You will want to modify this to write to a local or network drive available to your server.
Next you’ll want to update the @trace_runtime_in_min
parameter to specify how long the trace should run. This part of the script is directly below the CREATE PROCEDURE
piece. By default it is set to 120 minutes.
Finally you’ll want to update the @maxfilesize
parameter. By default this is set to 100. As before, when configuring the trace in SQL Profiler, you can set the max size of each trace file. The parameter for setting this is located about a quarter of the way down the script.
Once you’ve made the necessary changes to the script you can publish it to the database.
When you’re ready to call the procedure you can use the following script to do so:
exec dbo.runtrace @trace_file_folder = 'G:\TraceFiles',
@trace_runtime_in_min = 5, --5 minutes
@completed_events = 0,
@trace_filter_duration_in_ms = 0,
@replayable = 1
The first thing you’ll notice are some of the parameters already match what is in the procedure. Technically speaking, if they are the same, then they do not actually need to be included in the execute statement. However, when calling the procedure I have changed the @trace_file_folder
to reference the G:\ drive instead of the S:\ drive specified in the procedure. This will reassign the file path for this execution of the procedure. I have also updated the @trace_runtime_in_min
to only run for 5 minute instead of 2 hours.
The most important piece of the script is concerning the @replayable
parameter. By default, within the procedure, this is set to 0. Since we want to be able to replay the trace this must be set to 1 prior to executing the script.
Once your have executed dbo.runtrace
with the desired parameters you will see the following output. Take note of the last column which will indicate when the trace will be complete.
The next step is to replay the trace file against a database.
In order to do this you’ll need to open SQL Server Profiler and connect to the server from which you want to replay the trace events.
Once connected navigate to File>>Open>>Trace File as shown below.
Due to certain permission issues on certain servers, you may need to copy the trace file(s) to a new location. A common error message you may see when opening the trace files directly from the folder to which they were saved is shown below:
Even though I am a domain admin and sysadmin on this server, the file I am trying to open is essentially locked. To resolve I simply copied the folder containing the trace files to my desktop and opened them from there.
Once the trace file has been loaded into Profiler, you’ll notice you now have access to the Replay option on the menu, which would have previously been grayed out.
Select Replay from the menu and click Start.
The Replay Configuration window will be displayed. On the Basic Replay Options tab you can save the results to either a file or an existing table in the database. For this example I will be saving to a file on my desktop named Replay_Test.trc. I also recommend checking the box next to Display execution time. This will display the total execution time for each event as the trace is being replayed on the server. I find this to be one of the more useful fields when comparing stats between servers and am not sure why it’s not checked by default.
Though I have made no changes to the default settings regarding the Number of replay threads, its important to understand this setting. This allows you to specify the number of replay threads that will be used concurrently. A higher number of threads will consume more resources during the replay but will speed up the overall time it takes for the replay to complete. It’s important to note that event ordering is not a factor when multiple threads are being used.
Now click on the Advanced Replay Options tab. Review the options here. The screenshot below shows the default setting for this tab. Though I will not be making any changes to this tab, I find the most useful feature here to be the option to Enable SQL Server blocked processes monitor. For certain performance analysis traces this can be used to set how often the blocked processes monitor searches for blocking in the database. This can be useful when combined with a replayable trace as you will essentially be replaying the blocking events.
Once you have made the necessary configuration changes click OK to start the replay.
While the replay is running you will see a secondary pane open below the original trace file that shows the results of the replay. While the replay is running, you will also see a marker moving through the original trace which indicates which statements are currently being executed. The replay shouldn’t take nearly as long as the original trace as it will execute each statement immediately after the previous one completes.
When the replay is finished you can then go through the results and analyze it for any errors and check the execution times. The final record in the replay results will include the Replay Statistics Events output.
This will sum up the results of the replay and provide you with some valuable insight regarding how the trace replayed on the server.
Replayable traces can be very useful when diagnosing a variety of performance issues in SQL Server. They can also be used to test how activity on the server might be affected by an upgrade. For example, by simply capturing a replayalbe trace on a SQL Server 2012 environment and then replaying it against a 2016 environment you can easily test to see if any obvious issues might arise. Though this would only be a starting point in upgrade testing, it can certainly highlight any major issues you might encounter as well as provide you with some useful statistics regarding the upgraded environment.