Adding Performance Counter Code Into Your MSSQL Stored Procedure

Collecting information about performance data can be done in many ways. although one of the methods I often use is simply put the code in the body and let that code extract the numbers for me.

The code shown below contain the necessary statements needed to extract a number of seconds it take to run the procedure from line 06 to line 08. In the next paragraph, these lines of code will be explained in detail.

01  CREATE PROCEDURE sp_sample_stored_proc_01 AS
02  BEGIN
03	declare @start_time float
04	declare @end_time float
05	declare @elapsed_time float
06	select @start_time = @@CPU_BUSY * cast(@@TIMETICKS as float)
07      -- your normal routine code goes here.
08	set @end_time = @@CPU_BUSY * cast(@@TIMETICKS as float)
09	set @elapsed_time =  (@end_time - @start_time) / 1000000
10  END

Lines 01, 02, 10

The syntax for defining a stored procedure is shown in lines 01, 02 and 10. In this example, the name of the procedure get declared as sp_sample_stored_proc_01, having no parameter definition. While lines 02 and 10 define the body of the procedure.

01  CREATE PROCEDURE sp_sample_stored_proc_01 AS
02  BEGIN
     o  o  o
10  END

Lines 03, 04, 05

@start_time, @end_time and @elapsed_time are names or labels used to store values needed to calculate the elapsed time. And they are declared using the following syntax:

03	declare @start_time float
04	declare @end_time float
05	declare @elapsed_time float

Lines 06, 08, 09

When execution reaches line 06, it takes a snapshot of two system values contained in two system variables named: @@CPU_BUSY and @@TIMETICKS. An expression is evaluated before storing the result in @start_time

06	select @start_time = @@CPU_BUSY * cast(@@TIMETICKS as float)

The execution path goes on until it reaches line 08, which then takes another snapshot of two system values; calculates the expression and stores the result in @end_time.

08	set @end_time = @@CPU_BUSY * cast(@@TIMETICKS as float)

At this point, the procedure is almost finished and will jump out of its execution frame. But before jumping out, it calculates the expression defined in line 09.

09	set @elapsed_time =  (@end_time - @start_time) / 1000000

@elapsed_time contains a value of how much time it took to run the lines of code from line 06 to 08.

Recommendation

You can extend the code so that it saves @elapsed_time to a logfile.