PERFORMANCE TUNING

Guy Harrison
Winter 1996

Getting the Most from the SQL_TRACE Facility

How to use the powerful SQL_TRACE facility to trace SQL calls generated by an Oracle application and analyze the execution plans and database resource usage.

Although tuning the operating system or Oracle configuration can yield significant performance improvements, nothing can substitute for rigorous tuning of application SQL. The SQL_TRACE facility is a powerful but under-used facility for tracing the SQL calls generated by an Oracle application and analyzing the execution plans and database resource usage. The ALTER SESSION SET SQL_TRACE TRUE statement lets you initiate SQL tracing, and the tkprof command enables you to format the trace files in a meaningful way.

The SQL_TRACE facility and the tkprof formatter are some of the most powerful tools for tuning SQL. Sadly, most Oracle developers don't make use of these important tools. Why? Because the SQL_ TRACE/tkprof duo are somewhat obscure in their usage and application, and because the interpretation of the formatted trace files is poorly documented.

I hope to encourage you to use both SQL_TRACE and tkprof by outlining a means of initiating and interpreting trace output. In this article, I also discuss how to overcome the bugs and limitations inherent in the SQL_TRACE facility, and I reveal some undocumented methods for generating enhanced trace output.

When using SQL_TRACE and tkprof, the usual tuning cycle is:

• Enable SQL_TRACE for the instance or sessions in question
• Locate the trace files(s) of interest
• Use tkprof to generate trace output
• Interpret the formatted trace file
• Tune SQL and repeat

Preparing to use SQL_TRACE

Before you start using SQL_TRACE and tkprof, you should:

• Use realistic test data. To some extent, the data generated by SQL_TRACE and tkprof will only be as good as the data against which you run your SQL. This is particularly true if you are using cost-based optimization, because the execution plan generated by Oracle will change depending on the distribution of data. So try to ensure that you are using data that is as close as possible to your target environment and that the your table statistics are up to date. You can use the ANALYZE TABLE command to collect table statistics.
• Set initialization parameters. Some parameters you need to consider are:
  • TIMED_STATISTICS. On most platforms, unless TIMED_STATISTICS is set to true, your trace files will not contain elapsed or CPU timings for your SQL. Setting TIMED_STATISTICS to TRUE usually results in only a slight system overhead - I recommend that it be set to true always.
  • USER_DUMP_DEST. This specifies the location where trace files will be generated.
  • MAX_DUMP_FILE_SIZE. This specifies the maximum size (in operating system blocks) for the trace file. You may wish to increase this value if you are going to generate very large traces. But be careful not to run out of space in your target destination.
  • OPTIMIZER_MODE. This parameter defines the default operation of the query optimizer. valid values are RULE, CHOOSE, FIRST ROWS, and ALL ROWS. The execution plan for your query may change dramatically depending on the value of this parameter. Although you can change the optimizer mode from within your session using the ALTER SESSION SET OPTIMIZER_GOAL command, the optimizer mode will revert to the INIT.ORA setting when you format your trace file. If your OPTIMIZER_GOAL is different from the OPTIMIZER_MODE, your trace file may contain inaccurate explain plans. Therefore, it is best to set the optimizer approach through the init.ora parameter and not through the ALTER SESSION command.
• Make sure that you are connecting to the database using a "dedicated" server connection. If you are using multi-threaded servers, your trace output may be fragmented among the trace output from multiple server processes. Establishing a dedicated server connection may be as simple as prefixing your service name with "d_"; for instance, "sqlplus scott/tiger@d_sales." Otherwise, you can insert the keyword (SERVER=DEDICATED) in the CONNECT_DATA section of your tnsnames.ora file. If you are using network manager, use the ALIAS command on the CREATE menu to create an alias for the server in question and select "Dedicated server" on the Alias options page.

Enabling SQL_TRACE for the Whole System

The initialization parameter SQL_TRACE can be used to enable SQL tracing for all sessions within an Oracle instance. Normally, I would recommend this only if there were no practical way of switching on tracing on a session-by-session basis. Switching SQL_TRACE on for the entire instance can result in noticeable performance degradation and generate a large amount of trace files. To set SQL_TRACE on for the entire instance, add the following line to your init.ora file:

SQL_TRACE=TRUE

Enabling SQL_TRACE within a Session

From within a session, you can activate SQL_TRACE with the following statement:

ALTER SESSION SET SQL_TRACE TRUE;

Because PL/SQL cannot issue the ALTER SESSION statement directly (although you could use the DBMS_SQL package in Oracle7.1 or later), you can use the following standard package to switch on sql_trace in PL/SQL blocks:

