Profiling in Oracle 8i

n a previous 10-Minute Solution, “New PL/SQL Features in Oracle 8i: Part I,” I write that Oracle PL/SQL programmers develop complex code nowadays, utilizing custom and Oracle-supplied packages. It therefore becomes critical to identify and solve performance problems. Oracle 8i’s Profiler does just that: it analyzes PL/SQL code and locates bottlenecks.

As you probably know, the first working version of your code is usually inefficient and slow. There is a way to measure its execution time on a line-by-line basis without using a profiler, but it’s tedious and slow. It involves calling the GET_TIME function (from the Oracle-supplied DBMS_UTILITY package) before and after selected lines of code. That’s primitive and inefficient because it requires adding multiple lines of temporary code and recompiling it. Plus you still don’t know how many times each line gets executed without adding even more code.

In this 10-Minute Solution I share my experience in profiling PL/SQL code using one of the GUI tools with profiling capabilities (Quest Software’s TOAD, for “Tool for Oracle Application Developers”) as well as by using the Oracle standard application development tool called SQL*Plus.



Because PL/SQL programming involves writing and using custom and Oracle-supplied packages, as well as standalone procedures and functions, performance tuning is an important task for Oracle developers. Checking code line by line is slow and inefficient because it requires adding multiple lines of temporary code and recompiling it.



Use the Oracle 8i Profiler to analyze PL/SQL code and locate bottlenecks. Improving PL/SQL code performance is an iterative process:

  1. Run the application code with profiler data collection enabled.
  2. Analyze the profiler data and identify performance problems.
  3. Fix the problems.
Using the DBMS_PROFILER Package
The Profiler API is implemented as a PL/SQL package, called DBMS_PROFILER. This package provides services for collecting statistics related to the execution of PL/SQL code and persistently storing it in three profiler tables (PLSQL_PROFILER_DATA, PLSQL_PROFILER_RUNS, and PLSQL_PROFILER_UNITS) in order to analyze the code and identify performance problems.

The DBMS_PROFILER package is not created by default by the database. It must be generated by the ProfLoad.sql script. This script is supplied with Oracle 8.1.6 and is located in the $ORACLE_HOME/Rdbms/Admin directory. (It’s not provided in version 8.1.5 but can be downloaded from technet.oracle.com. OTN registration is required.) This script has to be executed by a SYS or INTERNAL user, and access has to be granted to PUBLIC. This script calls two other scripts, Dbmspbp.sql and Prvtpbp.plb, located in the same directory.

A typical profiling session consists of the following steps:

  1. Start the profiler data collection.
  2. Execute the PL/SQL code.
  3. Stop the profiler data collection.
The Oracle 8i profiler gathers information at the PL/SQL virtual machine level, which includes the total number of times each line has been executed, the total amount of time that has been spent executing that line, and the minimum and maximum times that have been spent on a particular execution of that line.

Creating the Test Data and Stored Procedure
Listing 1 shows the necessary code for creating the table and stored procedure, which I use in this article’s examples. Let’s create the TestData table and TestProc stored procedure to use in our profiling sessions.

Profiling with TOAD
I’m using TOAD (Tool for Oracle Application Developers) version 6.5.0.0 from Quest Software, Inc., to profile this TestProc stored procedure. Oracle doesn’t have a graphic profiling tool of its own. You can download a free trial version of TOAD from the Quest Web site.

To use the profiler in TOAD:

  1. Start TOAD and select Database > PL/SQL Profiling to turn on the profiler, or click the Toggle PL/SQL Profiling button in the main TOAD toolbar. The icon for the button is a stopwatch.

  2. Execute the procedure TestProc from the Schema Browser or the Procedure Editor using the Execute (lightning bolt) button. You will be prompted to enter a value for the p_Count IN parameter (10000) and a description of the procedure being executed (“TOAD, TestProc Run 1 – 12/19/2000”). This will show up in the Profile Analysis window when you analyze the results. You could run the procedure several times to get some data into the profiling tables.

    Make sure you truncate the TestData table before each run by issuing the following SQL command:
    TRUNCATE TABLE TestData;
    Turn off profiling if you want at this point.

  3. Select Database > Profiler Analysis to bring up the Profiler Analysis window. There are three levels to the data. The top level represents the individual “Runs” of each procedure executed while profiling was enabled (see Figure 1).

  4. Double-click on one item to see the execution stats for that individual run. At this level, you can double-click to see the line-by-line performance times for individual procedures called during the profiling (see Figure 2).

    The Code column, where you are supposed to see actual PL/SQL code lines, was actually empty after the run completed. I had to create my own stored procedure, ProfilerLoadSource, and run it to fix this problem by populating the Code column with lines of source code. According to the Quest Software support, it works fine there; they could not reproduce the problem.

