Bug in Profiler GUI when viewing .trc file

  • Hello

    I have recorded a Profiler trace to a flat file using the sp_trace procs.

    When I query the flat file using the fn_trace_gettable i can see the

    TextData field but when I open the flat file through the Profiler GUI I dont

    see the TextData field. Its not in the properties nor is the filter.

    These are the events I'm logging. The trace script was generated by Profiler:

    -- Set the events

    declare @on bit

    set @on = 1

    exec sp_trace_setevent @TraceID, 10, 15, @on

    exec sp_trace_setevent @TraceID, 10, 16, @on

    exec sp_trace_setevent @TraceID, 10, 1, @on

    exec sp_trace_setevent @TraceID, 10, 9, @on

    exec sp_trace_setevent @TraceID, 10, 17, @on

    exec sp_trace_setevent @TraceID, 10, 2, @on

    exec sp_trace_setevent @TraceID, 10, 10, @on

    exec sp_trace_setevent @TraceID, 10, 18, @on

    exec sp_trace_setevent @TraceID, 10, 11, @on

    exec sp_trace_setevent @TraceID, 10, 12, @on

    exec sp_trace_setevent @TraceID, 10, 13, @on

    exec sp_trace_setevent @TraceID, 10, 6, @on

    exec sp_trace_setevent @TraceID, 10, 14, @on

    is this a BUG or is there a way to see the Textdata field through Profiler?

    tks

    thanks

    SQL_EXPAT

  • Go into the Properties to the Events Selection tab and be sure that you've got the TextData column selected for the event you're viewing. I see that you've got Column 1 (TextData) set in your event, so it should be available.

    "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

  • Hi

    The properties box does not list the TextData column nor does it list the filter I specify in my script.

    The textdata field is there in the .trc file as I can see it when I query the file with fn_trace_gettable.

    Strange one.

    vtw - the script to run the trace was generated by Profiler.

    tks

    thanks

    SQL_EXPAT

  • If you click on "Show all columns" it doesn't appear way off to the right on the screen? If I turn off TextData for the event, then the column becomes invisible in properties unless I turn on "Show all columns." I'm pretty sure it's there. I do RPC traces all the time with no issue.

    "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

  • No, the textdata field is not there in the properties.

    This is my trace code. Try it for yourself. You will see that the .trc file that gets generated does not include the TextData field when viewed through Profiler:

    -- Create a Queue

    declare @rc int

    declare @TraceID int

    declare @maxfilesize bigint

    set @maxfilesize = 5

    exec @rc = sp_trace_create @TraceID output, 0, N'c:\temp\mytrace', @maxfilesize, NULL

    if (@rc != 0) goto error

    -- Set the events

    declare @on bit

    set @on = 1

    exec sp_trace_setevent @TraceID, 10, 15, @on

    exec sp_trace_setevent @TraceID, 10, 16, @on

    exec sp_trace_setevent @TraceID, 10, 1, @on

    exec sp_trace_setevent @TraceID, 10, 9, @on

    exec sp_trace_setevent @TraceID, 10, 17, @on

    exec sp_trace_setevent @TraceID, 10, 2, @on

    exec sp_trace_setevent @TraceID, 10, 10, @on

    exec sp_trace_setevent @TraceID, 10, 18, @on

    exec sp_trace_setevent @TraceID, 10, 11, @on

    exec sp_trace_setevent @TraceID, 10, 12, @on

    exec sp_trace_setevent @TraceID, 10, 13, @on

    exec sp_trace_setevent @TraceID, 10, 6, @on

    exec sp_trace_setevent @TraceID, 10, 14, @on

    -- Set the Filters

    declare @intfilter int

    declare @bigintfilter bigint

    exec sp_trace_setfilter @TraceID, 10, 1, 6, N'My Filter'

    exec sp_trace_setfilter @TraceID, 10, 0, 7, N'SQL Server Profiler - 35ff2f1f-0398-497c-9343-79e86524fe14'

    -- Set the trace status to start

    exec sp_trace_setstatus @TraceID, 1

    -- display trace id for future references

    select TraceID=@TraceID

    goto finish

    error:

    select ErrorCode=@rc

    finish:

    go

    --stop trace

    declare @trace_id INT

    select @trace_id = 0

    select @trace_id = traceid

    from fn_trace_getinfo (NULL)

    where value = 'c:\temp\mytrace.trc'

    IF @trace_id <> 0

    BEGIN

    -- Stops the specified trace.

    EXEC master..sp_trace_setstatus @traceid = @trace_id ,@status = 0

    -- Closes the specified trace and deletes its definition from the server.

    EXEC master..sp_trace_setstatus @traceid = @trace_id ,@status = 2

    END

    -- query trace file

    select Textdata, *

    from fn_trace_gettable('c:\temp\mytrace.trc',0)

    thanks

    SQL_EXPAT

  • The only events you're seeing are Trace Start and Trace Stop. TextData is not available for these events. If you make sure that it generates events, you can see them. I turned off your filters, added BatchCompleted events and ran some queries in between in order to generate values. Now the TextData is right there.

    -- Create a Queue

    declare @rc int

    declare @TraceID int

    declare @maxfilesize bigint

    set @maxfilesize = 5

    exec @rc = sp_trace_create @TraceID output, 0, N'c:\temp\mytrace2',

    @maxfilesize, NULL

    if ( @rc != 0 )

    goto error

    -- Set the events

    declare @on bit

    set @on = 1

    exec sp_trace_setevent @TraceID, 10, 15, @on

    exec sp_trace_setevent @TraceID, 10, 16, @on

    exec sp_trace_setevent @TraceID, 10, 1, @on

    exec sp_trace_setevent @TraceID, 10, 9, @on

    exec sp_trace_setevent @TraceID, 10, 17, @on

    exec sp_trace_setevent @TraceID, 10, 2, @on

    exec sp_trace_setevent @TraceID, 10, 10, @on

    exec sp_trace_setevent @TraceID, 10, 18, @on

    exec sp_trace_setevent @TraceID, 10, 11, @on

    exec sp_trace_setevent @TraceID, 10, 12, @on

    exec sp_trace_setevent @TraceID, 10, 13, @on

    exec sp_trace_setevent @TraceID, 10, 6, @on

    exec sp_trace_setevent @TraceID, 10, 14, @on

    exec sp_trace_setevent @TraceID, 12, 15, @on

    exec sp_trace_setevent @TraceID, 12, 16, @on

    exec sp_trace_setevent @TraceID, 12, 1, @on

    exec sp_trace_setevent @TraceID, 12, 9, @on

    exec sp_trace_setevent @TraceID, 12, 17, @on

    exec sp_trace_setevent @TraceID, 12, 2, @on

    exec sp_trace_setevent @TraceID, 12, 10, @on

    exec sp_trace_setevent @TraceID, 12, 18, @on

    exec sp_trace_setevent @TraceID, 12, 11, @on

    exec sp_trace_setevent @TraceID, 12, 12, @on

    exec sp_trace_setevent @TraceID, 12, 13, @on

    exec sp_trace_setevent @TraceID, 12, 6, @on

    exec sp_trace_setevent @TraceID, 12, 14, @on

    -- Set the Filters

    declare @intfilter int

    declare @bigintfilter bigint

    --exec sp_trace_setfilter @TraceID, 10, 1, 6, N'My Filter'

    --exec sp_trace_setfilter @TraceID, 10, 0, 7, N'SQL Server Profiler - 35ff2f1f-0398-497c-9343-79e86524fe14'

    -- Set the trace status to start

    exec sp_trace_setstatus @TraceID, 1

    -- display trace id for future references

    select TraceID = @TraceID

    goto finish

    error:

    select ErrorCode = @rc

    finish:

    go

    exec sp_who ;

    go

    use boundbooked ;

    select *

    from dbo.C_country

    go

    exec sp_who ;

    go

    --stop trace

    declare @trace_id INT

    select @trace_id = 0

    select @trace_id = traceid

    from fn_trace_getinfo(NULL)

    where value = 'c:\temp\mytrace2.trc'

    IF @trace_id <> 0

    BEGIN

    -- Stops the specified trace.

    EXEC master..sp_trace_setstatus @traceid = @trace_id, @status = 0

    -- Closes the specified trace and deletes its definition from the server.

    EXEC master..sp_trace_setstatus @traceid = @trace_id, @status = 2

    END

    -- query trace file

    select Textdata

    ,*

    from fn_trace_gettable('c:\temp\mytrace2.trc', 0)

    "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

  • thanks for that. Adding the BatchCompleted event is certainly an option and will work but we're only interested in RPC:Completed event.

    I see the Textdata just fine when I run the Trace using Profiler. Its only when I generate the trace definition SQL script from Profiler and then run that that I dont see the TextData field in the resulting trc file.

    Like I said before, i do, however, see the RPC:completed events when I query the trace file through fn_trace_gettable:

    select [TextData]

    from fn_trace_gettable('g:\mssql\trace\archive\Logger_GUI_investigation_XXXXXXX_20080201.trc',0)

    TextData

    ----------------------------------------------------------------------------------

    exec PostAvailableContractsCache_sp 'CONNECT\fuuser404','31 January 2008 09:35:26'

    exec PostAvailableContractsCache_sp 'CONNECT\fuuser304','31 January 2008 10:04:26'

    .

    .

    As I said its not an issue for us as we load the trace files into tables but it does expose a bug somewhere in the Profiler GUI code.

    cheers

    thanks

    SQL_EXPAT

  • I'm still not sure you found a bug. I use scripts to capture profiler traces all the time and the two events we capture are RPC complete and Batch complete. We can see the text field. The issue I found from your sample script was that it opened & closed, but there were no RPC events captured during that period and only the open & close statements were registered in the trace file. When you look at those events, mixed with the batch events, those events still don't show the textdata field.

    We have a fairly minimal trace that we run against production 24/7. It outputs to a file. I just opened it inside Profiler. I see RPC:Completed events with the TextData field, just fine. I also see the TraceStart event and no TextData field. I really think that's what you're seeing.

    "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

  • thanks for the reply.

    Please note that the last part of my script, to stop the Trace, should only be run once you have issued some RPC:Completed events that have been captured by the trace file 🙂

    I realise that if you run my script in its entirety in one go there will be no events captured for RPC:Completed.

    What you are saying is that you have to capture RPC complete and Batch complete events in order to view the TextData field for the RPC complete event? I know that this is not true as I use just the RPC:Completed event all the time in Profiler and I get TextData captured.

    We run this automated tracing 24x7 against 40 servers and load the trc files into tables. The textdata gets loaded into SQL and analysed no problem. Only if we open up one of these trc files in Profiler do we not see the Textdata field.

    Perhaps fn_trace_gettable derives the Textdata field from the BinaryData field.

    If I could I would attach one of these trc files to this post for you to see.

    appreciate the input.

    thanks

    SQL_EXPAT

  • Sorry I wasn't clear. We collect both BatchComplete & RPCComplete because, depending on the app, the calls are made in different ways and we want to see both (most are RPC though).

    What version of Profiler are you running? I've got 9.00.3042

    I've posted our script below. We use this all the time. It captures TextData in the output for RPC's. I'm wondering if it might be your filters?

    EXEC @error = sp_trace_create

    @trace_id = @TraceId output,

    @options = 2,

    @tracefile = @TraceFile,

    @maxfilesize = @MaxFileSize,

    @stoptime = @Stop_Time

    -- EVENT RPC:Completed

    EXEC sp_trace_setevent

    @trace_id = @TraceId,

    @Eventid = 10,

    @columnid = 27, -- EventClass

    @on = @Onbit

    EXEC sp_trace_setevent

    @trace_id = @TraceId,

    @Eventid = 10,

    @columnid = 1, -- TextData

    @on = @Onbit

    EXEC sp_trace_setevent

    @trace_id = @TraceId,

    @Eventid = 10,

    @columnid = 3, -- Database ID

    @on = @Onbit

    EXEC sp_trace_setevent

    @trace_id = @TraceId,

    @Eventid = 10,

    @columnid = 14, -- Start Time

    @on = @Onbit

    EXEC sp_trace_setevent

    @trace_id = @TraceId,

    @Eventid = 10,

    @columnid = 15, -- End Time

    @on = @Onbit

    EXEC sp_trace_setevent

    @trace_id = @TraceId,

    @Eventid = 10,

    @columnid = 13, -- Duration

    @on = @Onbit

    EXEC sp_trace_setevent

    @trace_id = @TraceId,

    @Eventid = 10,

    @columnid = 16, -- Reads

    @on = @Onbit

    EXEC sp_trace_setevent

    @trace_id = @TraceId,

    @Eventid = 10,

    @columnid = 17, -- Writes

    @on = @Onbit

    EXEC sp_trace_setevent

    @trace_id = @TraceId,

    @Eventid = 10,

    @columnid = 18, -- CPU

    @on = @Onbit

    EXEC sp_trace_setevent

    @trace_id = @TraceId,

    @Eventid = 10,

    @columnid = 10, -- Application Name

    @on = @Onbit

    EXEC sp_trace_setevent

    @trace_id = @TraceId,

    @Eventid = 10,

    @columnid = 6, -- NT User Name

    @on = @Onbit

    EXEC sp_trace_setevent

    @trace_id = @TraceId,

    @Eventid = 10,

    @columnid = 11, -- LoginName

    @on = @Onbit

    EXEC sp_trace_setevent

    @trace_id = @TraceId,

    @Eventid = 10,

    @columnid = 9, -- ClientProcessID

    @on = @Onbit

    EXEC sp_trace_setevent

    @trace_id = @TraceId,

    @Eventid = 10,

    @columnid = 12, -- SPID

    @on = @Onbit

    EXEC sp_trace_setfilter

    @trace_id = @TraceID,

    @columnid = 3,

    @logical_operator = 0, -- AND

    @comparison_operator = 1, -- <>

    @value = 1 -- master dbid

    --FILTER: Omit the msdb DB

    EXEC sp_trace_setfilter

    @trace_id = @TraceID,

    @columnid = 3,

    @logical_operator = 0, -- AND

    @comparison_operator = 1, -- <>

    @value = 4 -- msdb dbid

    END

    EXEC sp_trace_setfilter

    @trace_id = @TraceID,

    @columnid = 31, -- ERROR

    @logical_operator = 0, -- AND

    @comparison_operator = 1, -- NOT EQUAL

    @value = 208

    -- Start Trace

    EXEC @error= sp_trace_setstatus

    @trace_id = @TraceId,

    @status = 1

    "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

  • I've used your script to capture a trace file. When I open the trace file in Profiler I see loads of RPC:Completed events with all the fields displaying EXCEPT Textdata ! So, I can;t actually see what SQL was executed but I have over 700 rows. The properties box does not show the TextData field, checked or unchecked.

    When I run this I get the correct data:

    select top 1 TextData

    from fn_trace_gettable('c:\trace.trc',0)

    exec sp_executesql N'exec iuLastInfo_sp @P1, @P2, @P3, @P4'

    exec sp_executesql N'exec iuLastInfo_sp @P1, @P2, @P3, @P4'

    exec sp_executesql N'exec iuLastInfo_sp @P1, @P2, @P3, @P4'

    What am I doing wrong here. fn_trace_gettable sees it, Profiler doesn't. My Profiler is also on version 3042.

    I wonder what I'm doing wrong here.

    Have a great weekend!

    thanks

    SQL_EXPAT

  • I'm sorry. I really don't know at this point. We use this all the time and it works just fine.

    "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 12 posts - 1 through 11 (of 11 total)

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