18 Performing Application Tracing

The procedure CLIENT_ID_STAT_ENABLE enables statistics gathering for a given client ID, whereas the procedure CLIENT_ID_STAT_DISABLE disables it. You can view client identifiers in the CLIENT_IDENTIFIER column in V$SESSION.

Assumptions

This tutorial assumes that you want to enable and then disable statistics gathering for the client with the ID oe.oe.

To enable and disable statistics gathering for a client identifier:

1. Start SQL*Plus, and then connect to the database with the appropriate privileges.

2. Enable statistics gathering for oe.oe.

   For example, run the following command:

   EXECUTE DBMS_MONITOR.CLIENT_ID_STAT_ENABLE(client_id => 'OE.OE');
   

3. Disable statistics gathering for oe.oe.

   For example, run the following command:

   EXECUTE DBMS_MONITOR.CLIENT_ID_STAT_DISABLE(client_id => 'OE.OE');
   

The procedure SERV_MOD_ACT_STAT_ENABLE enables statistic gathering for a combination of service, module, and action, whereas the procedure SERV_MOD_ACT_STAT_DISABLE disables statistic gathering for a combination of service, module, and action.

When you change the module or action using the preceding DBMS_MONITOR procedures, the change takes effect when the next user call is executed in the session. For example, if a module is set to module1 in a session, and if the module is reset to module2 in a user call in the session, then the module remains module1 during this user call. The module is changed to module2 in the next user call in the session.

Assumptions

This tutorial assumes that you want to gather statistics as follows:

• For the ACCTG service

• For all actions in the PAYROLL module

• For the INSERT ITEM action within the GLEDGER module

To enable and disable statistics gathering for a service, module, and action:

1. Start SQL*Plus, and then connect to the database with the appropriate privileges.

2. Enable statistics gathering for the desired service, module, and action.

   For example, run the following commands:

   BEGIN 
     DBMS_MONITOR.SERV_MOD_ACT_STAT_ENABLE(
       service_name => 'ACCTG'   ,  
       module_name  => 'PAYROLL' );
   END;
   
   BEGIN 
     DBMS_MONITOR.SERV_MOD_ACT_STAT_ENABLE(
       service_name => 'ACCTG'       ,  
       module_name  => 'GLEDGER'     ,  
       action_name  => 'INSERT ITEM' );
   END;
   

3. Disable statistic gathering for the previously specified combination of service, module, and action.

   For example, run the following command:

   BEGIN 
     DBMS_MONITOR.SERV_MOD_ACT_STAT_DISABLE(
       service_name => 'ACCTG'       ,  
       module_name  => 'GLEDGER'     ,  
       action_name  => 'INSERT ITEM' );
   END;
   

To enable tracing globally for the database for a specified client identifier, use the CLIENT_ID_TRACE_ENABLE procedure. The CLIENT_ID_TRACE_DISABLE procedure disables tracing globally for the database for a given client identifier.

Assumptions

This tutorial assumes the following:

• OE.OE is the client identifier for which SQL tracing is to be enabled.

• You want to include wait information in the trace.

• You want to exclude bind information from the trace.

To enable and disable tracing for a client identifier:

1. Start SQL*Plus, and then connect to the database with the appropriate privileges.

2. Enable tracing for the client.

   For example, execute the following program:

   BEGIN 
     DBMS_MONITOR.CLIENT_ID_TRACE_ENABLE(
       client_id => 'OE.OE' ,      
       waits     => true    ,      
       binds     => false   );
   END;
   

3. Disable tracing for the client.

   For example, execute the following command:

   EXECUTE DBMS_MONITOR.CLIENT_ID_TRACE_DISABLE(client_id => 'OE.OE');
   

The SERV_MOD_ACT_TRACE_ENABLE procedure enables SQL tracing for a specified combination of service name, module, and action globally for a database, unless the procedure specifies a database instance name. The SERV_MOD_ACT_TRACE_DISABLE procedure disables the trace at all enabled instances for a given combination of service name, module, and action name globally.

Assumptions

This tutorial assumes the following:

• You want to enable tracing for the service ACCTG.

• You want to enable tracing for all actions for the combination of the ACCTG service and the PAYROLL module.

