Oracle now recommends that you use the DBMS_MONITOR package for most types of tracing.
we show how to trace sessions by setting various Oracle events, the setting of which is often requested by Oracle Support.
You'll learn
- How to trace a Specific SQL statement
- How to Enabling Tracing in Your Own Session
- How to Finding the Trace Files ( doubt )
- How to Examining a Raw SQL Trace File
- How to Analyzing Oracle Trace Files
- How to Formatting Trace Files with TKPROF
- How to Analyzing TKPROF Output
- How to Analyzing Trace Files with Oracle Trace Analyzer
- How to trace a parallel queries
- How to trace Specific Parallel Query Processes
- How to Trace Parallel Queries in a RAC System
- How to Consolidating Multiple Trace Files
- How to Find the Correct Session for Tracing
- How to trace a SQL Session
- How to trace a Session by Process ID
- How to trace Multiple SQL Sessions belong to single user
- How to Tracing an Instance or a Database
- How to Generating an Event 10046 Trace for a Session
- How to Generating an Event 10046 Trace for an Instance
- How to Setting a Trace in a Running Session
- How to Enabling Tracing in a Session After a Login -Trigger
- How to trace the Oracle optimizer's execution path using 10053
- How to Generating Automatic Oracle Error Traces
- How to Tracing a Background Process
- How to Enabling Oracle Listener Tracing
- How to Setting Archive Tracing for Data Guard
Oracle provides the TKPROF utility as well as the freely downloadable profiler named Oracle Trace Analyzer.
how to use both of these profilers to analyze the raw trace files you generate.
Preparing Your Environment before starting tracing
1. Enable timed statistics collection.
2. Specify a destination for the trace dump file.
3. Adjust the trace dump file size.
sho parameter statistics
NAME TYPE VALUE
------------------------------------ ----------- -----------
statistics_level string TYPICAL
timed_statistics boolean TRUE
SQL> alter system set timed_statistics=true scope=both;
System altered.
You can also set this parameter at the session level with the following statement:
SQL> alter session set timed_statistics=true;
You can find the location of the trace directory with the following command:
SQL> select name,value from v$diag_info where name='Diag Trace'
NAME VALUE
----------------------------- ----------------------------------------
Diag Trace c:\app\ora\diag\rdbms\orcl1\orcl1\trace
EX : <diagnostic_dest>/diag/rdbms/<dbname>/<instance>/trace
The default value of the max_dump_file_size parameter is unlimited to verify :
SQL> sho parameter dump
NAME TYPE VALUE
------------------------------------ ----------- ----------
...
max_dump_file_size string unlimited
An unlimited dump file size means that the file can grow as large as the operating system permits.
3. How to Finding the Trace Files (doubt still )
1. How to trace a Specific SQL statement
Trace a specific SQL statement, in order to find out where the database is spending its time during the
execution of the statement.
how to trace a SQL statement as a one-off operation
1. Issue the alter session set events statement, as shown here, to set up the trace.
SQL> alter session set events 'sql_trace level 12';
2. Execute the SQL statements.
SQL> select count(*) from sales;
3. Set tracing off.
SQL> alter session set events 'sql_trace off';
To trace specific SQL statements by specifying the SQL ID of a statement
1. Find the SQL ID of the SQL statement by issuing this statement:
SQL> select sql_id,sql_text from v$sql where sql_text='select sum(quantity_sold) from sales';
SQL_ID SQL_TEXT
---------------- ------------------------------------
fb2yu0p1kgvhr select sum(quantity_sold) from sales
2. Set tracing on for the specific SQL statement whose SQL ID you’ve retrieved.
SQL> alter session set events 'sql_trace [sql:fb2yu0p1kgvhr] level 12';
3. Execute the SQL statement.
SQL> select sum(quantity_sold) from sales;
SUM(QUANTITY_SOLD)
------------------
918843
4. Turn off tracing.
SQL> alter session set events 'sql_trace[sql:fb2yu0p1kgvhr] off';
Session altered.
You can trace multiple SQL statements by separating the SQL IDs with the pipe (|) character
Note: Even if you execute multiple SQL statements before you turn the tracing off, the trace file will show just the information pertaining to the SQL_ID or SQL_IDs you specify.
SQL> alter session set events ‘sql_trace [sql: fb2yu0p1kgvhr|4v433su9vvzsw]‘;
You can trace a specific SQL statement running in a different session and other session completes executing the SQL statement, turn off tracing with the following command:
SQL> alter system set events 'sql_trace[sql:fb2yu0p1kgvhr] level 12';
after completed in the other session we can turn it off...
SQL> alter system set events 'sql_trace[sql:fb2yu0p1kgvhr] off';
2. How to Enabling Tracing in Your Own Session
Ordinary users can use the DBMS_SESSION package to trace their own sessions
SQL>execute dbms_session.session_trace_enable(waits=>true, binds=> false);
To disable tracing, the user must execute the session_trace_disable procedure
SQL> execute dbms_session.session_trace_disable();
The DBMS_MONITOR package, which Oracle recommends for all tracing, is by default executable only by a user with the DBA role.
3. How to Finding the Trace Files (doubt still )
To set an identifier for your trace files, before you start generating the trace:
SQL> alter session set tracefile_identifier='MyTune1';
To view the most recent trace files the database has created
adrci> show tracefile -t
05-NOV-13 11:44:54 diag/rdbms/orcl/orcl/trace/orcl_ckpt_3047.trc
05-NOV-13 11:50:06 diag/rdbms/orcl/orcl/trace/alert_orcl.log
To find out the path to your current session’s trace file
SQL> select value from v$diag_info where name = 'Default Trace File';
VALUE
-------------------------------------------------------------
/u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_4287.trc
To find all trace files for the current instance
SQL> select value from v$diag_info where name = 'Diag Trace'
4. How to Examining a Raw SQL Trace File
Open the trace file in a text editor to inspect the tracing information. Here are portions of a raw SQL trace generated by executing the dbms_monitor.session_trace_enable procedure:
PARSING IN CURSOR #3 len=490 dep=1 uid=85 oct=3 lid=85 tim=269523043683 hv=672110367
ad='7ff18986250' sqlid='bqasjasn0z5sz'
PARSE #3:c=0,e=647,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=1,plh=0,tim=269523043680
EXEC #3:c=0,e=1749,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=1,plh=3969568374,tim=269523045613
WAIT #3: nam='Disk file operations I/O' ela= 15833 FileOperation=2 fileno=4 filetype=2 obj#=-1
tim=269523061555
FETCH #3:c=0,e=19196,p=0,cr=46,cu=0,mis=0,r=1,dep=1,og=1,plh=3969568374,tim=269523064866
STAT #3 id=3 cnt=12 pid=2 pos=1 obj=0 op='HASH GROUP BY (cr=46 pr=0 pw=0 time=11 us cost=4 size=5317
card=409)'
STAT #3 id=4 cnt=3424 pid=3 pos=1 obj=89079 op='TABLE ACCESS FULL DEPT (cr=16 pr=0 pw=0 time=246 us
cost=3 size=4251 card=327)'
As you can see from this excerpt of the raw trace file, you can glean useful information, such as parse misses, waits, and the execution plan of the SQL statement.
Parse: During this stage, the database converts the SQL statement into an execution plan
and checks for authorization and the existence of tables and other objects.
Execute: The database executes the SQL statement during this phase. For a SELECT
statement, the execute phase identifies the rows the database must retrieve. The database
modifies the data for DML statements such as insert, update, and delete.
Fetch: This step applies only for a SELECT statement. During this phase, the database
retrieves the selected rows.
5. How to Analyzing Oracle Trace Files
There are multiple ways to interpret a SQL trace file.
• Read the raw SQL trace file in a text editor.
• Use the Oracle-provided TKPROF (Trace Kernel Profiler) utility.
• Use Oracle Trace Analyzer, a free product you can download from Oracle Support.
• Use third-party tools.
6. How to Formatting Trace Files with TKPROF
TKPROF utility from the command line. Here’s an example of a typical tkprof command for formatting
a trace file.
$ tkprof user_sql_001.trc user1.prf explain=hr/hr table=hr.temp_plan_table_a sys=no
sort=exeela,prsela,fchela
trace file as input : user_sql_001.trc
output file named : user1.prf.
$ tkprof
Usage: tkprof tracefile outputfile [explain= ] [table= ]
[print= ] [insert= ] [sys= ] [sort= ]
filename1: Specifies the name of the trace file
filename2: Specifies the formatted output file
waits: Specifies whether the output file should record a summary of the wait events; default is yes.
sort: By default, TKPROF lists the SQL statements in the trace file in the order they were executed. You can specify various options with the sort argument to control the order in which TKPROF lists the various SQL statements.
• prscpu: CPU time spent parsing
• prsela: Elapsed time spent parsing
• execpu: CPU time spent executing
• exeela: Elapsed time spent executing
• fchela: Elapsed time spent fetching
print: By default TKPROF will list all traced SQL statements. By specifying a value for the print option, you can limit the number of SQL statements listed in the output file.
sys: By default TKPROF lists all SQL statements issued by the user SYS, as well as recursive statements. Specify the value no for the sys argument to make TKPROF omit these statements.
explain: Writes execution plans to the output file; TKPROF connects to the database and issues explain plan statements using the username and password you provide with this parameter.
table: By default, TKPROF uses a table named PLAN_TABLE in the schema of the user specified by the explain parameter, to store the execution plans. You can specify an alternate table with the table parameter.
width: This is an integer that determines the output line widths of some types of output, such as the explain plan information.
7.How to Analyzing TKPROF Output
format a trace file with TKPROF, and you now want to analyze the TKPROF output file
c:\>tkprof orcl1_ora_6448_mytrace1.trc ora6448.prf explain=hr/hr sys=no sort=prsela,exeela,fchela
orcl1_ora_6448_mytrace1.trc ---> trace file name
ora6448.prf --- > output file
Information we can view in tkprof
1.Header
2.Execution Statistics
3.Row Source Operations
4.The Execution Plan
5.Wait Events
8. How to Analyzing Trace Files with Oracle Trace Analyzer
The Oracle Trace Analyzer, also known as TRCANLZR or TRCA, is a SQL trace profiling tool that’s an alternative to the TKPROF utility. You must download the TRCA from Oracle Support. Once you download TRCA, unzip the files and install TRCA by executing the /trca/install/trcreate.sql script.
you must log in as a user with the SYSDBA privilege to execute the tacreate.sql script.
The tacreate.sql generates the formatted output files for any traces you’ve generated.
The script asks you for information relating to the location of the trace files, the output file, and the tablespace where you want TRCA to store its data.
1. Installing TRCA is straightforward,
SQL> @tacreate.sql
Uninstalling TRCA, please wait
TADOBJ completed.
SQL>
SQL> WHENEVER SQLERROR EXIT SQL.SQLCODE;
SQL> REM If this DROP USER command fails that means a session is connected with this user.
SQL> DROP USER trcanlzr CASCADE;
SQL> WHENEVER SQLERROR CONTINUE;
SQL>
SQL> SET ECHO OFF;
TADUSR completed.
TADROP completed.
Creating TRCA$ INPUT/BDUMP/STAGE Server Directories
...
TACREATE completed. Installation completed successfully.
SQL>
2. Set up tracing.
SQL> alter session set events '10046 trace name context forever, level 12';
System altered.
3. Execute the SQL statement you want to trace.
SQL> select ...
4. Turn off tracing.
SQL> alter session set events '10046 trace name context off';
System altered.
5. Run the /trca/run/trcanlzr script (START trcanlzr.sql) to profile the trace you’ve just generated. You must pass the trace file name as input to this script:
c:\trace\trca\trca\run>sqlplus hr/hr
SQL> START trcanlzr.sql orcl1_ora_7460_mytrace7.trc
Parameter 1:
Trace Filename or control_file.txt (required)
Value passed to trcanlzr.sql:
TRACE_FILENAME: orcl1_ora_7460_mytrace7.trc
Analyzing orcl1_ora_7460_mytrace7.trc
... analyzing trace(s) ...
Trace Analyzer completed.
Review first trcanlzr_error.log file for possible fatal errors.
...
233387 08/14/2013 15:59 trca_e21106.html
115885 08/14/2013 15:59 trca_e21106.txt
File trca_e21106.zip has been created
TRCANLZR completed.
SQL>
c:\trace\trca\trca\run>
You can now view the profiled trace data in text or HTML format—TRCA provides both of these in the ZIP file that it creates when it completes profiling the trace file. TRCA places the ZIP file in the directory from which you run the /trca/run/trcanlzr.sql script.
Here are the major sections of a TRCA report, and as you can see already, the report offers a richer set of
diagnostic information than that offered by TKPROF.
Summary: Provides a breakdown of elapsed time, response time broken down into CPU and non-idle wait time, and other response time-related information
Non-Recursive Time and Totals: Provides a breakdown of response time and elapsed time during the parse, execute, and fetch steps; the report also contains a table that provides total and average waits for each idle and non-idle wait event.
Top SQL: Provides detailed information about SQL statements that account for the most response time, elapsed time, and CPU time, as shown in the following extract from the report:
There are 2 SQL statements with "Response Time Accounted-for" larger than threshold of 10.0% of the "Total Response Time Accounted-for". These combined 2 SQL statements are responsible for a total of 99.3% of the "Total Response Time Accounted-for".
There are 3 SQL statements with "Elapsed Time" larger than threshold of 10.0% of the "Total Elapsed Time". These combined 3 SQL statements are responsible for a total of 75.5% of the "Total Elapsed Time".
There is only one SQL statement with "CPU Time" larger than threshold of 10.0% of the "Total CPU Time".
Individual SQL: This is a highly useful section, as it lists all SQL statements and shows their elapsed time, response time, and CPU time. It provides the hash values and SQL IDs of each statement.
SQL Self - Time, Totals, Waits, Binds and Row Source Plan: Shows parse, execute, and fetch statistics for each statement, similar to the TKPROF utility; it also shows the wait event
breakdown (average and total times) for each statement. There’s also a very nice explain
plan for each statement, which shows the time and the cost of each execution step.
Tables and Indexes: Shows the number of rows, partitioning status, the sample size, and the last time the object was analyzed; for indexes, it additionally shows the clustering factor and the number of keys.
Summary: Shows I/O related wait (such as the db file sequential read event) information including average and total waits, for tables and indexes
Hot I/O Blocks: Shows the list of blocks with the largest wait time or times waited Non-default Initialization Parameters: Lists all non-default initialization parameters
As this brief review of TRCA shows, it’s a far superior tool than TKPROF. Besides, if you happen to love TKPROF reports, it includes them as well in its ZIP file. So, what are you waiting for? Download the TRCA and benefit from its rich diagnostic profiling of problem SQL statements.
9. How to trace a parallel queries (and consolidate them )
You can get an event 10046 trace for a parallel query in the same way as you would for any other query.The only difference is that the 10046 event will generate as many trace files as the number of parallel query servers.
SQL>alter session set tracefile_identifier='MyTrace1';
SQL> alter session set events '10046 trace name context forever, level 12';
SQL> select /*+ full(sales) parallel (sales 6) */ count(quantity_sold) from sales;
COUNT(QUANTITY_SOLD)
--------------------
918843
SQL> alter session set events '10046 trace name context off';
Session altered.
You’ll now see a total of seven trace files with the trace file identifier MyTrace1 in the trace directory. Depending on what you’re looking for, you can analyze each of the trace files separately or consolidate them into one big trace file with the trcsess utility before analyzing it with TKPROF or another profiler such as the Oracle Trace Analyzer. You’ll also find several files with the suffix .trm in the trace directory—you can ignore these files, as they are for use by the database.
Once you turn off the trace, go to the trace directory and execute the following command to find all the trace files for the parallel query:
$ find . -name '*MyTrace1*'
The find command lists all the trace files for your parallel query (ignore the files ending with .trm in the tracedirectory). You can move the trace files to another directory and use the trcsess utility to consolidate those files, as shown here:
$ trcsess output=MyTrace1.trc clientid='px_test1' orcl1_ora_8432_mytrace1.trc orcl1_ora_8432_
mytrace2.trc
10. How to trace Specific Parallel Query Processes
To trace one or more specific parallel query processes.
Identify the parallel query processes you want to trace with the following command.
SQL> select inst_id,p.server_name,
p.status as p_status,
p.pid as p_pid,
p.sid as p_sid
from gv$px_process p
order by p.server_name;
Let’s say you decide to trace the processes p002 and p003. Issue the following alter system set events
command to trace just these two parallel processes.
SQL> alter system set events ‘sql_trace {process: pname = p002 | p003}’;
Once you’re done tracing, turn off the trace by issuing the following command:
SQL> alter system set events ‘sql_trace {process: pname = p002 | p003} off’;
11.How to Trace Parallel Queries in a RAC System
To tracing a parallel query in a RAC environment but aren’t sure in which instance the trace files are located
Finding the trace files for the server (or thread or slave) processes is sometimes difficult in a RAC environment, because you aren’t sure on which node or node(s) the database has created the trace files. Here are the steps to follow to make it easier to find the trace files on the different nodes.
1. Set the px_trace with an alter session command, to help identify the trace files, as shown here:
SQL> alter session set tracefile_identifier='10046';
SQL> alter session set "_px_trace" = low , messaging;
SQL> alter session set events '10046 trace name context forever,level 12';
2. Execute your parallel query. --- this is sample parallel query
SQL> alter table bigsales (parallel 4);
SQL> select count(*) from bigsales;
3. Turn all tracing off.
SQL> alter session set events '10046 trace name context off';
SQL> alter session set "_px_trace" = none;
Specifying px_trace will cause the query coordinator’s trace file to include information about the slave processes that are part of the query and the instance each slave process belongs to. You can then retrieve the trace files from the instances listed in the query coordinator’s trace file.
The _px_trace (px trace) parameter is an undocumented, internal Oracle parameter that has existed since the 9.2 release. Once you run the trace commands as shown in the “Solution” section of this recipe, the trace file for the query coordinator (QC) process will show within it the name of each of the slave processes and the instances the processes have run on—for example:
Acquired 4 slaves on 1 instances avg height=4 in 1 set q serial:2049
P000 inst 1 spid 7512
P001 inst 1 spid 4088
P002 inst 1 spid 7340
P003 inst 1 spid 9256
In this case, you know that Instance 1 is where you must look to get the trace files for the slave processes P000,P001, P002, and P003. On Instance 1, in the ADR trace subdirectory, look for file names that contain the words P000 (or P001/P002/P003), to identify the correct trace files.
12.How to Consolidating Multiple Trace Files
You have generated multiple trace files for a session in order to tune performance, and you want to consolidate those files into a single trace file.
Use the trcsess command to merge multiple trace files into a single trace file. Here’s a simple example:
c:\trace> trcsess output=combined.trc session=196.614 orcl1_ora_8432_mytrace1.trc orcl1_ora_8432_
mytrace2.trc
The trcsess command shown here combines two trace files generated for a session into a single trace file. The session parameter identifies the session with a session identifier, consisting of the session index and session serial number, which you can get from the V$SESSION view.
The trcsess utility is part of the Oracle database and helps by letting you consolidate multiple trace files during performance tuning and debugging exercises. Here’s the syntax of the trcsess command:
trcsess [output=output_file_name]
[session=session_id]
[client_id=cleint_id]
[service=service_name]
[action=action_name]
[module=module_name]
[trace_files]
$ trcsess output=main.trc session=196.614
In our example, we specified the name of the consolidated trace file with the output option. If you don’t specify the output option, trcsess prints the output to standard out. Once you use trcsess to combine the output of multiple trace files into one consolidated file, you can use the TKPROF utility to analyze the file, just as you’d do in the case of a single trace file.
13. How to Find the Correct Session for Tracing
To initiate a session trace for a user from your own session, and you would like to find out the correct session to trace.
You must have the SID and the serial number for the user whose session you want to trace. You can find these from the V$SESSION view, of course, once you know the user’s name. However, you must get several other details about the user’s session to identify the correct session, since the user may have multiple sessions open. Use the following query to get the user’s information:
SQL> select a.sid, a.serial#, b.spid, b.pid,
a.username, a.osuser, a.machine
from
v$session a,
v$process b
where a.username IS NOT NULL
and a.paddr=b.addr;
The query provides several attributes such as USERNAME, OSUSER, and MACHINE, which help you unambiguously select the correct session.
You can’t always rely on the first set of SID and serial number you manage to find for the user whose session you want to trace. Together, the SID and serial number uniquely identify a session. However, you may find multiple SID and serial number combinations for the same user, because your database may be using common user logins. Therefore, querying the V$SESSION view for other information such as OSUSER and MACHINE besides the SID and serial number helps to identify the correct user session.
V$SESSION view columns such as COMMAND, SERVER, LOGON_TIME, PROGRAM, and LAST_CALL_ET help identify the correct session to trace. The LAST_CALL_ET column stands for Elasped Time of the Last Call, and following is how Oracle documentation describes this column:
• If the session STATUS is currently ACTIVE, then the value represents the elapsed time (in
seconds) since the session has become active.
• If the session STATUS is currently INACTIVE, then the value represents the elapsed time (in
seconds) since the session has become inactive.
If you still can’t find the correct session, you may want to join the V$SESSION and V$SQLAREA views to identify the correct session.
14.How to trace a SQL Session
Note:SQL tracing does impose an overhead on the database—you need to be very selective in tracing sessions in a production environment, as a trace can fill up a disk or affect CPU usage adversely.
To turn on SQL tracing for a session to diagnose a performance problem.
There are multiple ways to trace a session, but the Oracle-recommended approach is to use the DBMS_MONITOR package to access the SQL tracing facility. To trace a session, first identify the session using the SQL statement shown point 13
Once you get the SID and SERIAL# from the query shown in Recipe 10-14, invoke the session_trace_enable procedure of the DBMS_MONITOR package, as shown here:
SQL> execute dbms_monitor.session_trace_enable(session_id=>138,serial_num=>242, waits=>true,binds=>false);
In this example, we chose to trace the wait information as well, but it’s optional. Once you execute this command have the user execute the SQL statements that you’re testing (in a dev or test environment). In a production environment, wait for a long enough period to make sure you’ve captured the execution of the SQL statements, before turning the tracing off. Invoke the session_trace_disable procedure to disable the SQL tracing for the session, as shown here:
SQL> execute dbms_monitor.session_trace_disable(138,242);
PL/SQL procedure successfully completed.
Once you complete tracing the session activity, you can get the trace file for the session from the trace directory and use the TKPROF utility (or a different profiler) to get a report. To trace the current user session, use the following pair of commands:
SQL> execute dbms_monitor.session_trace_enable();
SQL> execute dbms_monitor.session_trace_disable();
Tracing an entire session is expensive in terms of resource usage and you must do so only when you haven't identifieda poorly performing SQL statement already. A session trace gathers the following types of information.
• Physical and logical reads for each statement that's running in the session
• CPU and elapsed times
• Number of rows processed by each statement
• Misses in the library cache
• Number of commits and rollbacks
• Row operations that show the actual execution plan for each statement
• Wait events for each SQL statement
You can specify the following parameters for the session_trace_enable procedure:
session_id: Identifies the session you want to trace (SID); if you omit this, your own session will be traced.
serial_num: Serial number for the session
waits: Set it to true if you want to capture wait information (default = false).
binds: Set it to true to capture bind information (default=false).
plan_stat: Determines the frequency with which the row source statistics (execution plan and execution statistics) are dumped
All the parameters for the session_trace_enable procedure are self-evident, except the plan_stat parameter.
You can set the following values for this parameter:
never: The trace file won’t contain any information about row source operations.
first_execution (same as setting the plan_stat parameter to the value null): Row source information is written once, after the first execution of a statement.
all_executions: Execution plan and execution statistics are written for each execution of the cursor, instead of only when the cursor is closed.
Since an execution plan for a statement can change during the course of a program run, you may want to set the plan_stat parameter to the value all_executions if you want to capture all possible execution plans for a statement.
15. How to trace a Session by Process ID
To identify and trace a session using an operating system process ID.
Execute the alter session (or alter system) set events command to trace a session by its operating system
process ID, which is shown by the SPID column in the V$PROCESS view. The general format of this command is as follows:
alter system set events 'sql_trace {process:pid}'
Here are the steps to tracing a session by its OS PID.
1. Get the OS process ID by querying the V$PROCESS view.
SQL> select spid,pname from v$process;
2. Once you identify the SPID of the user, issue the following statement to start the trace for that session:
SQL> alter system set events 'sql_trace {process:2714}';
3. Turn off tracing the following way:
SQL> alter system set events 'sql_trace {process:2714} off';
4. You can also execute the set events command in the following manner, to trace two processes at once:
SQL> alter system set events 'sql_trace {process:2714|2936}';
SQL> alter system set events 'sql_trace {process:2714|2936} off';
When you trace tow processes simultaneously, Oracle generates two separate trace files, one for each process, as shown here:
orcl1_ora_2714.trc
orcl1_ora_2936.trc
How It Works
The alter system set events command allows you to trace a process by specifying the process ID (PID), process name (PNAME), or the Oracle Process ID (ORAPID). Here’s the syntax of the command:
alter session set events ‘sql_trace {process : pid = <pid>, pname = <pname>,
orapid = <orapid>} rest of event specification’
The V$PROCESS view contains information about all currently active processes. In the V$PROCESS view, the following columns help you identify the three process-related values:
PID: the Oracle process identifier
SPID: the Operating System process identifier
PNAME: name of the process
In this recipe, we showed how to generate a trace file using the OS process identifier (SPID column in the
V$PROCESS view). You can use the general syntax shown here to generate a trace using the PID or the process name.
16.How to trace Multiple SQL Sessions belongs to one user
To trace multiple SQL sessions that belong to a single user.
You can trace multiple sessions that belong to a user by using the client_id_trace_enable procedure from the DBMS_MONITOR package. Before you can execute the dbms_monitor.client_id_trace_enable procedure, you must set the client_identifier for the session by using the DBMS_SESSION package, as shown here:
SQL> execute dbms_session.set_identifier('MySQLTune1')
Once you set the client identifier as shown here, the client_identifier column in the V$SESSION view is
populated. You can confirm the value of the client_identifier column by executing the following statement:
SQL> select sid, serial#,username from v$session where client_identifier='MySQLTune1';
Now you can execute the dbms_monitor.client_id_trace_enable procedure:
SQL> execute dbms_monitor.client_id_trace_enable(client_id=>'SH', waits=>true, binds=>false);
You can disable the trace with the following command:
SQL> execute dbms_monitor.client_id_trace_disable(client_id=>'SH');
Setting the client_identifier column lets you enable the tracing of multiple sessions, when several users may be
connecting as the same Oracle user, especially in applications that use connection pools. The client_id_trace_enable procedure collects statistics for all sessions with a specific client ID. Note that the client_id that you must specify doesn’t have to belong to a currently active session. By default, the waits and binds parameters are set to false and you can set the tracing of both waits and binds by adding those parameters when you execute the client_id_ trace_enable procedure:
SQL> exec dbms_monitor.client_id_trace_enable('SH',true,true);
PL/SQL procedure successfully completed.
You can query the DBA_ENABLED_TRACES view to find the status of a trace that you executed with a client identifier. In this view, the column TRACE_TYPE shows the value CLIENT_ID and the PRIMARY_ID shows the value of the client identifier.
SQL> select trace_type, primary_id,waits,binds from dba_enabled_traces;
TRACE_TYPE PRIMARY_ID WAITS BINDS
------------- --------------- -------- --------------
CLIENT_ID SH TRUE TRUE
17.How to Tracing an Instance or a Database
You want to trace the execution of all SQL statements in the entire instance or database.
Use the dbms_monitor.database_trace_enable procedure to trace a specific instance or an entire database.
Issue the following pair of commands to start and stop tracing for an individual instance.
SQL> execute dbms_monitor.database_trace_enable(instance_name=>'instance1');
SQL> execute dbms_monitor.database_trace_disable(instance_name=>'instance1');
You can optionally specify the waits and binds attributes. The following commands enable and disable SQL
tracing at the database level:
SQL> execute dbms_monitor.database_trace_enable();
SQL> execute dbms_monitor.database_trace_disable();
You can also set the sql_trace initialization parameter to true to turn on and turn off SQL tracing, but this
parameter is deprecated. Oracle recommends that you use the dbms_monitor (or the dbms_session) package for SQL tracing.
Obviously, instance-level and database-level SQL tracing is going to impose a serious overhead and may well turn out to be another source of performance problems! It’s possible for background processes to continue writing to their trace files until the trace files reach their maximum size, the directory containing the trace files exhausts all the space allocated to it, or until you bounce the database. This is so because even after you disable this type of tracing, background processes may keep writing to the trace files. You normally don’t ever have to do this—use the session-level tracing instead to identify performance problems. If you must trace an entire instance, because you don’t know from which session a query may be executed, turn off tracing as soon as possible to reduce the overhead.
18. How to Generating an Event 10046 Trace for a Session
level 12: Specifies the trace level—in this case, it captures both bind and wait information.
To get an Oracle event 10046 trace for a session.
You can get an Oracle event 10046 trace, also called an extended trace, by following these steps:
1. Set your trace file identifier.
SQL> alter session set tracefile_identifier='My_Trace';
2. Issue the following statement to start the trace.
SQL> alter session set events '10046 trace name context forever, level 12'
3. Execute the SQL statement(s) that you want to trace.
SQL> select sum(amount_sold) from sales;
4. Turn tracing off with the following command:
SQL> alter session set events '10046 trace name context off';
You’ll find the trace dump file in the trace directory that’s specified by the diagnostic_dest parameter
($DIAG_HOME/rdbms/db/inst/trace). You can analyze this trace file with TKPROF or another utility such as the Oracle Trace Analyzer.
Here’s what the various keywords in the syntax for setting a 10046 trace mean:
set events: Sets a specific Oracle event, in this case, the event 10046
10046: Specifies when an action should be taken
trace: The database must take this action when the event (10046) occurs.
name: Indicates the type of dump or trace
context: Specifies that Oracle should generate a context-specific trace; if you replace context with errorstack, the database will not trace the SQL statement. It dumps the error stack when it hits the 10046 event.
forever: Specifying the keyword forever tells the database to invoke the action (trace) every time the event (10046) is invoked, until you disable the 10046 trace. If you omit the keyword forever, the action is invoked just once, following which the event is automatically disabled.
level 12: Specifies the trace level—in this case, it captures both bind and wait information.
| Level | Description |
|---|---|
| 0 | The debugging event is disabled. |
| 1 | The debugging event is enabled. For each processed database call,
the following information is given: SQL statement, response time,
service time, number of processed rows, number of logical reads, number
of physical reads and writes, execution plan, and little additional
information. Up to 10.2 an execution plan is written to the trace file only when the cursor it is associated with is closed. The execution statistics associated to it are values aggregated over all executions. As of 11.1 an execution plan is written to the trace file only after the first execution of every cursor. The execution statistics associated to it are the ones of the first execution only. |
| 4 | As in level 1, with additional information about bind variables. Mainly, the data type, its precision, and the value used for each execution. |
| 8 | As in level 1, plus detailed information about wait time. For each wait experienced during the processing, the following information is given: the name of the wait event, the duration, and a few additional parameters identifying the resource that has been waited for. |
| 16 | As in level 1, plus the execution plans information is written to the trace file for each execution. Available as of 11.1 only. |
| 32 | As in level 1, but without the execution plans information. Available as of 11.1 only. |
| 64 | As in level 1, plus the execution plans information might be written for executions following the first one. The condition is that, since the last write of execution plans information, a particular cursor consumed at least one additional minute of DB time. This level is interesting in two cases. First, when the information about the first execution is not enough for analysing a specific issue. Second, when the overhead of writing the information about every execution (level 16) is too high. Generally available as of 11.2.0.2 only. |
- Level 12 (4 + 8): simultaneously enable level 4 and level 8.
- Level 28 (4 + 8 + 16): simultaneously enable level 4, level 8 and level 16.
- Level 68 (4 + 64): simultaneously enable level 4 and level 64.
- Level 4: waits=FALSE, binds=TRUE, plan_stat=’first_execution’
- Level 8: waits=TRUE, binds=FALSE, plan_stat=’first_execution’
- Level 16: waits=FALSE, binds=FALSE, plan_stat=’all_executions’
- Level 32: waits=FALSE, binds=FALSE, plan_stat=’never’
- Level 64: not available yet
19.How to Generating an Event 10046 Trace for an Instance
You want to trace a problem SQL query, but you can’t identify the session in advance. You would like to trace all SQL statements executed by the instance.
You can turn on tracing at the instance level with the following alter system command, after connecting to the instance you want to trace.
SQL> alter system set events '10046 trace name context forever,level 12';
The previous command enables the tracing of all sessions that start after you issue the command—it won’t trace sessions that are already connected.
You disable the trace by issuing the following command:
SQL> alter system set events '10046 trace name context off';
This command disables tracing for all sessions.
Instance-wide tracing helps in cases where you know a problem query is running, but there’s no way to identify the session ahead of time. Make sure that you enable instance-wide tracing only when you have no other alternative, and turn it off as soon as you capture the necessary diagnostic information. Any instance-wide tracing is going to not only generate very large trace files in a busy environment but also contribute significantly to the system workload.
As in the case of Recipe 10-18, it’s possible for background processes to continue writing to their trace files until the trace files reach their maximum size, the directory containing the trace files exhausts all the space allocated to it, or until you bounce the database. This is so because even after you disable this type of tracing, background processes may keep writing to the trace files.
20.How to Setting a Trace in a Running Session
You want to set a trace in a session, but the session has already started.
Note: A user who phones to ask for help with a long-running query is a good example of a case in which you might want to initiate a trace in a currently executing session. Some business-intelligence queries, for example, run for dozens of minutes, even hours, so there is time to initiate a trace mid-query and diagnose a performance problem.
You can set a trace in a running session using the operating system process ID (SPID), with the help of the oradebug utility. Once you identify the PID of the session you want to trace, issue the following commands to trace the session.
SQL> connect / as sysdba
SQL> oradebug setospid <SPID>
SQL> oradebug unlimit
SQL> oradebug event 10046 trace name context forever,level 12
SQL> oradebug event 10046 trace name context off
In the example shown here, we specified Level 12, but as with the 10046 trace you set with the alter session
command, you can specify the lower tracing levels 4 or 8.
The oradebug utility comes in handy when you can’t access the session you want to trace, or when the session has already started before you can set tracing. oradebug lets you attach to the session and start the SQL tracing. If you aren’t sure about the operating system PID (or SPID) associated with an Oracle session, you can find it with the following query.
SQL> select p.PID,p.SPID,s.SID
from v$process p,v$session s
where s.paddr = p.addr
and s.sid = &SESSION_ID
oradebug is only a facility that allows you to set tracing—it’s not a tracing procedure by itself. The results of the 10046 trace you obtain with oradebug are identical to those you obtain with a normal event 10046 trace command.
In the example shown in the “Solution” section, we use the OS PID of the Oracle users. You can also specify the Oracle Process Identifier (PID) to trace a session instead of the OS PID.
SQL> connect / as sysdba
SQL> oradebug setorapid 9834
SQL> oradebug unlimit
SQL> oradebug event 10046 trace name context forever,level 12
In an Oracle RAC environment, as is the case with all other types of Oracle tracing, make sure you connect to the correct instance before starting the trace. As an alternative to using oradebug, you can use the dbms_system.set_sql_trace_in_session procedure to set a trace in a running session. Note that DBMS_SYSTEM is an older package, and the recommended way to trace sessions starting with the Oracle Database 10g release is to use the DBMS_MONITOR package.
21.How to Enabling Tracing in a Session After a Login -- trigger
want to trace a user’s session, but that session starts executing queries immediately after it logs in.
If a session immediately begins executing a query after it logs in, it doesn’t give you enough time to get the session information and start tracing the session. In cases like this, you can create a logon trigger that automatically starts tracing the session once the session starts. Here is one way to create a logon trigger to set up a trace for sessions created by a specific user:
SQL> create or replace trigger trace_my_user
after logon on database
begin
if user='SH' then
dbms_monitor.session_trace_enable(null,null,true,true);
end if;
end;
SQL> /
Trigger created.
Often, you find it hard to trace session activity because the session already starts executing statements before you can set up the trace. This is especially so in a RAC environment, where it is harder for the DBA to identify the instance and quickly set up tracing for a running session. A logon trigger is the perfect solution for such cases. Note that in a RAC environment, the database generates the trace files in the trace directory of the instance to which a user connected. A logon trigger for tracing sessions is useful for tracing SQL statements issued by a specific user, by setting the trace as soon as the user logs in. From that point on, the database traces all SQL statements issued by that user. Make sure you disable the tracing and drop the logon trigger once you complete tracing the SQL statements you are interested in. Remember to revoke the alter session privilege from the user as well.
22. How to trace the Oracle optimizer's execution path using 10053
You want to trace the cost-based optimizer (CBO) to examine the execution path for a SQL statement.
You can trace the optimizer’s execution path by setting the Oracle event 10053. Here are the steps.
1. Set the trace identifier for the trace file.
SQL> alter session set tracefile_identifier='10053_trace1'
Session altered.
2. Issue the alter session set events statement to start the trace.
SQL> alter session set events '10053 trace name context forever,level 1';
Session altered.
3. Execute the SQL statement whose execution path you want to trace.
SQL> select * from users
2 where user_id=88 and
3 account_status='OPEN'
4 and username='SH';
...
4. Turn the tracing off.
SQL> alter session set events '10053 trace name context off';
Session altered.
You can examine the raw trace file directly to learn how the optimizer went about its business in selecting
the execution plan for the SQL statement.
An event 10053 trace gives you insight into the way the optimizer does its job in selecting what it estimates to be the optimal execution plan for a SQL statement. For example, you may wonder why the optimizer didn’t use an index in a specific case—the event 10053 trace shows you the logic used by the optimizer in skipping that index. The optimizer considers the available statistics for all objects in the query and evaluates various join orders and access paths. The event 10053 trace also reveals all the evaluations performed by the optimizer and how it arrived at the best join order and the best access path to use in executing a query.
You can set either Level 1 or Level 2 for the event 10053 trace. Level 2 captures the following types of information:
• Column statistics
• Single access paths
• Table joins considered by the optimizer
• Join costs
• Join methods considered by the optimizer
A Level 1 trace includes all the foregoing, plus a listing of all the default initialization parameters used by the
optimizer. You’ll also find detailed index statistics used by the optimizer in determining the best execution plan. The trace file captures the amazing array of statistics considered by the cost optimizer and explains how the CBO creates the execution plan. Here are some of the important things you’ll find in the CBO trace file.
• List of all internal optimizer-related initialization parameters
• Peeked values of the binds in the SQL statement
• Final query after optimizer transformations
• System statistics (CPUSPEEDNW, IOTFRSPEED, IOSEEKTIM, MBRC)
• Access path analysis for all objects in the query
• Join order evaluation
Unlike a raw 10046 event trace file, a 10053 event trace file is quite easy (and interesting) to read. You must
understand here that a 10053 trace will be generated only when a hard parse is required. Bear in mind that the trace files might at times be hard to follow when several tables with multiple indexes are analyzed during optimization. Also, the contents of a 10053 event trace file are subject to change from one Oracle Database release to the next.
Here are key excerpts from our trace file. The trace file shows the cost-based query transformations applied by the optimizer:
OBYE: Considering Order-by Elimination from view SEL$1 (#0)
OBYE: OBYE performed.
In this case, the optimizer eliminated the order by clause in our SQL statement. After performing all its
transformations, the optimizer arrives at the “final query after transformations,” which is shown here:
select channel_id,count(*)
from sh.sales
group by channel_id
Next, the output file shows the access path analysis for each of the tables in your query.
Access path analysis for SALES
***************************************
SINGLE TABLE ACCESS PATH
Single Table Cardinality Estimation for SALES[SALES]
Table: SALES Alias: SALES
Card: Original: 918843.000000 Rounded: 918843 Computed: 918843.00 Non Adjusted: 918843.00
Access Path: TableScan
Cost: 495.47 Resp: 495.47 Degree: 0
Cost_io: 481.00 Cost_cpu: 205554857
Resp_io: 481.00 Resp_cpu: 205554857
Access Path: index (index (FFS))
Index: SALES_CHANNEL_BIX
resc_io: 42.30 resc_cpu: 312277
ix_sel: 0.000000 ix_sel_with_filters: 1.000000
Access Path: index (FFS)
Cost: 42.32 Resp: 42.32 Degree: 1
Cost_io: 42.30 Cost_cpu: 312277
Resp_io: 42.30 Resp_cpu: 312277
****** trying bitmap/domain indexes ******
Access Path: index (FullScan)
Index: SALES_CHANNEL_BIX
resc_io: 75.00 resc_cpu: 552508
ix_sel: 1.000000 ix_sel_with_filters: 1.000000
Cost: 75.04 Resp: 75.04 Degree: 0
Access Path: index (FullScan)
Index: SALES_CHANNEL_BIX
resc_io: 75.00 resc_cpu: 552508
ix_sel: 1.000000 ix_sel_with_filters: 1.000000
Cost: 75.04 Resp: 75.04 Degree: 0
Bitmap nodes:
Used SALES_CHANNEL_BIX
Cost = 75.038890, sel = 1.000000
Access path: Bitmap index - accepted
Cost: 75.038890 Cost_io: 75.000000 Cost_cpu: 552508.000000 Sel: 1.000000
Believed to be index-only
******** Begin index join costing ********
******** End index join costing ********
Best:: AccessPath: IndexFFS
Index: SALES_CHANNEL_BIX
Cost: 42.32 Degree: 1 Resp: 42.32 Card: 918843.00 Bytes: 0
In this case, the optimizer evaluates various access paths and shows the optimal access path as an Index Fast
Full Scan (IndexFFS).
The optimizer then considers various permutations of join orders and estimates the cost for each join order it
considers:
Considering cardinality-based initial join order.
Join order[1]: SALES[SALES]#0
GROUP BY sort
GROUP BY adjustment factor: 1.000000
Total IO sort cost: 0 Total CPU sort cost: 834280255
Best so far: Table#: 0 cost: 101.0459 card: 918843.0000 bytes: 2756529
Number of join permutations tried: 1
GROUP BY adjustment factor: 1.000000
GROUP BY cardinality: 4.000000, TABLE cardinality: 918843.000000
Total IO sort cost: 0 Total CPU sort cost: 834280255
Best join order: 1
Cost: 101.0459 Degree: 1 Card: 918843.0000 Bytes: 2756529
As our brief review of the 10053 trace output shows, you can get answers to puzzling questions such as
why exactly the optimizer chose a certain join order or an access path, and why it ignored an index. The answers are
all there!
23. How to Generating Automatic Oracle Error Traces
You want to create an automatic error dump file when a specific Oracle error occurs
You can create error dumps to diagnose various problems in the database by specifying the error number in a hanganalyze or systemstate command. For example, diagnosing the causes for deadlocks is often tricky. You can ask the database to dump a trace file when it hits the ORA-00060: Deadlock detected error. To do this, specify the event number 60 with the hanganalyze or the systemstate command:
SQL> alter session set events '60 trace name hanganalyze level 4';
Session altered.
SQL> alter session set events '60 trace name systemstate level 266';
Session altered.
Both of these commands will trigger the automatic dumping of diagnostic data when the database next
encounters the ORA-00060 error. You can use the same technique in an Oracle RAC database. For example, you can issue the following command to generate automatic hanganalyze dumps:
SQL>alter session set events '60 trace name hanganalyze_global level 4';
This alter session statement invokes the hanganalyze command in any instance in which the database
encounters the ORA-00060 error.
Although we showed how to set the error trace event at the session level, it would be better, for some hard to- catch unfortunate conditions, to set this trace event at the system level. It isn’t always easy to reproduce a problem in one's session
Setting event numbers for an error will ensure that when the specified error occurs the next time, Oracle automatically dumps the error information for you. This comes in very handy when you’re diagnosing an error that occurs occasionally and getting a current systemstate dump or a hanganalyze dump is unhelpful. Some events such as deadlocks have a text alias, in which case you can specify the alias instead of the error number. For the ORA-00060 error, the text alias is deadlock, and so you can issue the following command for tracing the error:
SQL> alter session set events 'deadlock trace name systemstate level 266';
Session altered.
24.How to Tracing a Background Process
25.How to Enabling Oracle Listener Tracing
26. How to Setting Archive Tracing for Data Guard
