dcsimg
Database Journal
MS SQL Oracle DB2 Access MySQL PostgreSQL Sybase PHP SQL Etc SQL Scripts & Samples Tips Database Forum

» Database Journal Home
» Database Articles
» Database Tutorials
MS SQL
Oracle
DB2
MS Access
MySQL
» RESOURCES
SQL Scripts & Samples
Tips
» Database Forum
» Slideshows
» Sitemap
Free Newsletters:
DatabaseDaily  

By submitting your information, you agree that databasejournal.com may send you databasejournal offers via email, phone and text message, as well as email offers about other products and services that databasejournal believes may be of interest to you. databasejournal will process your information in accordance with the Quinstreet Privacy Policy.

News Via RSS Feed


Database Journal |DBA Support |SQLCourse |SQLCourse2
 

Featured Database Articles

Oracle

Posted February 12, 2018

WEBINAR:
On-Demand

Building the Right Environment to Support AI, Machine Learning and Deep Learning


Using Oracle's DBMS_PROFILER to tune PL/SQL

By David Fitzjarrell

Performance is high on the list of IT requirements, especially with queries, functions and stored procedures. Queries have been easy to work with because the execution plan gives all of the details one could need to find trouble spots. When it's PL/SQL, that's been a more difficult apple to peel since extracting statements from a procedure or function changes the execution context and, thus, the plan. Oracle provides a very useful utility, the PL/SQL profiler, to aid in finding poorly performing areas of PL/SQL code so they can be addressed. Let's look at how to configure and use that utility to find problem areas.

Configuring the profiler is fairly easy; in the schema that owns the PL/SQL objects the proftab.sql script (located at $ORACLE_HOME/rdbms/admin) must be run to create the tables that the profiler needs to store run data; those tables are:


PLSQL_PROFILER_UNITS
PLSQL_PROFILER_RUNS
PLSQL_PROFILER_DATA

These three tables are the backbone of the profiler as views are created from them so that reports can be run. Once those tables are created, running the profiler is a simple matter of starting it with a 'tag', running the suspect PL/SQL and then stopping it. One 'warning' is that the profiler cannot profile code owned by another user unless it's run when connected as 'sys as sysdba', so it's important that the account that owns the object to be profiled is used to generate the profiler data. [The account used in these examples is BING, and all of the tables and views necessary for the profiler to do its work are created in that schema.]

An example of how to use the profiler once the setup has been successfully completed follows:


set linesize 1000 trimspool on

select dbms_profiler.start_profiler('DATES PACKAGE') from dual;

select dates_pkg.minutes_elapsed(sysdate-10, sysdate) from dual;

select dbms_profiler.stop_profiler from dual;

spool dates_package_profiler_run.rpt
@?/rdbms/admin/profsum
spool off

The first select starts the profiler running; the next select is running the 'problem' function to be traced, and the final select turns off profiling. The portion of the script from the 'spool ...' line to the 'spool off' line generates the report for the run, and that report contains a wealth of performance data. The report generated from the script shown above is reproduced below:




View created.


View created.


View created.


View created.


Package created.

No errors.

Package body created.

No errors.

3 rows updated.


PL/SQL procedure successfully completed.


GRAND_TOTA
----------
       .00


     RUNID RUN_COMMENT                                                                                                                 SECONDS
---------- ------------------------------------------------------------------------------------------------------------------------ ----------
         1 DATES PACKAGE                                                                                                                  .015


     RUNID RUN_COMMENT                                                                      UNIT_OWNER                       UNIT_NAME                     SECONDS   PERCEN
---------- -------------------------------------------------------------------------------- -------------------------------- ----------------------------- --------- ------
         1 DATES PACKAGE                                                                    BING                             DATES_PKG                     .00       8.9


UNIT_OWNER                       UNIT_NAME                                                                                            SECONDS   PERCENTAG
-------------------------------- ---------------------------------------------------------------------------------------------------- --------- ---------
BING                             DATES_PKG                                                                                                  .00     90.85
                                                                                                                      .00      9.15

    to_char(p1.total_time/(p1.total_occur*p1.min_time),'99999.99')as "Ave/min",
                         *