• You want to include wait information in the trace.

• You want to exclude bind information from the trace.

• You want to enable tracing only for the inst1 instance.

To enable and disable tracing for a service, module, and action:

1. Start SQL*Plus, and then connect to the database with the appropriate privileges.

2. Enable tracing for the service, module, and actions.

   For example, execute the following command:

   BEGIN 
     DBMS_MONITOR.SERV_MOD_ACT_TRACE_ENABLE(
       service_name  => 'ACCTG'   ,
       module_name   => 'PAYROLL' ,
       waits         =>  true     ,
       binds         =>  false    ,
       instance_name => 'inst1'   );
   END;
   

3. Disable tracing for the service, module, and actions.

   For example, execute the following command:

   BEGIN 
     DBMS_MONITOR.SERV_MOD_ACT_TRACE_DISABLE(
       service_name  => 'ACCTG'   ,
       module_name   => 'PAYROLL' ,
       instance_name => 'inst1'   );
   END;
   

The SESSION_TRACE_ENABLE procedure enables the trace for a given database session identifier (SID), on the local instance. Whereas the DBMS_MONITOR package can only be invoked by a user with the DBA role, any user can also enable SQL tracing for their own session by using the DBMS_SESSION package. A user can invoke the SESSION_TRACE_ENABLE procedure to enable session-level SQL trace for the user's session. For example:

EXECUTE DBMS_SESSION.SESSION_TRACE_ENABLE(waits => true, binds => false);

Assumptions

This tutorial assumes the following:

• You want to log in to the database with administrator privileges.

• User OE has one active session.

• You want to temporarily enable tracing for the OE session.

• You want to include wait information in the trace.

• You want to exclude bind information from the trace.

To enable and disable tracing for a session:

1. Start SQL*Plus, and then connect to the database with the administrator privileges.

2. Determine the session ID and serial number values for the session to trace.

   For example, query V$SESSION as follows:

   SELECT SID, SERIAL#, USERNAME 
   FROM   V$SESSION
   WHERE  USERNAME = 'OE';
   
          SID    SERIAL# USERNAME
   ---------- ---------- ------------------------------
           27         60 OE
   

3. Use the values from the preceding step to enable tracing for a specific session.

   For example, execute the following program to enable tracing for the OE session, where the true argument includes wait information in the trace and the false argument excludes bind information from the trace:

   BEGIN 
     DBMS_MONITOR.SESSION_TRACE_ENABLE(
       session_id => 27 , 
       serial_num => 60 ,
       waits => true    , 
       binds => false   );
   END;
   

4. Disable tracing for the session.

   The SESSION_TRACE_DISABLE procedure disables the trace for a given database session identifier (SID) and serial number. For example:

   EXECUTE DBMS_MONITOR.SESSION_TRACE_DISABLE(session_id => 27, serial_num => 60);
   

The DBMS_MONITOR.DATABASE_TRACE_ENABLE procedure overrides all other session-level traces, but is complementary to the client identifier, service, module, and action traces. Tracing is enabled for all current and future sessions.

All new sessions inherit the wait and bind information specified by this procedure until you call the DATABASE_TRACE_DISABLE procedure. When you invoke this procedure with the instance_name parameter, the procedure resets the session-level SQL trace for the named instance. If you invoke this procedure without the instance_name parameter, then the procedure resets the session-level SQL trace for the entire database.

Prerequisites

You must be logged in as an administrator execute the DATABASE_TRACE_ENABLE procedure.

Assumptions

This tutorial assumes the following:

• You want to enable tracing for all SQL the inst1 instance.

• You want wait information to be in the trace.

• You do not want bind information in the trace.

To enable and disable tracing for a session:

1. Start SQL*Plus, and then connect to the database with the administrator privileges.

2. Call the DATABASE_TRACE_ENABLE procedure to enable SQL tracing for a given instance or an entire database.

   For example, execute the following program, where the true argument specifies that wait information is in the trace, and the false argument specifies that no bind information is in the trace:

   BEGIN 
     DBMS_MONITOR.DATABASE_TRACE_ENABLE(
       waits         => true    , 
       binds         => false   ,     
       instance_name => 'inst1' );
   END;
   

3. Disable tracing for the session.

   The SESSION_TRACE_DISABLE procedure disables the trace. For example, the following program disables tracing for inst1:

   EXECUTE DBMS_MONITOR.DATABASE_TRACE_DISABLE(instance_name => 'inst1');
   

   To disable the session-level SQL tracing for an entire database, invoke the DATABASE_TRACE_DISABLE procedure without specifying the instance_name parameter:

   EXECUTE DBMS_MONITOR.DATABASE_TRACE_DISABLE();
   

When the SQL Trace facility is enabled for a session, Oracle Database generates a trace file containing statistics for traced SQL statements for that session. When the SQL Trace facility is enabled for an instance, Oracle Database creates a separate trace file for each process.

To set initialization parameters for trace file management:

1. Check the settings of the TIMED_STATISTICS, MAX_DUMP_FILE_SIZE, and DIAGNOSTIC_DEST initialization parameters, as indicated in Table 18-1.

   ---

   Table 18-1 Initialization Parameters to Check Before Enabling SQL Trace

   Parameter	Description
   DIAGNOSTIC_DEST	Specifies the location of the Automatic Diagnostic Repository (ADR) Home. The diagnostic files for each database instance are located in this dedicated directory. Oracle Database Reference for information about the DIAGNOSTIC_DEST initialization parameter.
   MAX_DUMP_FILE_SIZE	When the SQL Trace facility is enabled at the database instance level, every call to the database writes a text line in a file in the operating system's file format. The maximum size of these files in operating system blocks is limited by this initialization parameter. The default is UNLIMITED. See Oracle Database Administrator's Guide to learn how to control the trace file size.
   TIMED_STATISTICS	Enables and disables the collection of timed statistics, such as CPU and elapsed times, by the SQL Trace facility, and the collection of various statistics in the V$ views. If STATISTICS_LEVEL is set to TYPICAL or ALL, then the default value of TIMED_STATISTICS is true. If STATISTICS_LEVEL is set to BASIC, then the default value of TIMED_STATISTICS is false. See Oracle Database Reference for information about the STATISTICS_LEVEL initialization parameter. Enabling timing causes extra timing calls for low-level operations. This is a dynamic parameter. It is also a session parameter. See Oracle Database Reference for information about the TIMED_STATISTICS initialization parameter.

   ---

2. Devise a way of recognizing the resulting trace file.

   Be sure you know how to distinguish the trace files by name. You can tag trace files by including in your programs a statement such as SELECT 'program_name' FROM DUAL. You can then trace each file back to the process that created it.

   You can also set the TRACEFILE_IDENTIFIER initialization parameter to specify a custom identifier that becomes part of the trace file name (see Oracle Database Reference for information about the TRACEFILE_IDENTIFIER initialization parameter). For example, you can add my_trace_id to subsequent trace file names for easy identification with the following:

   ALTER SESSION SET TRACEFILE_IDENTIFIER = 'my_trace_id';
   

3. If the operating system retains multiple versions of files, then ensure that the version limit is high enough to accommodate the number of trace files you expect the SQL Trace facility to generate.

4. If the generated trace files can be owned by an operating system user other than yourself, then ensure that you have the necessary permissions to use TKPROF to format them.

Enable the SQL Trace facility at either of the following levels:

• Database instance

  Use DBMS_MONITOR.DATABASE_TRACE_ENABLE procedure to enable tracing, and DBMS_MONITOR.DATABASE_TRACE_DISABLE procedure to disable tracing.

• Database session

  Use DBMS_SESSION.SET_SQL_TRACE procedure to enable tracing (true) or disable tracing (false).

  Note:

  Because running the SQL Trace facility increases system overhead, enable it only when tuning SQL statements, and disable it when you are finished.

To enable and disable tracing at the database instance level:

1. Start SQL*Plus, and connect to the database with administrator privileges.

2. Enable tracing at the database instance level.

   The following example enables tracing for the orcl instance:

   EXEC DBMS_MONITOR.DATABASE_TRACE_ENABLE(INSTANCE_NAME => 'orcl');
   

3. Execute the statements to be traced.

4. Disable tracing for the database instance.

   The following example disables tracing for the orcl instance:

   EXEC DBMS_MONITOR.DATABASE_TRACE_DISABLE(INSTANCE_NAME => 'orcl');
   

To enable and disable tracing at the session level:

1. Start SQL*Plus, and connect to the database with the desired credentials.

2. Enable tracing for the current session.

   The following example enables tracing for the current session:

   EXEC DBMS_SESSION.SET_SQL_TRACE(sql_trace => true);
   

3. Execute the statements to be traced.

4. Disable tracing for the current session.

   The following example disables tracing for the current session:

   EXEC DBMS_SESSION.SET_SQL_TRACE(sql_trace => false);
   

TKPROF accepts as input a trace file produced by the SQL Trace facility, and it produces a formatted output file. TKPROF can also generate execution plans.

After the SQL Trace facility has generated trace files, you can:

• Run TKPROF on each individual trace file, producing several formatted output files, one for each session.

• Concatenate the trace files, and then run TKPROF on the result to produce a formatted output file for the entire instance.

• Run the TRCSESS command-line utility to consolidate tracing information from several trace files, then run TKPROF on the result.

TKPROF does not report COMMIT and ROLLBACK statements recorded in the trace file.

SET ROLE
GRANT
ALTER USER
ALTER ROLE
CREATE USER
CREATE ROLE

Timing statistics have a resolution of one hundredth of a second. Therefore, any operation on a cursor that takes a hundredth of a second or less might not be timed accurately. Keep this limitation in mind when interpreting statistics. In particular, be careful when interpreting the results from simple queries that execute very quickly.

Sometimes, to execute a SQL statement issued by a user, Oracle Database must issue additional SQL statements. Such statements are called recursive calls or recursive SQL. For example, if a session inserts a row into a table that has insufficient space to hold that row, then the database makes recursive calls to allocate the space dynamically. The database also generates recursive calls when data dictionary information is not available in memory and so must be retrieved from disk.

If recursive calls occur while the SQL Trace facility is enabled, then TKPROF produces statistics for the recursive SQL statements and marks them clearly as recursive SQL statements in the output file. You can suppress the listing of Oracle Database internal recursive calls (for example, space management) in the output file by setting the SYS command-line parameter to NO. The statistics for a recursive SQL statement are included in the listing for that statement, not in the listing for the SQL statement that caused the recursive call. So, when you are calculating the total resources required to process a SQL statement, consider the statistics for that statement and those for recursive calls caused by that statement.

You must determine which SQL statements use the most CPU or disk resource. If the TIMED_STATISTICS parameter is enabled, then you can find high CPU activity in the CPU column. If TIMED_STATISTICS is not enabled, then check the QUERY and CURRENT columns.

With the exception of locking problems and inefficient PL/SQL loops, neither the CPU time nor the elapsed time is necessary to find problem statements. The key is the number of block visits, both query (that is, subject to read consistency) and current (that is, not subject to read consistency). Segment headers and blocks that are going to be updated are acquired in current mode, but all query and subquery processing requests the data in query mode. These are precisely the same measures as the instance statistics CONSISTENT GETS and DB BLOCK GETS. You can find high disk activity in the disk column.

The following listing shows TKPROF output for one SQL statement as it appears in the output file:

SELECT * 
FROM emp, dept 
WHERE emp.deptno = dept.deptno;

call   count      cpu    elapsed     disk    query current    rows
---- -------  -------  --------- -------- -------- -------  ------
Parse     11     0.08      0.18        0       0       0         0
Execute   11     0.23      0.66        0       3       6         0
Fetch     35     6.70      6.83      100   12326       2       824
------------------------------------------------------------------
total     57     7.01      7.67      100   12329       8       826

Misses in library cache during parse: 0 

If it is acceptable to have 7.01 CPU seconds and to retrieve 824 rows, then you need not look any further at this trace output. In fact, a major use of TKPROF reports in a tuning exercise is to eliminate processes from the detailed tuning phase.

The output indicates that 10 unnecessary parse call were made (because 11 parse calls exist for this single statement) and that array fetch operations were performed. More rows were fetched than there were fetches performed. A large gap between CPU and elapsed timings indicates Physical I/Os.