Figure 1. The TOAD Profiler Analysis Window: The TOAD profiler analysis window shows three runs of the original procedure. Line-by-line analysis of TestProc original version, run 3. As you can see, line 18 took 99.61% of the total time to execute (10,000 passes, 5,852 ms. total).

Figure 2. Line-by-line Analysis of TestProc: Line-by-line analysis of TestProc original version, run 3. As you can see, line 18 took 99.61% of the total time to execute (10,000 passes, 5,852 ms. total).

Let’s improve this code by utilizing the FORALL statement that Oracle 8i introduced to support bulk binds. (See my 10-Minute Solution, “New PL/SQL Features in Oracle 8i: Part II,” where I describe the advantages of the bulk binds feature.)

Replace the keyword FOR with FORALL and remove the LOOP and END LOOP statements, which are no longer needed because all 10,000 inserts will be passed to the SQL engine in one step. Listing 2 shows the improved version of TestProc.


Figure 3.
Improved version of TestProc: This figure shows the results of the next three runs. As you can see, the improved TestProc executes 10 to 12 times faster (average time 0.56 seconds) than the original one (average time 5.99 seconds).
Figure 4. Line-by-line Analysis of Improved TestProc: Line 16 was executed only once instead of 10,000 times and it took only 584 ms. instead of 5,852 ms., as line 18 did in the original TestProc line-by-line analysis.

Let’s use TOAD to profile an improved version of the TestProc stored procedure. Figure 3 shows the results of the next three runs. As you can see, the improved TestProc executes 10 to 12 times faster (average time 0.56 sec.) than the original one (average time 5.99 sec.).

As Figure 4 shows, line 16 in the improved TestProc was executed only once instead of 10,000 times and it took only 584 ms. instead of 5,852 ms., as line 18 did in the original TestProc.

Profiling with SQL*Plus
So far the runs have been made with TOAD. There are situations, however, where you’ll want to start a profiling process outside of TOAD in order to control the profiling session more?for instance, by profiling multiple procedures in batch mode, opening multiple SQL*Plus sessions and running profilings in parallel, etc. With TOAD you are limited to one instance of the program running and one procedure profiling at a time.

To profile outside of TOAD, you need to do TOAD’s work by yourself:

  1. Add a wrapper around the procedure call, utilizing the START_PROFILER and STOP_PROFILER procedures of the DBMS_PROFILER package.

  2. Insert additional code to calculate totals, load source code, and do the cleanup.
I created the stored procedures ProfilerUnitsTotals (Listing 3) and ProfilerLoadSource (Listing 4) to do the second item. You may consider creating your custom profiling package where you can put these procedures and add more utilities later.

After doing this, you can use TOAD’s nice graphic profiling interface, even though you will be running your procedure from SQL*Plus.

Start SQL*Plus, connect to the database as the same user connected via TOAD, and execute the PL/SQL anonymous block shown in Listing 5.

Figure 5. Line-by-line Analysis of SQL*Plus Runs: A line-by-line analysis of the improved TestProc, SQL*Plus runs 8-10.

Now you can look at the profiling data generated by SQL*Plus’ runs via the graphical TOAD interface.

From Figure 5 it’s clear that all six runs of the improved version of TestProc (TOAD runs 46 and SQL*Plus runs 810) are 1012 times faster than the original version (runs 13). This happened because we were able to locate the problem (line 18) using the Profiler and solve it, with a consequent significant performance gain.

As you can see, Oracle 8i Profiler is a powerful tool that allows Oracle database developers to collect execution time statistics, identify bottlenecks, and tune PL/SQL code efficiently.

Share the Post:
Share on facebook
Share on twitter
Share on linkedin

Overview

Recent Articles: