Profiling mode

When the driver runs in profiling mode, each phase in the SQL query processing that exceeds the profiling value is printed. The following three event types are timed and can appear in the log file:

  • The Parse event

    This represents the amount of time the RDBMS takes to parse an SQL statement.

  • The Execute event

    This represents the amount of time the RDBMS takes to execute an SQL statement.

  • The Fetch event

    This represents the amount of time it takes to retrieve data from the driver’s internal buffer cache or the RDBMS.

A sample MSQLPROF file: 

------ Profiling value exceeded -----
<nkumar><qptool>:2002-03-05[11:25:05.491]: 
Time (parse) : 0.010000 seconds
SQL statement:
SELECT a.t_byte,a.t_date,a.t_double,a.t_float,a.t_int,a.t_long,a.t_string FROM dbo.taabdb000001 a WITH ( INDEX=Itaabdb000001_1a)  WHERE (a.t_byte > ?)  OPTION (FAST 1)  
-------------------------------------
------ Profiling value exceeded -----
<nkumar><qptool>:2002-03-05[11:25:05.521]: 
Time (multi_exec) : 0.020000 seconds
SQL statement:
SELECT a.t_byte,a.t_date,a.t_double,a.t_float,a.t_int,a.t_long,a.t_string FROM dbo.taabdb000001 a WITH ( INDEX=Itaabdb000001_1a)  WHERE (a.t_byte > ?)  OPTION (FAST 1)  
-------------------------------------
------ Profiling value exceeded -----
<nkumar><qptool>:2002-03-05[11:25:05.521]: 
Time (multi_fetch) : 0.000000 seconds
SQL statement:
SELECT a.t_byte,a.t_date,a.t_double,a.t_float,a.t_int,a.t_long,a.t_string FROM dbo.taabdb000001 a WITH ( INDEX=Itaabdb000001_1a)  WHERE (a.t_byte > ?)  OPTION (FAST 1)  
-------------------------------------
------ Profiling value exceeded -----
<nkumar><qptool>:2002-03-05[11:25:05.611]: 
Time (multi_fetch) : 0.000000 seconds
SQL statement:
SELECT a.t_byte,a.t_date,a.t_double,a.t_float,a.t_int,a.t_long,a.t_string FROM dbo.taabdb000001 a WITH ( INDEX=Itaabdb000001_1a)  WHERE (a.t_byte > ?)  OPTION (FAST 1)  
-------------------------------------
------ Profiling value exceeded -----
<nkumar><qptool>:2002-03-05[11:25:05.691]: 
Time (multi_fetch) : 0.000000 seconds
SQL statement:
SELECT a.t_byte,a.t_date,a.t_double,a.t_float,a.t_int,a.t_long,a.t_string FROM dbo.taabdb000001 a WITH ( INDEX=Itaabdb000001_1a)  WHERE (a.t_byte > ?)  OPTION (FAST 1)  
--------------------------------------

The data in the above sample file can be interpreted as follows:

  • In this example, the number of seconds (profiling value) is 0.00. This means that all actions are logged to the file.
  • Once a statement is executed, the result set can be fetched many times (until the result set is exhausted or the cursor is closed).