ERROR at line 10:
ORA-01476: divisor is equal to zero



     RUNID SECONDS  OWNER                                                                            UNIT_NAME                                              LINE#
---------- -------- -------------------------------------------------------------------------------- ------------------------------------------------------ ----------
TEXT
----------------------------------------------------------------------------------------------------------------------------------------------------------- 
         1       .0 BING                                                                             DATES_PKG                                              147
        SELECT minutes_since_midnight (lowdate)

         1       .0 BING                                                                             DATES_PKG                                               57
        SELECT TO_NUMBER

         1       .0 BING                                                                             DATES_PKG                                               19
        SELECT TO_CHAR


     RUNID SECONDS  OWNER                                                                            UNIT_NAME                                               LINE#
---------- -------- -------------------------------------------------------------------------------- ------------------------------------------------------- ----------
TEXT
-------------------------------------------------------------------------------------------------------------------------------------------------------------
         1       .0 BING                                                                             DATES_PKG                                               70
        SELECT (secs_elapsed / 60)

         1       .0 BING                                                                             DATES_PKG                                              108
        SELECT julian_date (lowdate)

         1       .0 BING                                                                             DATES_PKG                                               30
        SELECT TO_NUMBER (varch_value)


     RUNID SECONDS  OWNER                                                                            UNIT_NAME                                               LINE#
---------- -------- -------------------------------------------------------------------------------- ----------------------------------------------------------------
TEXT
-------------------------------------------------------------------------------------------------------------------------------------------------------------
         1       .0 BING                                                                             DATES_PKG                                               151
        SELECT minutes_since_midnight (highdate)

         1       .0 BING                                                                             DATES_PKG                                               125
        SELECT (high_julian - low_julian)

         1       .0 BING                                                                             DATES_PKG                                               136
        SELECT (num_days * 1440)


     RUNID SECONDS  OWNER                                                                            UNIT_NAME                                               LINE#
---------- -------- -------------------------------------------------------------------------------- ------------------------------------------------------- ----------
TEXT
-------------------------------------------------------------------------------------------------------------------------------------------------------------
         1       .0 BING                                                                             DATES_PKG                                               112
        SELECT julian_date (highdate)

         1       .0 BING                                                                             DATES_PKG                                               169
        SELECT (num_minutes + temp_mins)

         1       .0 BING                                                                             DATES_PKG                                               161
        SELECT (min_high - min_low)


12 rows selected.


SECONDS  UNIT_OWNER                                                                       UNIT_NAME                                                          LINE#
-------- -------------------------------------------------------------------------------- ------------------------------------------------------------------ ----------
TEXT
------------------------------------------------------------------------------------------------------------------------------------------------------------
      .0 BING                                                                             DATES_PKG                                                          147
        SELECT minutes_since_midnight (lowdate)

      .0 BING                                                                             DATES_PKG                                                           57
        SELECT TO_NUMBER

      .0 BING                                                                             DATES_PKG                                                           19
        SELECT TO_CHAR


SECONDS  UNIT_OWNER                                                                       UNIT_NAME                                                         LINE#
-------- -------------------------------------------------------------------------------- ----------------------------------------------------------------- ----------
TEXT
-----------------------------------------------------------------------------------------------------------------------------------------------------------
      .0 BING                                                                             DATES_PKG                                                          70
        SELECT (secs_elapsed / 60)

      .0 BING                                                                             DATES_PKG                                                         108
        SELECT julian_date (lowdate)

      .0 BING                                                                             DATES_PKG                                                          30
        SELECT TO_NUMBER (varch_value)


SECONDS  UNIT_OWNER                                                                       UNIT_NAME                                                         LINE#
-------- -------------------------------------------------------------------------------- ----------------------------------------------------------------- ----------
TEXT
------------------------------------------------------------------------------------------------------------------------------------------------------------
      .0 BING                                                                             DATES_PKG                                                         151
        SELECT minutes_since_midnight (highdate)

      .0 BING                                                                             DATES_PKG                                                         125
        SELECT (high_julian - low_julian)

      .0 BING                                                                             DATES_PKG                                                         136
        SELECT (num_days * 1440)


