DBMS_PROFILER

15.10.2005

The DBMS_PROFILER package allows to determine the time taken by each instruction of your code.
At the same time, you could also see the internal processing time for the basic instructions.

Of course, these times depend on the power of the test machine.

On 9i database, you have to run some scripts to install the DBMS_PROFILER package

Connect to SYS

connect / as sysdba

@<ORACLE_HOME>/rdbms/admin/proftab.sql
@<ORACLE_HOME>/rdbms/admin/profload.sql
@<ORACLE_HOME>/plsql/demo/profrep.sql

Then run the test with the following instructions:

SQL>
1 DECLARE
2    Pgm NUMBER;
3 BEGIN
4    DBMS_PROFILER.START_PROFILER('test','test1',Pgm);
5    FD.F_TRACE('Hello Oracle world','T');
6    DBMS_PROFILER.STOP_PROFILER;
7    DBMS_PROFILER.ROLLUP_RUN(Pgm);
8    PROF_REPORT_UTILITIES.PRINT_RUN(Pgm);
9* END;
SQL> /

On 10g database, it seems that there is nothing to install

This is a very simple procedure to test the DBMS_PROFILER package :

CREATE OR REPLACE PROCEDURE TEST_PROFILER
IS
TYPE TYP_TV1 IS TABLE OF VARCHAR2(50) INDEX BY BINARY_INTEGER ;
TYPE TYP_TV2 IS TABLE OF VARCHAR2(50) INDEX BY PLS_INTEGER ;
i1 PLS_INTEGER ;
n1 NUMBER ;
v1 VARCHAR2(2000) ;
t1 TYP_TV1 ;
t2 TYP_TV2 ;
d1 DATE ;
BEGIN

For i IN 1 .. 1000 Loop

     i1 := i ;
     n1 := i ;
     v1 := i ;
     v1 := To_char( i ) ;
     v1 := Ltrim( To_Char( i ) ) ;
     v1 := Replace( To_Char( i ), ' ', '' ) ;
     i1 := Instr( v1, '0' ) ;
     v1 := Substr( v1, 1, 1 ) ;
     t1(i) := i ;
     t2(i) := i ;
     n1 := Round( i * 1.37 ) ;
     n1 := Trunc( i * 1.37 ) ;
     n1 := Round( i * 1.37999999999999 ) ;
     n1 := Trunc( i * 1.37999999999999 ) ;
     d1 := SYSDATE + i ;

End Loop ;

END TEST_PROFILER ;
/

Run the test:

SQL> Begin
2
3    dbms_profiler.start_profiler ('start') ;
4    test_profiler ;
5    dbms_profiler.stop_profiler ;
6
7 End ;
8 /

PL/SQL procedure successfully completed.

Then show the result:

SQL> set linesize 500
SQL>
SQL> column unit_name format a15
SQL> column occured format 999999
SQL> column line# format 99999
SQL> column tot_time format 999.999999
SQL> set linesize 500
SQL>
SQL> select p.unit_name, p.occured, p.tot_time, p.line# line,
2         substr(s.text, 1,150) text
3    from
4         (select u.unit_name, d.TOTAL_OCCUR occured,
5                 (to_char(d.TOTAL_TIME/1000000000,'999.999999')) tot_time, d.line#
6            from plsql_profiler_units u, plsql_profiler_data d
7           where d.RUNID=u.runid and d.UNIT_NUMBER = u.unit_number
8             and d.TOTAL_OCCUR >0
9             and u.runid= (select max(runid) from plsql_profiler_units)) p,
10         user_source s
11   where p.unit_name = s.name(+) and p.line# = s.line (+)
12   order by p.unit_name, p.line#;

UNIT_NAME       OCCURED TOT_TIME          LINE TEXT
--------------- ------- ----------- ---------- ---------------------------------------------------
<anonymous>           2     .000084          4
<anonymous>           1     .000006          5
TEST_PROFILER         1     .000063          1 PROCEDURE TEST_PROFILER
TEST_PROFILER      1001     .000653         13   For i IN 1 .. 1000 Loop
TEST_PROFILER      1000     .001463         16   n1 := i ;
TEST_PROFILER      1000     .005228         17   v1 := i ;
TEST_PROFILER      1000     .005106         18   v1 := To_char( i ) ;
TEST_PROFILER      1000     .007010         19   v1 := Ltrim( To_Char( i ) ) ;
TEST_PROFILER      1000     .007110         20   v1 := Replace( To_Char( i ), ' ', '' ) ;
TEST_PROFILER      1000     .003209         21   i1 := Instr( v1, '0' ) ;
TEST_PROFILER      1000     .003021         22   v1 := Substr( v1, 1, 1 ) ;
TEST_PROFILER      1000     .006956         23   t1(i) := i ;
TEST_PROFILER      1000     .002220         24   t2(i) := i ;
TEST_PROFILER      1000     .006157         25   n1 := Round( i * 1.37 ) ;
TEST_PROFILER      1000     .002388         26   n1 := Trunc( i * 1.37 ) ;
TEST_PROFILER      1000     .002861         27   n1 := Round( i * 1.37999999999999 ) ;
TEST_PROFILER      1000     .001619         28   n1 := Trunc( i * 1.37999999999999 ) ;
TEST_PROFILER      1000     .011119         29   d1 := SYSDATE + i ;
TEST_PROFILER         1     .000065         33 END TEST_PROFILER ;

19 rows selected.

SQL>

As we can see, PLS_INTEGER type is 4/5 times faster than NUMBER
The NESTED TABLE INDEX BY PLS_INTEGER is 3 times faster than the INDEX BY BINARY_INTEGER
Operation on double-precision number is faster than operation on single-precision number

Francois