Enable SQL Trace and locate your trace files
Format trace files using TKPROF
Interpret the output of the TKPROF command
SQL Trace Facility
Is set at the instance or session level
Gathers statistics for SQL statements
Produces output that can be formatted by TKPROF
A good way to compare two execution plans is to run them and compare the statistics to see which one performs better. You can use the SQL Trace facility to obtain performance information. SQL Trace writes its output to a file, and you use TKPROF to format it.
The SQL Trace facility:
• Can be switched on for an instance or a session
• Reports on volume and time statistics for the PARSE, EXECUTE, and FETCH phases
• Produces output that can be formatted by TKPROF
When the SQL trace facility is enabled for a session, Oracle generates a trace file containing statistics for traced SQL statements for that session. When the SQL trace facility is enabled for an instance, Oracle creates a separate trace file for each process.
Note: SQL Trace involves some overhead, so you normally do not want to enable SQL Trace at the instance level.
How to Use the SQL Trace Facility
Set the initialization parameters.
Switch on tracing.
Run the application.
Format the trace file.
Interpret the output.
You must complete five steps to use the SQL Trace tool:
1. Set the appropriate initialization parameters.
2. Switch on SQL Trace.
3. Run the application (and switch off tracing when done).
4. Format the trace file produced by SQL Trace with TKPROF.
5. Interpret the output and tune the SQL statements when needed.
Running SQL Trace increases system overhead. Use SQL Trace only when required, and use it at the session level rather than at the instance level.
Note : On certain platforms, it is necessary to exit your session after step 3 to get the full trace file on disk. Sometimes the last part is missing from a trace file; exiting your session resolves that problem. STAT lines in the trace file are only written when the corresponding cursor is closed.
Initialization Parameters
Several initialization parameters relate to SQL Trace.
TIMED_STATISTICS :
• The SQL Trace facility provides a variety of information about processes, optionally including timing information.
• If you want timing information, you must turn on this parameter. You can do so for the entire database by setting the following initialization parameter in the parameter file before starting up and opening the database:
TIMED_STATISTICS = TRUE
• The parameter also can be set dynamically for a particular session with the following command:
SQL> alter session set timed_statistics=true;
• The timing statistics have a resolution of one-hundredth of a second. This means that any operation that finishes quickly may not be timed accurately, such as simple queries that execute quickly.
• Having TIMED_STATISTICS turned on affects performance slightly because the Oracle server must do some additional work. Therefore, this parameter is commonly turned off until specifically desired for tuning purposes. However, keeping TIMED_STATISTICS turned on could make trace files more useful for support engineers upon a system crash.
Note: The underlined values in the slide indicate the default values for the parameters.
MAX_DUMP_FILE_SIZE and USER_DUMP_DEST
These two parameters control the size and destination of the output file:
MAX_DUMP_FILE_SIZE = n
USER_DUMP_DEST = directory_path
• The MAX_DUMP_FILE_SIZE default value is 500, and this parameter value is expressed in operating system blocks.
• MAX_DUMP_FILE_SIZE can also be changed at the session level by using the ALTER SESSION command.
• The default USER_DUMP_DEST location varies by operating system; it normally is the default destination for system dumps on your system.
• USER_DUMP_DEST is a system level parameter that cannot be changed at the session level. It can only be changed dynamically by a database administrator using the ALTER SYSTEM command.
• Obtain Information about Parameter Settings. You can display current parameter values by querying the V$PARAMETER view:
SQL> select name, value
2 from v$parameter
3 where name like '%dump%';
Note: The directory path specifications that show up in the VALUE column are operating system dependent.
• In Oracle9i you can also use the “show parameter
• If the MAX_DUMP_FILE_SIZE is reached, *** Trace File Full *** is written to the trace file. No notification or error message is displayed, and the background process stops writing to the trace file.
• Note that there is an additional initialization parameter, SQL_TRACE, that influences SQL Trace. However, it is not a parameter to use when preparing for SQL Trace, but rather when enabling SQL Trace. That is why it is not on the previous slide but is introduced on the next slide. You should discourage use of that parameter and suggest enabling SQL Trace at the session level instead.
• Note that when you are using SQL Trace in Multi-Threaded Server (MTS), the shared server processes will create trace files in the BACKGROUND_DUMP_DEST, not in the USER_DUMP_DEST directory.
TIMED_STATISTICS = {false|true}
MAX_DUMP_FILE_SIZE = {n|500}
USER_DUMP_DEST = directory_path
MAX_DUMP_FILE_SIZE is measured in Operating System blocks
Default USER_DUMP_DEST : background dump destination
Switching On SQL Trace for an Instance
For an instance, set the following parameter:
SQL_TRACE = TRUE
For your current session:
SQL> alter session set sql_trace = true;
SQL> execute dbms_session.set_sql_trace(true);
For any session:
SQL> execute dbms_system.set_sql_trace_in_session
2 (session_id, serial_id, true);
• In order to switch on SQL Trace for an entire instance, set the initialization parameter:
SQL_TRACE = TRUE
• Switching On SQL Trace for a Session. You can use a SQL command to switch on SQL Trace for your session.
SQL> alter session set sql_trace = true;
• You can also use a supplied package to switch on SQL Trace for your session. This is useful when you want to turn SQL Trace on and off from within a PL/SQL unit.
SQL> execute dbms_session.set_sql_trace(true);
• You can also switch on SQL Trace for another user’s session with a supplied package.
SQL> execute dbms_system.set_sql_trace_in_session
2 (session_id, serial_id, true);
• In this procedure call, session_id and serial_id are the values in the SID and SERIAL# columns of V$SESSION, a data dictionary view commonly used by database administrators.
• Switching Off SQL Trace. When you have finished tuning, you can switch off SQL Trace by using any of the above methods, substituting the word FALSE for TRUE. If you switch on SQL Trace for a single session, exiting that session also turns off SQL Trace.
Finding Your Trace Files
Look in the directory specified by USER_DUMP_DEST.
If only a few people are running SQL Trace, look for the most recent time stamp.
Otherwise, consider writing a script.
SQL> @readtrace.sql
SQL> execute gettrace;
PL/SQL procedure successfully completed.
Identifying your trace file in the directory specified by USER_DUMP_DEST is usually a matter of finding the trace file with the most recent time stamp. However, this task becomes more difficult when several users generate trace files at the same time.
When several users create trace files simultaneously, the readtrace.sql script can be useful. It creates a procedure that opens your current trace file using the UTL_FILE package. The default output file name is username.trc, but you can also specify a name yourself.
SQL> @readtrace.sql
SQL> alter session set sql_trace = true;
SQL> select * from dual;
SQL> execute gettrace('output_filename');
Note :
The readtrace is not a standard Oracle utility that comes with the software, but is only developed and provided for this course.
There is also a script gt.sql that you can use to hide the execute gettrace statement; it accepts the output_filename as an argument.
Formatting Your Trace Files
OS> tkprof tracefile outputfile [options]
TKPROF command examples :
OS> tkprof
OS> tkprof ora_815.trc run1.txt
OS> tkprof ora_815.trc run2.txt sys=no
sort=execpu print=3
Use the TKPROF command to format your trace files into a readable output.
OS> tkprof tracefile outputfile [options]
tracefile The name of the trace output file (input for TKPROF)
outputfile The name of the file to store the formatted results
When the TKPROF command is entered without any arguments, it generates a usage message together with a description of all TKPROF options.
Note: Trace files generated immediately after instance startup contain data that reflects the activity of the startup process. In particular, they reflect a disproportionate amount of physical I/O activity as caches in the SGA are filled. For the purposes of tuning, you should ignore such trace files.
These are just some examples; the full TKPROF syntax will be explained later.
In previous releases, TKPROF had a version component in the command name on Windows platforms (for example, tkprof73 or tkprof80). With Oracle9i, there is no tkprof81 command anymore.
SORT = option
PRINT = n
EXPLAIN = username/password
INSERT = filename
SYS = NO
AGGREGATE = NO
RECORD = filename
TABLE = schema.tablename
Output of the TKPROF command
Text of the SQL statement
Trace statistics (for statement and recursive calls) separated into three SQL processing steps:
PARSE Translates the SQL statement into an execution plan
EXECUTE Executes the statement
(This step modifies the data for INSERT, UPDATE, and DELETE statements.)
FETCH Retrieves the rows returned by a query (Fetches are performed only for SELECT statements.)
The TKPROF output lists the statistics for a SQL statement by the SQL processing step.
The step for which each row contains statistics is identified by the value of the call column.
Seven categories of trace statistics:
Count Number of times procedure was executed.
CPU Number of seconds to process
Elapsed Total number of seconds to execute
Disk Number of physical blocks read
Query Number of logical buffers read for consistent read
Current Number of logical buffers read in current mode
Rows Number of rows processed by the fetch or execute
Output of the TKPROF command
The TKPROF output also includes the following:
Recursive SQL statements
Library cache misses
Parsing user ID
Execution plan
Optimizer mode or hint
• Recursive Calls : Sometimes in order to execute a SQL statement issued by a user, the Oracle server must issue additional statements. Such statements are called recursive SQL statements. For example, if you insert a row into a table that does not have enough space to hold that row, the Oracle server makes recursive calls to allocate the space dynamically. Recursive calls are also generated when data dictionary information is not available in the data dictionary cache and must be retrieved from disk. If recursive calls occur while the SQL trace facility is enabled, TKPROF marks them clearly as recursive SQL statements in the output file. You can suppress the listing of recursive calls in the output file by setting the SYS=NO command-line parameter. Note that the statistics for recursive SQL statements are always included in the listing for the SQL statement that caused the recursive call.
• Library Cache Misses : TKPROF also lists the number of library cache misses resulting from parse and execute steps for each SQL statement. These statistics appear on separate lines following the tabular statistics.
• Parsing User ID : This is the ID of the last user to parse the statement.
• Execution Plan : If you specify the EXPLAIN parameter on the TKPROF command line, TKPROF uses the EXPLAIN PLAN command to generate the execution plan of each SQL statement traced. TKPROF also displays the number of rows processed by each step of the execution plan. Note: Be aware that the execution plan is generated at the time that the TKPROF command is run and not at the time the trace file was produced. This could make a difference if, for example, an index has been created or dropped since tracing the statements.
• Optimizer Mode or Hint : This indicates the optimizer hint used during the execution of the statement. If there is no hint, then it shows the optimizer mode used. Hints and optimizer modes are discussed in more detail in the “Influencing the Optimizer” lesson.
• Note that Oracle9i TKPROF output also shows the row source operators (RSO) before the (optional) full execution plan. Note that these row source operators are derived from the trace file STAT lines without accessing the database, as opposed to the additional execution plan generated with the EXPLAIN option.
TKPROF Output Example : No Index
SQL> select status from registrations
2 where class_id = 155801 and stud_id = 7586;
call count cpu elapsed disk query current rows
------------ ---- ------- ---- ----- ------- ----
Parse 1 0.54 0.56 1 0 0 0
Execute 1 0.01 0.01 0 0 0 0
Fetch 1 0.52 1.47 1159 1160 0 1
------------ ---- ------- ---- ---- ------- ----
total 3 1.07 2.04 1160 1160 0 1
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 75
The example in the slide shows one row being fetched from the registrations table. It requires 1,160 reads and 0.52 seconds of CPU fetch time. The statement is executed through a full table scan of the REGISTRATIONS table, as you could see using the EXPLAIN command-line option. The statement needs to be optimized.
TKPROF Output Example : Unique Index
SQL> select status from registrations
2 where class_id = 155801 and stud_id = 7586;
call count cpu elapsed disk query current rows
------------ ---- ------- ---- ----- ------- ----
Parse 1 0.10 0.10 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 4 0 1
------------ ---- ------- ---- ---- ------- ----
total 3 0.10 0.10 0 4 0 1
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 75
The same row is retrieved, but in this case I/O is substantially reduced to only four blocks read. In addition, CPU time is reduced to 0.00 seconds. These results are achieved because the statement uses a unique index.
You can achieve significant improvements in performance by sensible indexing. Identify areas for potential improvement using the SQL Trace facility.
Note: Indexes should not be built until required. Indexes slow down the processing of INSERT, UPDATE, and DELETE commands, because references to rows need to be added, changed, or removed. Unused indexes should be removed. If possible, process all application SQL through EXPLAIN PLAN and remove any indexes that are not referenced.
This demonstration can also be done using SQL*Plus AUTOTRACE or TKPROF:
SQL> alter table registrations disable primary key cascade;
SQL> set autotrace traceonly
SQL> @d04-17
SQL> alter table registrations enable primary key;
SQL> @d04-17
Some TKPROF Interpretation Pitfalls
Read consistency trap
Schema trap
Time trap
Trigger trap
• Read Consistency Trap : Sometimes other transactions hold uncommitted changes against a table. This increases the number of block visits, because additional blocks must be constructed and visited for read consistency.
• Schema Trap : The TKPROF statistics show a high number of block visits while the execution plan indicates an index access. Especially if the output shows a nonzero value for current, the table is probably accessed by a full table scan (compare the current columns on the two previous pages). The index is probably built after the trace file is produced, or the table and column statistics may be recomputed.
• Time Trap : If a particular DML statement shows high timing statistics, the explanation may be interference from another transaction holding (shared) locks on the table. That is why CPU time is a better indicator than elapsed time.
• Trigger Trap : The resources reported for a statement include those for all of the SQL issued while the statement was being processed. Therefore, they include any resources used within a trigger, along with the resources used by any other recursive SQL (such as SQL used for space allocation).
No comments:
Post a Comment