SECONDS  UNIT_OWNER                                                                       UNIT_NAME                                                         LINE#
-------- -------------------------------------------------------------------------------- ----------------------------------------------------------------- ----------
TEXT
------------------------------------------------------------------------------------------------------------------------------------------------------------
      .0 BING                                                                             DATES_PKG                                                         112
        SELECT julian_date (highdate)

      .0 BING                                                                             DATES_PKG                                                         169
        SELECT (num_minutes + temp_mins)

      .0 BING                                                                             DATES_PKG                                                         161
        SELECT (min_high - min_low)


12 rows selected.


PL/SQL procedure successfully completed.


UNIT_OWNER                       UNIT_NAME                        LINES_EXECUTED
-------------------------------- -------------------------------- --------------
BING                             DATES_PKG                                    18


UNIT_OWNER                       UNIT_NAME                        LINES_PRESENT
-------------------------------- -------------------------------- -------------
BING                             DATES_PKG                                   21


LINES_EXECUTED
--------------
            18


LINES_PRESENT
-------------
           21

The first section of the report shows what was executed and how long each call took to run; it's a generalized report that doesn't provide a lot of detail, but it does pave the way for the tuning investigation as long run times will be reported here first. The next section goes into detail about what was executed and the time each executed statement consumed; it provides the PL/SQL code of 'relevant', sections so they can be evaluated and, possibly, investigated:


=================================trace info=================================
===========================Results for run #1 made on 09-FEB-18 09:43:32 =========================
(DATES PACKAGE) Run total time:       .02 seconds
Unit #1: . - Total time:       .00 seconds
Unit #2: BING.DATES_PKG - Total time:       .00 seconds
9                                                    BEGIN
10                                                	--
11                                                	-- First, we take a date and convert it to a date by converting it
12                                                	-- to a character string using the same format we will use to
13                                                	-- convert it BACK to a date again
14                                                	--
15                                                	-- Oh, then we convert it back to a character string
16                                                	--
17                                                	-- In Julian format, which is a number
18                                                	--
19           2   .00012803  .00006401                     SELECT TO_CHAR
20                                                               ( TO_DATE(TO_CHAR(date_to_convert,'MM/DD/YYYY'),'MM/DD/YYYY')
21                                                               , 'J')
22                                                        INTO   varch_value
23                                                        FROM   dual;
24
25                                                	--
26                                                	-- Okay, so we had a Julian date as a number but we changed it to
27                                                	-- a character string so we could go back and make it a ...
28                                                	-- NUMBER ... again
29                                                	--
30           2   .00008374  .00004187                     SELECT TO_NUMBER (varch_value)
31                                                        INTO   num_value
32                                                        FROM   dual;
33
34                                                	--
35                                                	-- So, we finally make up our mind and keep it a number and
36                                                	-- return it from the function
37                                                	--
38           2   0  0                                     RETURN (num_value);
39           2   .00000402  .00000201                 END julian_date;
40
41
42           0   .00000322                            FUNCTION minutes_since_midnight (
43                                                        timevalue DATE)
44                                                        RETURN NUMBER
45                                                    IS
46                                                        secs_elapsed NUMBER (20);
47                                                        mins_elapsed NUMBER (20);
48                                                    BEGIN
49                                                	--
50                                                	-- So now we take a date and extract the time portion of it,
51                                                	-- convert that BACK to a date, then convert THAT to a string
52                                                	-- of seconds and convert THAT to a number
53                                                	--
54                                                	-- Is it me, or are we essentially driving across town just to
55                                                	-- go next door?
56                                                	--
57           2   .00026250  .00013125                     SELECT TO_NUMBER
58                                                               ( TO_CHAR(TO_DATE(TO_CHAR(timevalue,'HH:MI AM'),'HH:MI AM')
59                                                               , 'SSSSS') )
60                                                        INTO   secs_elapsed
61                                                        FROM   dual;
62
63                                                	--
64                                                	-- Oooo, now we divide that total number of seconds by ...
65                                                	-- wait for it ...
66                                                	-- any second now ...
67                                                	-- 60!  Who would have thought that 60 seconds equals
68                                                	-- one minute?
69                                                	--
70           2   .00011595  .00005797                     SELECT (secs_elapsed / 60)
71                                                        INTO   mins_elapsed
72                                                        FROM   dual;
73
74                                                	--
75                                                	-- Before we rest on our laurels we return the minutes since midnight
76                                                	--
77           2   .00000080  .00000040                     RETURN (mins_elapsed);
78           2   .00000402  .00000201                 END minutes_since_midnight;
79
80
81           0   .00000241                            FUNCTION minutes_elapsed
82                                                        ( lowdate DATE
83                                                        , highdate DATE )
84                                                        RETURN NUMBER
85                                                    IS
86                                                        final_number NUMBER (20);
87                                                        low_julian NUMBER (20);
88                                                        high_julian NUMBER (20);
.
.
.
98                                                	--
99                                                	-- Oh, yeah, because we just WROTE that wonderful function
100                                                	--
101                                                	-- So, okay, we take our date values and return the Julian
102                                                	-- representations of them using all of the mathematical
103                                                	-- aerobics from earlier
104                                                	--
105                                                	-- I guess this is so much easier than simply subtracting
106                                                	-- them
107                                                	--
108           1   .00011353  .00011353                     SELECT julian_date (lowdate)
109                                                        INTO   low_julian
110                                                        FROM   dual;
111
112           1   .00004750  .00004750                     SELECT julian_date (highdate)
113                                                        INTO   high_julian
114                                                        FROM   dual;
115
116                                                	--
117                                                	-- Woo-hoo! Higher math time!  Subtract the Julian dates
118                                                	-- and get the number of days
119                                                	--
120                                                	-- Isn't that what we'd get if we just subtracted the
121                                                	-- submitted dates as-is?
122                                                	--
123                                                	-- Of course it is
124                                                	--
125           1   .00006844  .00006844                     SELECT (high_julian - low_julian)
126                                                        INTO   num_days
127                                                        FROM   dual;
128
129                                                	--
130                                                	-- Now we calculate the total minutes elapsed
131                                                	-- using our values generated by our extreme
132                                                	-- gyrations
133                                                	--
134                                                	-- I'm out of breath just thinking about all of this work
135                                                	--
136           1   .00006280  .00006280                     SELECT (num_days * 1440)
137                                                        INTO   num_minutes
138                                                        FROM   dual;
139
140                                                	--
141                                                	-- And now we put those other mathematical moves
142                                                	-- to use
143                                                	--
144                                                	-- Tell me again why we think we're smarter than
145                                                	-- the average bear?
146                                                	--
147           1   .00029230  .00029230                     SELECT minutes_since_midnight (lowdate)
148                                                        INTO   min_low
149                                                        FROM   dual;
150
151           1   .00007408  .00007408                     SELECT minutes_since_midnight (highdate)
152                                                        INTO   min_high
153                                                        FROM   dual;
154
155                                                	--
156                                                	-- Now this is disgusting
157                                                	--
158                                                	-- Using a TEMP variable to aid in simple mathematical
159                                                	-- processing
160                                                	--
161           1   .00002576  .00002576                     SELECT (min_high - min_low)
162                                                        INTO   temp_mins
163                                                        FROM   dual;
164
165                                                	--
166                                                	-- And this is better than:
167                                                	-- select (end_date - start_date)*1440 because?
168                                                	--
169           1   .00004428  .00004428                     SELECT (num_minutes + temp_mins)
170                                                        INTO   final_number
171                                                        FROM   dual;
172
173           1   0  0                                     RETURN (final_number);
174
175           1   0  0                                 END minutes_elapsed;
176                                                END dates_pkg
Unit #3: . - Total time:       .00 seconds
============================================================================

PL/SQL procedure successfully completed.

================== Profiler report - all runs rolled up ===================
Unit .:
Unit BING.DATES_PKG:
9                                                    BEGIN
10                                                	--
11                                                	-- First, we take a date and convert it to a date by converting it
12                                                	-- to a character string using the same format we will use to
13                                                	-- convert it BACK to a date again
14                                                	--
15                                                	-- Oh, then we convert it back to a character string
16                                                	--
17                                                	-- In Julian format, which is a number
18                                                	--
19           2   .00012803  .00006401                     SELECT TO_CHAR
20                                                               ( TO_DATE(TO_CHAR(date_to_convert,'MM/DD/YYYY'),'MM/DD/YYYY')
21                                                               , 'J')
22                                                        INTO   varch_value
23                                                        FROM   dual;
24
25                                                	--
26                                                	-- Okay, so we had a Julian date as a number but we changed it to
27                                                	-- a character string so we could go back and make it a ...
28                                                	-- NUMBER ... again
29                                                	--
30           2   .00008374  .00004187                     SELECT TO_NUMBER (varch_value)
31                                                        INTO   num_value
32                                                        FROM   dual;
33
34                                                	--
35                                                	-- So, we finally make up our mind and keep it a number and
36                                                	-- return it from the function
37                                                	--
38           2   0  0                                     RETURN (num_value);
39           2   .00000402  .00000201                 END julian_date;
40
41
42           0   .00000322                            FUNCTION minutes_since_midnight (
43                                                        timevalue DATE)
44                                                        RETURN NUMBER
45                                                    IS
46                                                        secs_elapsed NUMBER (20);
47                                                        mins_elapsed NUMBER (20);
48                                                    BEGIN
49                                                	--
50                                                	-- So now we take a date and extract the time portion of it,
51                                                	-- convert that BACK to a date, then convert THAT to a string
52                                                	-- of seconds and convert THAT to a number
53                                                	--
54                                                	-- Is it me, or are we essentially driving across town just to
55                                                	-- go next door?
56                                                	--
57           2   .00026250  .00013125                     SELECT TO_NUMBER
58                                                               ( TO_CHAR(TO_DATE(TO_CHAR(timevalue,'HH:MI AM'),'HH:MI AM')
59                                                               , 'SSSSS') )
60                                                        INTO   secs_elapsed
61                                                        FROM   dual;
62
63                                                	--
64                                                	-- Oooo, now we divide that total number of seconds by ...
65                                                	-- wait for it ...
66                                                	-- any second now ...
67                                                	-- 60!  Who would have thought that 60 seconds equals
68                                                	-- one minute?
69                                                	--
70           2   .00011595  .00005797                     SELECT (secs_elapsed / 60)
71                                                        INTO   mins_elapsed
72                                                        FROM   dual;
73
74                                                	--
75                                                	-- Before we rest on our laurels we return the minutes since midnight
76                                                	--
77           2   .00000080  .00000040                     RETURN (mins_elapsed);
78           2   .00000402  .00000201                 END minutes_since_midnight;
79
80
81           0   .00000241                            FUNCTION minutes_elapsed
82                                                        ( lowdate DATE
83                                                        , highdate DATE )
84                                                        RETURN NUMBER
85                                                    IS
86                                                        final_number NUMBER (20);
87                                                        low_julian NUMBER (20);
88                                                        high_julian NUMBER (20);
.
.
.
98                                                	--
99                                                	-- Oh, yeah, because we just WROTE that wonderful function
100                                                	--
101                                                	-- So, okay, we take our date values and return the Julian
102                                                	-- representations of them using all of the mathematical
103                                                	-- aerobics from earlier
104                                                	--
105                                                	-- I guess this is so much easier than simply subtracting
106                                                	-- them
107                                                	--
108           1   .00011353  .00011353                     SELECT julian_date (lowdate)
109                                                        INTO   low_julian
110                                                        FROM   dual;
111
112           1   .00004750  .00004750                     SELECT julian_date (highdate)
113                                                        INTO   high_julian
114                                                        FROM   dual;
115
116                                                	--
117                                                	-- Woo-hoo! Higher math time!  Subtract the Julian dates
118                                                	-- and get the number of days
119                                                	--
120                                                	-- Isn't that what we'd get if we just subtracted the
121                                                	-- submitted dates as-is?
122                                                	--
123                                                	-- Of course it is
124                                                	--
125           1   .00006844  .00006844                     SELECT (high_julian - low_julian)
126                                                        INTO   num_days
127                                                        FROM   dual;
128
129                                                	--
130                                                	-- Now we calculate the total minutes elapsed
131                                                	-- using our values generated by our extreme
132                                                	-- gyrations
133                                                	--
134                                                	-- I'm out of breath just thinking about all of this work
135                                                	--
136           1   .00006280  .00006280                     SELECT (num_days * 1440)
137                                                        INTO   num_minutes
138                                                        FROM   dual;
139
140                                                	--
141                                                	-- And now we put those other mathematical moves
142                                                	-- to use
143                                                	--
144                                                	-- Tell me again why we think we're smarter than
145                                                	-- the average bear?
146                                                	--
147           1   .00029230  .00029230                     SELECT minutes_since_midnight (lowdate)
148                                                        INTO   min_low
149                                                        FROM   dual;
150
151           1   .00007408  .00007408                     SELECT minutes_since_midnight (highdate)
152                                                        INTO   min_high
153                                                        FROM   dual;
154
155                                                	--
156                                                	-- Now this is disgusting
157                                                	--
158                                                	-- Using a TEMP variable to aid in simple mathematical
159                                                	-- processing
160                                                	--
161           1   .00002576  .00002576                     SELECT (min_high - min_low)
162                                                        INTO   temp_mins
163                                                        FROM   dual;
164
165                                                	--
166                                                	-- And this is better than:
167                                                	-- select (end_date - start_date)*1440 because?
168                                                	--
169           1   .00004428  .00004428                     SELECT (num_minutes + temp_mins)
170                                                        INTO   final_number
171                                                        FROM   dual;
172
173           1   0  0                                     RETURN (final_number);
174
175           1   0  0                                 END minutes_elapsed;
176                                                END dates_pkg
============================================================================

PL/SQL procedure successfully completed.

Each 'unit' executed has its own section. These sections start with the line number of the the executed section, and include the number of executions of the code, the total time for all of the executions and the per-execution time. It's the total time of execution that is reported in the first section of the report; the single execution time is what should be considered when evaluating the code for tuning, as decreasing that value decreases the total execution time. In this example there really aren't any big 'offenders', but some of the code does run a bit longer than the native conversions provided by Oracle. [This example was posted online several years ago as an attempt to provide a different way of calculating date differences. When tested against the native functions these took much longer to complete and consumed more resources. So, the small times reported by the profiler are actually much larger than the times the native functions take to execute.]

With reports like this tuning PL/SQL packages, procedures and functions becomes much easier, as problem sections are easily spotted by the (possibly) exceptionally long overall execution times. It's then a simple task of extracting the code, and performing the usual tuning steps such as check an execution plan, check table statistics, check for indexes, etc. Even though the execution plan might be slightly different when run within a PL/SQL context the 'garden variety' execution plan can be very helpful in spotting parts of the code that aren't optimal.

Performance tuning requires information, and when there are tools designed to provide such information it's wise to use them. Oracle provides the PL/SQL Profiler to analyze running PL/SQL objects and code, so they can be written to run better and faster, and use fewer resources. And making code run better, faster and use fewer resources is part of a DBA's job.

Use the PL/SQL profiler; it will make performance tuning easier.

See all articles by David Fitzjarrell



Oracle Archives

Comment and Contribute

 


(Maximum characters: 1200). You have characters left.

 

 




Latest Forum Threads
Oracle Forum
Topic By Replies Updated
Oracle Data Mining: Classification jan.hasller 0 July 5th, 07:19 AM
Find duplicates - Unique IDs Lava 5 July 2nd, 08:30 AM
no matching unique or primary key rcanter 1 April 25th, 12:32 PM
Update values of one table based on condition of values in other table using Trigger Gladiator 3 February 29th, 06:01 PM