SQL Profiler

• GF

  Hall of Fame

  Points: 3774

  More actions

  September 7, 2004 at 10:44 am

  #86349

  Hi, I have been using SQL Profiler to help me solve a problem we are having. I am tracing stored procedure starting and completing. I want to know what the "--" at the begining of a "-- exec sp_stored_procedure" means. I know it is used as a comment in a query or stored procedure but if it is just a comment why is it showing up. The next line in the profiler displays the same stored procedure without the comment tag.

  Can someone shed some light on this?

  Thanks

  GF

• chrisleonard

  SSCertifiable

  Points: 5030

  More actions

  September 7, 2004 at 5:42 pm

  #522038

  GF,

  I assume you are looking at the TextData field, correct?  Is the word "exec" really there after the "--"?  When I run traces, the only time I see comments like that is when I am tracing statements starting and completing in the Profiler.  In other words, the events SP:StmtStarting and SP:StmtCompleted show the procedure name in a comment before the actual statement that is being traced inside the sp.

  For example, this TextData value means that the "select @single_lockedout..." statement was occuring inside the sp_MSdbuseraccess procedure:

  -- sp_MSdbuseraccess
  select @single_lockedout = DATABASEPROPERTY( @dbname, N'issingleuser' )

  Is that the kind of thing you're seeing?

  Cheers,

  Chris

• GF

  Hall of Fame

  Points: 3774

  More actions

  September 8, 2004 at 9:58 am

  #522146

  Chris, you are correct, I was mistaken. There is no "exec" after the "--".

  Here is a classic example of what I am getting in my trace:

  -- sp_sqlagent_get_perf_counters

  SET NOCOUNT ON

  -- sp_sqlagent_get_perf_counters

  CREATE TABLE #temp

    (

    performance_condition NVARCHAR(1024) COLLATE database_default NOT NULL

    )

  -- sp_sqlagent_get_perf_counters

  INSERT INTO #temp VALUES (N'dummy')-- sp_sqlagent_get_perf_counters

  IF (@all_counters = 0)

   -- sp_sqlagent_get_perf_counters

  INSERT INTO #temp

      SELECT DISTINCT SUBSTRING(performance_condition, 1, CHARINDEX('|', performance_condition, PATINDEX('%_|_%', performance_condition) + 2) - 1)

      FROM msdb.dbo.sysalerts

      WHERE (performance_condition IS NOT NULL)

        AND (enabled = 1)

  -- sp_sqlagent_get_perf_counters

  SELECT 'object_name' = RTRIM(SUBSTRING(spi1.object_name, 1, 50)),

           'counter_name' = RTRIM(SUBSTRING(spi1.counter_name, 1, 50)),

           'instance_name' = CASE spi1.instance_name

                               WHEN N'' THEN NULL

                               ELSE RTRIM(spi1.instance_name)

                             END,

           'value' = CASE spi1.cntr_type

                       WHEN 537003008 -- A ratio

                         THEN CONVERT(FLOAT, spi1.cntr_value) / (SELECT CASE spi2.cntr_value WHEN 0 THEN 1 ELSE spi2.cntr_value END

                                                                 FROM master.dbo.sysperfinfo spi2

                                                                 WHERE (spi1.counter_name + ' ' = SUBSTRING(spi2.counter_name, 1, PATINDEX('% Base%', spi2.counter_name)))

                                                                   AND (spi1.instance_name = spi2.instance_name)

                                                                   AND (spi2.cntr_type = 1073939459))

                       ELSE spi1.cntr_value

                     END

    FROM master.dbo.sysperfinfo spi1,

         #temp tmp

    WHERE (spi1.cntr_type <> 1073939459) -- Divisors

      AND ((@all_counters = 1) OR

           (tmp.performance_condition = RTRIM(spi1.object_name) + '|' + RTRIM(spi1.counter_name)))

  After the above I get this

  EXECUTE msdb.dbo.sp_sqlagent_get_perf_counters

  So if I follow what you are saying, all the -- stuff is what is happening in the Execute section. Correct?

  It stands to reason then that the only rows with a duration entry are the rows where there is an exec.

  Thanks

  Gary

• chrisleonard

  SSCertifiable

  Points: 5030

  More actions

  September 8, 2004 at 11:43 am

  #522173

  OK, that's what I thought.  I assume you know that stored procedures are made up of individual Transact-SQL statements.  What you are seeing is one trace record for each individual T-SQL statement contained within sp_sqlagent_get_perf_counters, and then another trace record for the entire stored procedure.  If you look at the EventClass you should see this.  Suppose, for example, that you have a simple stored procedure like this:

  create procedure hello2x
  as
     print 'This is the first hello.'
     print 'This is the second hello.'

  Then suppose you run a SQL Profiler trace and turn on the following events:  SP:Starting, SP:StmtStarting, SP:StmtCompleted, and SP:Completed.  Then, in your trace, you would see something like this:

  EventClass: SP:Starting 
  TextData:
  hello2x

  EventClass: SP:StmtStarting 
  TextData:
  -- hello2x
  print 'This is the first hello.'

  EventClass: SP:StmtCompleted 
  TextData:
  -- hello2x
  print 'This is the first hello.'

  EventClass: SP:StmtStarting 
  TextData:
  -- hello2x
  print 'This is the second hello.'

  EventClass: SP:StmtCompleted 
  TextData:
  -- hello2x
  print 'This is the second hello.'

  EventClass: SP:Completed 
  TextData:
  hello2x

  You can see that the entries that contain the -- stored procedure name text are the ones relating to statements rather than entire procedures.  The reason the comment is in there is to give you a quick visual way to identify which procedure the statement is part of.  It is inserted by the profiler as an informational comment, and it is not part of the text that was optimized / compiled / executed by SQL Server.

  Hope this clears it up for you!  Let me know if not.

  Cheers,

  Chris

• GF

  Hall of Fame

  Points: 3774

  More actions

  September 8, 2004 at 11:54 am

  #522178

  Chris, yes, that clears up my question. Thanks for your time and informaiton.

  Gary