Trace File Rollover & EndTime

Question

Post reply

Trace File Rollover & EndTime

homebrew01

SSC Guru

Points: 55548
More actions
January 3, 2014 at 11:17 am

#281631

I have a server side trace running, and curious how long running jobs are logged. If the trace starts at 1:00 am and is full at 10:00 am (Trace_1.trc) and needs to create a new file (Trace_2.trc) from 10:00 am to 5:00 pm, how would a long running query be logged that started at 9:58 am and runs for 20 minutes ? I assume it will be an entry in Trace_1.trc, but it will complete after Trace_2.trc has started. Where will the "EndTime" be logged ?
I have looked at a few files for an example of a log running job starting near the end of the file but have not found a real example on my system.

Viewing 7 posts - 1 through 6 (of 6 total)

You must be logged in to reply to this topic. Login to reply

Lowell SSC Guru Points: 323518 More actions · Answer 1

I believe in that case, you want to load all the files associated to a trace, instead of individual files.

I typically create a view for every trace i have to make it easier to review them.

here's my classic example; this loads all five files of the default trace into a view.

--SELECT * from sys.traces

declare @TraceIDToReview int

declare @path varchar(255)

declare @cmd varchar(max)

SET @TraceIDToReview = 1 --this is the trace you want to review!

SELECT @path = path from sys.traces WHERE id = @TraceIDToReview

SET @cmd='

CREATE VIEW VW_Trace'

+ RIGHT('00' + CONVERT(varchar,@TraceIDToReview),2)

+ '

AS

SELECT

TE.name As EventClassDescrip,

v.subclass_name As EventSubClassDescrip,

T.*

FROM ::fn_trace_gettable(''' + @path + ''', default) T

LEFT OUTER JOIN sys.trace_events TE ON T.EventClass = TE.trace_event_id

LEFT OUTER JOIN sys.trace_subclass_values V

ON T.EventClass = V.trace_event_id AND T.EventSubClass = V.subclass_value'

print @cmd

IF EXISTS(select * from master.dbo.sysobjects where xtype='V' and name= 'VW_Trace' + RIGHT('00' + CONVERT(varchar,@TraceIDToReview),2))

BEGIN

SET @cmd = REPLACE(@cmd,'CREATE VIEW','ALTER VIEW')

print @cmd

END

print @cmd

--exec(@cmd)

Lowell

--help us help you! If you post a question, make sure you include a CREATE TABLE... statement and INSERT INTO... statement into that table to give the volunteers here representative data. with your description of the problem, we can provide a tested, verifiable solution to your question! asking the question the right way gets you a tested answer the fastest way possible!

Michael Valentine Jones SSC Guru Points: 64818 More actions · Answer 2

homebrew01 (1/3/2014)
I have a server side trace running, and curious how long running jobs are logged. If the trace starts at 1:00 am and is full at 10:00 am (Trace_1.trc) and needs to create a new file (Trace_2.trc) from 10:00 am to 5:00 pm, how would a long running query be logged that started at 9:58 am and runs for 20 minutes ? I assume it will be an entry in Trace_1.trc, but it will complete after Trace_2.trc has started. Where will the "EndTime" be logged ?
I have looked at a few files for an example of a log running job starting near the end of the file but have not found a real example on my system.

The EndTime is captured in the RPC:Completed or SQL:BatchCompleted events, so you should setup the trace to capture those events.

homebrew01 SSC Guru Points: 55548 More actions · Answer 3

I usually dump the files into a table so I can more easily query them, based on the file date and when an event occurred:

SELECT * INTO Trace_20131229

FROM fn_trace_gettable('F:\TraceFiles\MyTrace_x131123_x2330_54.trc', 1);

INSERT INTO Trace_20131229

SELECT *

FROM fn_trace_gettable('F:\TraceFiles\MyTrace_x131123_x2330_55.trc', 1);

And I do capture the EndTime. What I'm not sure is, if a query duration spans trace files, how & where is it captured ?

Michael Valentine Jones SSC Guru Points: 64818 More actions · Answer 4

homebrew01 (1/3/2014)
I usually dump the files into a table so I can more easily query them, based on the file date and when an event occurred:
SELECT * INTO Trace_20131229
FROM fn_trace_gettable('F:\TraceFiles\MyTrace_x131123_x2330_54.trc', 1);
INSERT INTO Trace_20131229
SELECT *
FROM fn_trace_gettable('F:\TraceFiles\MyTrace_x131123_x2330_55.trc'.trc', 1);
And I do capture the EndTime. What I'm not sure is, if a query duration spans trace files, how & where is it captured ?

It will be in the file where the RPC:Completed or SQL:BatchCompleted event for that query is recorded.

homebrew01 SSC Guru Points: 55548 More actions · Answer 5

Michael Valentine Jones (1/3/2014)
It will be in the file where the RPC:Completed or SQL:BatchCompleted event for that query is recorded.

If the query starts during file_1, but completes during file_2, then the entry will be in file_2 ?

So, If I want to find all queries that started between 1:00 am and 10:00 am, I might need to look in the 2nd file (10:00 am - 5:00 pm for a query with a 9:58 am start time ? (Per my example in original post)

Edit: I just confirmed that the older StartTime record will be in the newer file.

Thanks.

Grant Fritchey SSC Guru Points: 398882 More actions · Answer 6

Yep, if you're capturing both start and stop, you could span files.

"The credit belongs to the man who is actually in the arena, whose face is marred by dust and sweat and blood"
- Theodore Roosevelt

Author of:
SQL Server Execution Plans
SQL Server Query Performance Tuning