Trace File Rollover & EndTime

  • 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.

  • 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!

  • 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.

  • 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 ?

  • 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.

  • 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.

  • 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

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

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