dbms_session.set_sql_trace(TRUE)

To use this package, the DBMS_SESSION package must be installed and the ALTER SESSION privilege must be granted (directly - not through a role) to the user.

Table 1 shows examples of how to initiate - from various client tools. I like to encourage developers to build in the ability to turn on SQL tracing within their program, perhaps by a command-line argument. This ability lets you generate traces easily without turning - on for the entire database.

Switching on SQL Tracing from Another Session

Sometimes you can't easily turn on - for the session in which you are interested (for example, if you don't have the source code). Starting with version 7.2, Oracle7 provides a facility to invoke SQL tracing from a different session. The - procedure of the - package provides this functionality. The syntax is:

dbms_system.set_sql_trace_in_session
(sid,serial#,TRUE|FALSE);

where sid and serial# are the session identifier and serial number, respectively, for the session you wish to trace. You can obtain the sid and serial number for a session from the V$SESSION dynamic data dictionary view. For example, the following PL/SQL block enables tracing for all sessions that match the SQL*Plus variable &user_mask:

BEGIN
  FOR sess_rec in (
    SELECT sid,serial#
      FROM v$session
        WHERE username LIKE
         UPPER('&user_mask')) 
  LOOP
    sys.dbms_system.set_sql_trace_
     in_session(sess_rec.sid,sess_
     rec.serial#,TRUE);
  END LOOP;
END;

To use this facility, you or your DBA must ensure that the DBMS_SYSTEM package is installed and then grant the EXECUTE privilege on this package to users who require access to it.

If you're running a version of Oracle earlier than 7.2, it may still be possible to switch on SQL_TRACE for other sessions, depending on the platform and your privileges. I discuss this process later under the subhead "Setting the Trace Event for Another Session."

Finding the Trace File

Having enabled SQL_TRACE, the next challenge is often to find the trace file that was generated. The trace file is written to the location defined by the USER_DUMP_DEST parameter mentioned earlier. The name of the trace file is port-specific, but in Unix and many other operating systems it will be:

header_pid.trc

where header is usually "ora" but sometimes "oracle_sid_ora," and pid is the process identifier for the Oracle server process.

You can determine your USER_DUMP_DEST with the following query (provided that you have access to the V$PARAMETER pseudo-table - see your DBA if you don't):

SELECT value 

   FROM v$parameter 

 WHERE name='user_dump_dest'

However, there might be numerous trace files in the USER_DUMP_DEST, and typically they will all be owned by the Oracle user. Following are some of the ways you can determine which trace is yours:

 

• Examine the timestamps of the files.
• Search for a particular SQL statement. A handy way of "tagging" your trace file is by issuing a statement such as "SELECT 'freddies trace file' FROM dual;". Then you can search among the trace files for the string "freddies trace file."
• Have your program tell you where the trace will be written. For instance, the following PL/SQL block enables SQL_TRACE, determines the location of the trace file, and stores the trace file in the bind variable trace_file_name. The calling program could display the trace file name and location in a log file or on the screen:

DECLARE
 cursor udd_csr is
  SELECT value
    FROM sys.v_$parameter
      WHERE name='user_dump_dest';
 cursor my_pid_csr is
  SELECT spid 
    FROM sys.v_$process 
      WHERE addr=(select paddr 
        FROM sys.v_$session 
          WHERE audsid=userenv('sessionid'));
 l_user_dump_dest  varchar2(256);
 l_pid             varchar2(20);
BEGIN
  - set trace on
  dbms_session.set_sql_trace(TRUE);
  - Get user_dump_dest
  open  udd_csr;
  fetch udd_csr into l_user_dump_dest;
  close udd_csr;
  - Get process id for the shadow
  open my_pid_csr;
  fetch my_pid_csr into l_pid;
  close my_pid_csr;
  - Return the name of the trace file
  :trace_file_name:=l_user_dump_dest||
   '/ora_'||l_pid||'.trc');
END;

Using the tkprof Trace File Formatter

Once you find the trace file, you can use the tkprof utility to render it into a useable form. The basic syntax for tkprof is:

tkprof trace_file output_file

 explain=username/password

 sort=(sort options)

where:

• trace_file is the raw trace file generated by the SQL_TRACE facility
• output_file is the file to which the formatted trace information will be written
• explain=username/password specifies the connection that will be used to generate SQL execution plans; if you don't specify the explain keyword, no output will be generated
• sort=(sort keys) displays the SQL statements in descending values of the sort keys; I prefer the sort keys "(prsela,exeela,fchela)," which sort the SQL statements in descending order of elapsed time - elapsed time usually being the bottom line

Table 2 lists the possible two-part combinations of tkprof sort keys. The first part indicates the type of calls to be sorted; the second part indicates the values to be sorted. For example, exedsk indicates that statements are to be sorted on disk reads during execute calls. Adding options together causes statements to be sorted by the sum of the options specified. For example, (prsdsk,exedsk,fchdisk) causes statements to be sorted by overall physical disk reads. A few combinations are not valid: mis can only be applied to prs, and row can only applied to exe or fch.

A typical tkprof invocation would be:

tkprof ora_12345.trc trace1.prf

 explain=/ sort=

 '( prsela,exeela,fchela)'

which processes the raw trace file ORA_12345.TRC and writes the output file TRACE1.PRF, generating execution plans using my default ("OPS$") account and sorting SQL statements by elapsed time. Note that because this example is under the Unix operating system, I had to enclose the parentheses in quotes.

"Problem" Trace Files

There may still be a few obstacles in your way:

• You can't read your trace file. Oracle usually generates trace files as read-only to the Oracle user or DBA in case the files contain sensitive information (such as passwords for roles or hard-coded data values such as account numbers). If you can't read the trace file and are confident that there are no security implications, ask your DBA to set the undocumented initialization parameter _TRACE_FILES_PUBLIC=TRUE. This change will allow for the creation of trace files with public read permission.
• Your SQL_TRACE is spread across multiple files. This can happen if you are connected to multi-threaded servers. Because each SQL statement might be executed by a different server, the trace information ends up in files associated with each server. The workaround is to use a dedicated server connection. See the earlier section on titled "Preparing to Use SQL_TRACE " for more details on creating a dedicated server connection.

Interpretation of tkprof Output

When users first encounter tkprof output, they are usually confused by the large amount of information, and they have very little guidance on how to interpret it. Listing 1 shows some sample tkprof output. I've added some highlighted superscripts to Listing 1, which I refer to in the following paragraphs.

tkprof Execution Statistics

First, let's look at the top half of the output in Listing 1 (letters in brackets refer to the superscripts shown in Listing 1):

• The SQL text is displayed (1)
• Next is a table containing the execution statistics. Working across the top of the table:
  •  
  • The number of times each category of call was issued (2)
  • The CPU time required (3)
  • The elapsed time required (4)
  • Number of disk reads required (5)
  • Number of buffers read in query (consistent) (6) or current (7) mode. "Current" mode reads occur during updates and table scans, while "query" mode reads occur during SELECTs. I don't believe the distinction is particularly important for SQL tuning, so I usually add them together and call them "logical reads."
  • The number of rows processed (8)

Working down the table, you can see that each measurement is broken down by the category of Oracle call. The three categories are:

 

• parse (a), in which the SQL statement is checked for syntax, valid objects, and security, and in which an execution plan is determined by the optimizer.
• execute (b), in which an SQL statement is executed or, in the case of a query, prepared for fetching.
• fetch (c), in which rows are returned from a query. In the case of a query that contains an ORDER BY or a FOR UPDATE clause, rows may actually have to be accessed during the execute stage.

You can tell a great deal about the SQL statement by deriving some ratios from this output. Some important ratios are:

• Blocks read (f+g) to rows processed (h). This ratio is a rough indication of the relative expense of the query. The more blocks that had to be accessed relative to the number of rows returned, the more "expensive" each row is. A similar ratio is: blocks read (f+g) to executions (e). In our example, the ratio is about 1764.9, which means that each row "cost" about 1765 block I/Os. Ratios above 10-20 may indicate inefficiencies.
• Parse count (d)/execute count (e). Ideally, parse count should be close to 1. If it is high relative to execute count, the statement has been needlessly re-parsed. In Pro*C this may indicate that MAXOPENCURSORS is too low or that the RELEASE_CURSOR option was used inappropriately. In Oracle*Glue it indicates that you have not used explicit context areas. In SQL*Windows it indicates that you have used PrepareAndExecute and/or only a single SQL statement handle. In Oracle Forms, you may have de-selected "optimize transaction mode processing" (optimzeTP) or "optimize SQL processing" (optimizeSQL). In PowerBuilder your value for SQLCache may be too low.
• Rows fetched (i) to fetches (j). This ratio indicates the level to which the array fetch facility has been exercised. In our example the ratio is about 14, which indicates that rows were fetched 14 at a time. A ratio close to one indicates no array processing - which may indicate a significant opportunity for optimization.
• Disk reads (k) to logical reads (f+g). This ratio is a measurement of the "miss rate" within the data buffer cache. You should aim for a miss rate of less than about 10 percent. In my example I had 808 disk reads and therefore a miss rate of 808/(24706+3) = 3 percent.

Interpreting the Execution Plan

The execution plan describes the steps that Oracle will undertake in order to execute the SQL statement. Remember that the execution plan is generated when tkprof is executed and not when the trace file is generated. You should make sure that you haven't changed indexes, run ANALYZE, or changed the OPTIMIZER_MODE between the time you generate the trace file and the time you run tkprof.

The execution plan shows the step (m) and the number of rows processed by each step (l). The row count (l) can indicate which step did the most work and hence might be most amenable to tuning.

Although the detailed interpretation of execution plans is a complex topic that would take more space than I have here, the following rules of thumb may help:

 

• Heavily indented steps are performed first.
• If two statements have the same level of indentation, the upper step is normally performed first.
• The step with the highest row count is often the step you need to optimize.

Refer to your Oracle documentation for further guidance (the Oracle Server tuning manual version 7.2 or the Oracle Application developer's guide in earlier releases; both manuals have an appendix titled "Performance Diagnostic Tools").

Table 3 details some of the common types of execution steps you are likely to encounter.

I interpreted the execution plan shown in Listing 1 as follows (letters in brackets refer to superscripts in Listing 1):

• All rows in SALGRADE were scanned to obtain the one row in which grade=5 (n)
• For each matching row in SALGRADE (one only), the PEOPLE_SEX_IDX was then used to find all rows in which sex="m" (o). 12338 rows matched the criteria (p).
• For each row retrieved by the index, a table lookup was performed to check for matches on AGE and SAL (q).
• 14 rows satisfied the conditions (r).
• For each of the 14 rows, the DEPT_PRIMARY_KEY index was used (s) to look up the DEPT table (via the DEPTNO key) to retrieve the DNAME column (t).
• The resulting rows were sorted (u).

Optimizing SQL

Tuning SQL is a big topic that I can't cover in detail here. However, as an example, let's see how we can use the output in Listing 1 to tune the SQL statement. First, a ratio of 1700 block reads per row returned is fairly high, which should lead you to conclude that some optimization is desirable and probably possible. Looking at the execution plan, you can see that the lookup of PEOPLE_SEX_IDX caused over 12,000 rows to be accessed. Clearly, using an index on gender is not likely to be very selective because there are (usually) only two values. In fact, the PEOPLE table had individual indexes on SEX, AGE, and SAL, but the rule-based optimizers decided to use the index on SEX only (because the gender criteria was specific [="m"], but the salary condition was based on a range).

More appropriate indexing might improve this query. By dropping the existing indexes and replacing them with a concatenated index on sex and sal, you get much improved performance. Listing 2 shows the amended execution statistics and execution plan. As an alternative to creating a new index, you can use a hint to force the use of an appropriate index. For example:

/*+INDEX(PEOPLE,PEOPLE_SALARY_IDX)*/

Elapsed time is now only 1.38 seconds, down from 16.69 (92 percent reduction). Block gets per row are now only 5.2, down from over 1700. Also, you can see that the PEOPLE_SEX_SAL_IDX needs to retrieve only 20 rows, as opposed to over 12,000 for the PEOPLE_SEX_IDX.

This example may seem somewhat contrived and exaggerated, but it's not at all uncommon in my experience to generate tkprof output for some poorly performing SQL statement and find that a particular step is accessing many more rows than required, and that a minor indexing change will result in a dramatic performance improvement.

Adding Wait Statistics to the Trace File

It's possible to include additional information in the trace file by use of an undocumented "event." Experienced DBAs will be familiar with the concept of setting events to trap Oracle errors or to alter the behavior of the RDBMS. (Although officially undocumented, these are discussed in some detail in the book Oracle Backup and Recovery Handbook by Rami Valpuri (Osborne/McGraw-Hill, 1995.) A warning: The functionality provided by events was primarily intended for Oracle support personnel, and you should use these events at your own risk. However, I've found this trace event safe to use.

To set the trace event, you can use the following syntax:

ALTER SESSION set event '10046 trace

name context forever, level n';

where n is a number from 0 to 12, which can take the following values:

 

0	turn tracing off
1	basic tracing (equivalent to ALTER SESSION set sql_trace TRUE)
4	include bind information in the trace
8	include event wait statistics in the trace
12	include both event and bind statistics in the trace

 

The "event wait" statistics are of the most use when tuning SQL; they reveal how long the session waited for various resources, such as disk I/O, latches, locks, and so on. Frequently, analysis of these statistics can reveal the reason for the discrepancy between CPU time and the elapsed times shown in the tkprof output. Very often this information can indicate a bottleneck within the Oracle instance, which indicates that some database-level tuning action is required. Table 4 shows some of the more commonly seen wait events.

Extracting and Displaying Wait Events

Prior to Oracle version 7.1 or 7.0.16 (depending on the platform), tkprof would recognize the wait statistics entries in the trace file and would automatically report on totals for each wait type in the formatted output. (Listing 3 shows an example of this style of tkprof.) In fact, prior to Oracle version 7.0.14, tkprof could break down the waits by the object (for instance, table or latch name) being waited on if you used the undocumented "verbose=yes" option.

For reasons best known to Oracle, the undocumented ability to report on wait information was removed from tkprof in Oracle7.1. The information is still in the raw trace file, but it's hard to interpret because waits times are not summed and because the location of the wait is not displayed in readable format. I wanted to analyze this information for tuning purposes, so I wrote a Pro*C program that can extract the information from the trace file. This program doesn't attribute waits to individual statements in the file, but it does work out the resource the wait was against where possible (for example, the name of the latch or table). Listing 4 shows sample output from this program. You can obtain the source code for this program from http://werple.mira.net.au/~gharriso.

Setting the Trace Event for Another Session

I showed you previously that you could use the DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION packaged procedure to turn on trace for some other session in Oracle7.2. But what if you are pre-7.2 or also want to generate the wait events mentioned above?

On some platforms, an undocumented program will let you activate events against other Oracle sessions. Under Unix, the program is called "oradbx," and in VMS it is called "orambx." There may also be equivalents under other operating systems. Warning: These utilities are undocumented and unsupported, and they were intended only for Oracle support personnel. However, as described in the following paragraphs, the utility is safe to use.

Under Unix, oradbx will probably not already exist. You can create it as the Oracle user by issuing the following commands:

cd $ORACLE_HOME/rdbms/lib

make -f oracle.mk oradbx

You can then use oradbx as follows:

$ oradbx

oradbx>dbug pid

oradbx> event '10046 trace name

context forever, level 8'

oradbx >^D

These commands will cause the process whose server or shadow process is "pid" to generate SQL_TRACE output, including the wait events.

Using the SQL*Plus AUTOTRACE Facility

As you've seen, SQL_TRACE and tkprof are powerful tools. But they are not always easy to use. Each time you use SQL_TRACE, you must find the trace file (which in a client/server environment will often be on a different machine), and then format and interpret the tkprof output. Finding and interpreting the trace files can be time-consuming, and in the past I have often wished I could get tkprof-like feedback immediately after executing a new SQL statement.

Starting with SQL*Plus version 3.3 (the version released with Oracle7.3), Oracle moved part of the way toward providing such a facility. The facility is enabled with the SET AUTOTRACE command within SQL*Plus. AUTOTRACE can generate execution plans and execution statistics for SQL statements executed from SQL*Plus. However, it doesn't provide all the facilities of tkprof - in particular, it doesn't show rows processed for each step in the execution plan.

Requirements for Using AUTOTRACE

Your DBA should grant the PLUSTRACE role to users who need to use the AUTOTRACE utility. I don't see any reason not to grant PLUSTRACE to PUBLIC (all users).

You must have a plan table called PLAN_TABLE in your account. (You can create this with the utlxplan.sql script included with your Oracle distribution.)

Initiating AUTOTRACE

The autotrace command has the options shown in Table 5. For instance, to display the execution plan after each SQL statement, use the following statement:

SET AUTOTRACE ON EXPLAIN

To show both the execution plan and the execution statistics, but to suppress the display of rows returned by queries, use the following statement:

SET AUTOTRACE TRACEONLY STATISTICS

AUTOTRACE Output

Listing 5 shows some output from a sample autotrace session.

AUTOTRACE Compared to tkprof

The AUTOTRACE facility can be extremely useful, but it has the following deficiencies when compared to SQL_TRACE and tkprof:

 

• Row counts are not assigned to individual execution steps. You have seen that the SQL_TRACE/tkprof facility can show the number of rows processed by each stage of execution. This capability is one of tkprof's greatest strengths because it lets you quickly focus in on a particular stage of the execution plan. This focus often reveals an inappropriate index or other weakness. The AUTOTRACE facility cannot produce this information and is accordingly less powerful.

  SQL_TRACE can be turned on from within any Oracle session, but AUTOTRACE only works from within SQL*Plus.

• AUTOTRACE statistics do not include CPU or elapsed times and also do not break execution down by parse, execute, and fetch.
• tkprof output is definitely more useful than AUTOTRACE output - but you shouldn't write off AUTOTRACE. You can use AUTOTRACE under the following circumstances:

   

  • AUTOTRACE is easy to use, and you get the results more quickly than if you have to find and format a trace file. Therefore, you may wish to use AUTOTRACE to rapidly compare multiple approaches to an SQL statement (for example, changing hints, wordings, or perhaps even indexes). When the SQL statement seems close to optimal, you may use SQL_TRACE and tkprof to confirm.
  • Some client/server developers may not have access to the server platform. Therefore, they won't have access to the trace files produced by SQL_TRACE. In this case, the AUTOTRACE facility may be the best tuning option available.

 

Use it or Lose

Imperfectly tuned SQL statements probably account for the vast majority of Oracle performance problems. The SQL_TRACE/tkprof combination is the premier weapon in your SQL tuning arsenal -and it is therefore arguably the most important Oracle tuning tool. Although its usage and interpretation is somewhat obscure and imperfectly documented, DBAs and senior (if not all) developers should make the effort to master this effective tuning tool.

Guy Harrison is an independent consultant working in Melbourne, Australia. He specializes in client/server development using Oracle, and in Oracle performance tuning. You can email Guy at [email protected], or contact him through the Internet at http://werple.mira.net.au/~gharriso.

 

 

TABLE 1. Code to Initialize SQL Tracing within Various Client Tools

 

SQL_TRACE TRUE;

SQL*Plus	ALTER SESSION SET SQL_TRACE TRUE;
Pro*C	EXEC SQL ALTER SESSION SET SQL_TRACE TRUE;
Oracle*Glue	ExecSql("ALTER SESSION SET SQL_TRACE TRUE");
SQL*Forms 4.x	Use statistics=YES on the command line.
SQL*Forms 3.0	Use the -s command line option
SQL*Windows	call sqlPrepareAndExecute(hSql," ALTER SESSION SET SQL_TRACE TRUE")
PowerBuilder	EXECUTE IMMEDIATE ALTER SESSION SET
Stored procedures	dbms_session.set_sql_trace(TRUE)

 

 

---

TABLE 2. Allowable tkprof Sort Key Combinations

 

First part		Second part
prs	Sort on values during parse calls	cnt	Sort on number of calls
		cpu	Sort on CPU consumption
exe	Sort on values during execute calls (equivalent to open cursor for a query)	ela	Sort on elapsed time
		dsk	Sort on disk reads
		qry	Sort on consistent reads
fch	Sort on values during fetch calls (queries only)	cu	Sort on current reads
		mis S	ort on library cache misses
		row	Sort on rows processed

 

 

---

 

LISTING 1. Sample tkprof Output - Before Optimization

  
******************************************************************************
  
 
  
select dname,ename,sal
  
from people,dept,salgrade
  
where people.deptno=dept.deptno
  
and people.sal < salgrade.hisal
  
and people.sal >= salgrade.losal
  
and salgrade.grade=5
  
and people.sex='M'
  
and people.age <30
  
order by dname,ename,sal1
  

 

 

call	count2	cpu3	elapsed4	disk5	query6	current7	rows8
--------	-------	--------	---------	--------	--------	------- -	---------
Parsea	1d	0.00	0.16	0	0	0	0
Executeb	1e	0.00	0.00	0	0	0	0
Fetchc	1	0.00	16.53	808	24706	3	14
--------	-------	--------	---------	--------	--------	-------	----------
total	3	0.00	16.69	808k	24706f	3g	14h

  
Misses in library cache during parse: 1
  
Optimizer hint: CHOOSE
  
Parsing user id: 8 (SCOTT)
  
 
  
Rowsl Execution Planm
  
------- ---------------------------------------------------
  
0 SELECT STATEMENT OPTIMIZER HINT: CHOOSE
  
14 SORT (ORDER BY)u
  
14 NESTED LOOPS
  
14r NESTED LOOPS
  
5 TABLE ACCESS (FULL) OF 'SALGRADE'n
  
12337 TABLE ACCESS (BY ROWID) OF 'PEOPLE'q
  
12338p INDEX (RANGE SCAN) OF 'PEOPLE_SEX_IDX' (NON-UNIQUE)o
  
14 TABLE ACCESS (BY ROWID) OF 'DEPT't
  
14 INDEX (UNIQUE SCAN) OF 'DEPT_PRIMARY_KEY' (UNIQUE)s
  
 
  
******************************************************************************
  

 

 

---

TABLE 3. Some Common Execution Steps

 

AND-EQUALS	Index Merge: Two or more indexes are used to obtain rows from a single table. A list of matching rows is obtained from each index, and rows in all lists are returned. This step sometimes indicates the absence of an appropriate concatenated index and can be an inefficient operation.
INDEX UNIQUE SCAN	Get a single unique value from an index. This is usually highly efficient
INDEX RANGE SCAN	Get one or more matching rows from an index. The efficiency of this step depends on how many rows need to be retrieved. Some of these rows may need to be eliminated during a later table access.
MERGE JOIN	Two tables (or result sets) are sorted and the sorted rows merged. This step sometimes indicates that a join is being performed in the absence of an appropriate index.
NESTED LOOPS	For each row in the first table or result set, a corresponding row is fetched from the second table or result set, usually via an index operation.
HASH JOIN	Perform a hash join (Oracle7.3 only). A hash join works by creating a hash table for one of the tables in the join. This hash table is used as an on-the-fly index to speed the join
HASH JOIN ANTI/MERGE JOIN ANTI	Perform and Oracle7.3 "anti-join." This method allows merge join or hash join techniques to be applied to NOT IN subqueries.
SORT ORDER BY SORT GROUP BY	A result set is sorted to satisfy either an ORDER BY or GROUP BY clause. Although a sort like this is often unavoidable, you can sometimes dispense with the sort by using an appropriate index.
TABLE ACCESS FULL	A full table scan. Avoid these except for very small tables (less than 8 blocks?) or for processing more than 10-25 percent of table rows.
TABLE ACCESSBY ROWID	This step can be seen either where the WHERE CURRENT OF CURSOR construct is used or where an previous INDEX operation has occurred.

 

 

---

LISTING 2. Amended Execution Statistics and Execution Plan

 

call	count	cpu	elapsed	disk	query	current	rows
--------	-------	--------	---------	--------	--------	-------	----------
Parse	1	0.00	0.17	0	0	0	0
Execute	1	0.00	0.00	0	0	0	0
Fetch	1	0.00	1.21	6	70	3	14
--------	-------	--------	---------	--------	--------	-------	----------
total	3	0.00	1.38	6	70	3	14

  
Rows Execution Plan
  
------- ---------------------------------------------------
  
0 SELECT STATEMENT OPTIMIZER HINT: CHOOSE
  
14 SORT (ORDER BY)
  
14 NESTED LOOPS
  
14 NESTED LOOPS
  
5 TABLE ACCESS (FULL) OF 'SALGRADE'
  
19 TABLE ACCESS (BY ROWID) OF 'PEOPLE'
  
20 INDEX (RANGE SCAN) OF 'PEOPLE_SEX_SAL_IDX' (NON-UNIQUE)
  
14 TABLE ACCESS (BY ROWID) OF 'DEPT'
  
14 INDEX (UNIQUE SCAN) OF 'DEPT_PRIMARY_KEY' (UNIQUE)
  

 

 

---

 

TABLE 4. Common Wait Events as Produced by event 10046, level 8

 

Event	Description
db file sequential reads db file scattered reads	Means that the session had to wait while database file blocks were read from disk into the SGA. This wait is unavoidable (unless your entire database is in the SGA) and typically consumes about 80-90 percent of total wait times.
log file sync	This wait occurs during a commit when the log buffer must be written to disk. Again, this wait is unavoidable and may account for 20 percent or more of waits (especially for update-intensive programs). If the average wait time exceeds 0.02-0.05 seconds, it may indicate that the redo log is on slow device, there are two few redo log groups, or the log buffer is too large.
log file space/switch	This wait occurs either when the redo log buffer is full or when a log file switch is required but cannot be performed because of incomplete checkpoint or archiving. If significant, increase the size of the LOG_BUFFER or create more redo log groups.
Buffer busy waits	Should be negligible. High values can indicate rollback segment or free list contention.
Free buffer waits	Should be negligible. Indicates that the database writers are not clearing blocks from SGA as fast as dirty blocks are being created. High values are often due to excessive disk sorts.
latch wait	Should be negligible. If not, action depends on the latch. Reducing contention for the redo copy/redo allocation latches is covered in the Oracle administration or Oracle tuning guides. Contention for library cache, shared pool, or library cache pin latches usually means that too much non-sharable SQL is being executed. Try to use stored procedures or bind variables.
enqueue	Indicates waits while attempting to acquire a lock. Consistently high values may indicate contention for locks.
Write complete waits	Should be negligible. This wait occurs when the process attempts to write to a block that is currently being written to disk by the database writers. High values may indicate insufficient db_writers or a disk bottleneck that is affecting the database writer.
SQL*Net message to client	Should be low. High values may indicate that there is a network or client-side bottleneck.
client message SQL*Net message from client	Usually safe to ignore. Indicates that the session is waiting for instructions from the client.

 

 

---

LISTING 3. Wait Events as Displayed by pre-Oracle7 version 7.1 tkprof

 

 

Rows	Execution Plan
-------	---------------------------------------------------
0	SELECT STATEMENT
34028	SORT (ORDER BY)
34028	TABLE ACCESS (FULL) OF 'BIGEMP'

  
Elapsed times include waiting on following wait events:
  
2 times for 0.00 seconds for "rdbms ipc reply"
  
2 times for 0.42 seconds for "write complete waits"
  
1 time for 0.53 seconds for "log file space/switch"
  
1 time for 0.02 seconds for "log file sync"
  
2 times for 0.00 seconds for "db file sequential
  read"
  
110 times for 0.12 seconds for "db file scattered
  read"
  
3 times for 142.01 seconds for "client message"
  
2 of above waits occurred during Parse.
  
115 of above waits occurred during Execute.
  
4 of above waits occurred during Fetch.
  

 

 

---

LISTING 4. Partial Output from the tk_waits Pro*C Program

 

 

Summary of waits by category


----------------------------

 

Event Name	No of Waits	Pct of Total	Time Waited	Pct of Total
------------------------------	--------	--------	--------	--------
free buffer waits	3	2.26	1.77	42.14
write complete waits	4	3.01	1.67	39.76
log file space/switch	1	0.75	0.53	12.62
db file scattered read	110	82.71	0.12	2.86
log file sync	4	3.01	0.11	2.62
db file sequential read	9	6.77	0.00	0.00
rdbms ipc reply	2	1.50	0.00	0.00

 

 

Breakdown of waits by resource


------------------------------

 

Event or resource Name	No of Waits	Pct of Total	Time Waited	Pct of Total
------------------------------	--------	--------	--------	--------
	** free buffer waits
Seg in TEMP tspace	3	100.00	1.77	100.00
** Sub Total **	3		1.77
	** write complete waits
SYS.FET$	2	50.00	1.25	74.85
R03	1	25.00	0.26	15.57
Seg in TEMP tspace	1	25.00	0.16	9.58
** Sub Total **	4		1.67

 

 

---

TABLE 5. AUTOTRACE Options

 

 

OFF	Normal behavior, generate no trace output.
EXPLAIN	Following each SQL statement execution, display the execution plan in the normal "nested" format.
STATISTICS	Following each SQL statement execution, print a report detailing I/O, CPU, and other resource utilization.
ON	After SQL statement execution, display both the execution plan and the execution statistics.
TRACEONLY	Suppresses the display of data from an SQL statement so that only the execution plan and statistics are shown.

 

 

---

 

LISTING 5. AUTOTRACE Output

  
SQL> set autotrace traceonly explain statistics
  
SQL> @qry1
  
 
  
SQL> l
  
1 select /*+ ORDERED USE_HASH(C) */
  
2 c.contact_surname,c.contact_firstname,c.date_of_birth
  
3 from
  
4 employees e,
  
5 customers c
  
6 where e.surname=c.contact_surname
  
7 and e.firstname=c.contact_firstname
  
8* and e.date_of_birth=c.date_of_birth
  
SQL> 
  
SQL> /
  
 
  
no rows selected
  

 

Execution Plan


----------------------------------------------------------


 

 

0		SELECT STATEMENT Cost=77 Optimizer=CHOOSE
1	0	HASH JOIN
2	1	TABLE ACCESS (FULL) OF 'EMPLOYEES'
3	1	INDEX (FULL SCAN) OF 'SURNAME_FIRSTNAME_DOB_PHONENO'

 

 

Statistics


----------------------------------------------------------


 

1361	recursive calls
13	db block gets
768	consistent gets
618	physical reads
0	redo size
245	bytes sent via SQL*Net to client
523	bytes received via SQL*Net from client
3	SQL*Net roundtrips to/from client
0	sorts (memory)
0	sorts (disk)
0	rows processed