Tools to analyse trace files
Up to and including Oracle 10g the tool that is generally used to analyse trace files is called tkprof. This tool formats the trace files that have been generated into a more readable format. Understanding the trace file format seems daunting on first inspection. A good source for details on the trace file format is a metalink note 39817.1. In 10g there is a new tool for formatting trace files calledtrcsess. This tool has been designed to deal with the new trace facilities that allow trace to be identified based on client identifier or by a combination of service name / module / action. This allows trace to be completed even if connection pooling and multi-threading is used. An individual client in these circumstances could share many different sessions.
Find out where the trace file will be written to
If the user you are using is not a DBA or to be more specific has not been granted access to the data dictionary view V$PARAMETERthen you will need to use this technique to find out where your trace files are written to:
SQL> set serveroutput on size 1000000 for wra SQL> declare 2 paramname varchar2(256); 3 integerval binary_integer; 4 stringval varchar2(256); 5 paramtype binary_integer; 6 begin 7 paramtype:=dbms_utility.get_parameter_value('user_dump_dest',integerval,stringval); 8 if paramtype=1 then9 dbms_output.put_line(stringval); 10 else 11 dbms_output.put_line(integerval); 12 end if; 13 end; 14 / C:\oracle\admin\sans\udump PL/SQL procedure successfully completed. SQL>
SQL> select name,value2 from v$parameter3 where name='user_dump_dest'; NAME----------------------------------------------------------------VALUE--------------------------------------------------------------------------------user_dump_destC:\oracle\admin\sans\udump SQL> # allow trace files to be created with public permissions_trace_files_public=true# disable this feature:#_trace_files_public=true# or =>_trace_files_public=false SQL> select x.ksppinm name,y.ksppstvl value2 from sys.x$ksppi x,sys.x$ksppcv y3 where x.inst_id=userenv('Instance')4 and y.inst_id=userenv('Instance')5 and x.indx=y.indx6 and x.ksppinm='_trace_files_public'; NAME----------------------------------------------------------------VALUE--------------------------------------------------------------------------------_trace_files_publicFALSE SQL> SQL> connect system/manager@sans as sysdbaConnected.SQL> col sid for 999999SQL> col serial# for 999999SQL> col username for a20SQL> col osuser for a20SQL> select s.sid,s.serial#,s.username,s.osuser2 from v$session s,v$process p3 where s.paddr=p.addr; SID SERIAL# USERNAME OSUSER------- ------- -------------------- --------------------1 1 SYSTEM2 1 SYSTEM3 1 SYSTEM4 1 SYSTEM5 1 SYSTEM6 1 SYSTEM7 1 SYSTEM8 1 SYSTEM9 253 SYSTEM ZULIA\pete10 20 SCOTT ZULIA\pete 10 rows selected. SQL>
- Level 0 = No statistics generated
- Level 0 = No statistics generated
- Level 1 = standard trace output including parsing, executes and fetches plus more.
- Level 1 = standard trace output including parsing, executes and fetches plus more.
- Level 2 = Same as level 1.
- Level 2 = Same as level 1.
- Level 4 = Same as level 1 but includes bind information
- Level 4 = Same as level 1 but includes bind information
- Level 8 = Same as level 1 but includes wait's information
- Level 8 = Same as level 1 but includes wait's information
- Level 12 = Same as level 1 but includes binds and waits
- Level 12 = Same as level 1 but includes binds and waits
PL/SQL procedure successfully completed.
SQL> exec dbms_system.set_int_param_in_session(10,20,'max_dump_file_size',2147483647);
PL/SQL procedure successfully completed.
SQL> -- now use standard dbms_support interface
SQL> exec dbms_system.set_sql_trace_in_session(10,20,true);
PL/SQL procedure successfully completed.
SQL> -- execute some code
SQL> exec dbms_system.set_sql_trace_in_session(10,20,false);
PL/SQL procedure successfully completed.
SQL>
SQL> exec dbms_system.set_ev(10,20,10046,8,'');
PL/SQL procedure successfully completed.
SQL> -- execute some code
SQL> exec dbms_system.set_ev(10,20,10046,0,'');
PL/SQL procedure successfully completed.
SQL> -- now do the same with dbms_support
SQL> -- the package has to be installed first - you should ask Oracle first though!
SQL> @%ORACLE_HOME%\rdbms\admin\dbmssupp.sql
Package created.
Package body created.
SQL>
SQL> exec dbms_support.start_trace_in_session(10,20,waits=>true,binds=>false);
PL/SQL procedure successfully completed.
SQL> -- execute some code
SQL> exec dbms_support.stop_trace_in_session(10,20);
PL/SQL procedure successfully completed.
SQL>
SQL> exec dbms_support.start_trace(waits=>true,binds=>false);
PL/SQL procedure successfully completed.
SQL> -- run some code
SQL> exec dbms_support.stop_trace;
PL/SQL procedure successfully completed.
SQL>
SQL> -- in your own session using dbms_session
SQL> exec dbms_session.set_sql_trace(true);
PL/SQL procedure successfully completed.
SQL> -- execut some code
SQL> exec dbms_session.set_sql_trace(false);
PL/SQL procedure successfully completed.
SQL>
SQL> connect system/manager@sans as sysdba
Connected.
SQL> col sid for 999999
SQL> col serial# for 999999
SQL> col spid for a8
SQL> col username for a20
SQL> col osuser for a20
1 select s.sid,s.serial#,p.spid,p.pid,s.username,s.osuser
2 from v$session s,v$process p
3* where s.paddr=p.addr
SQL> /
SID SERIAL# SPID PID USERNAME OSUSER
------- ------- -------- ---------- -------------------- --------------------
1 1 2528 2 SYSTEM
2 1 2536 3 SYSTEM
3 1 2540 4 SYSTEM
4 1 2544 5 SYSTEM
5 1 2552 6 SYSTEM
6 1 2604 7 SYSTEM
7 1 2612 8 SYSTEM
8 1 2652 9 SYSTEM
10 343 3740 12 SYS ZULIA\pete
12 70 864 13 SCOTT ZULIA\pete
10 rows selected.
SQL> -- set the OS PID
SQL> oradebug setospid 864
Windows thread id: 864, image: ORACLE.EXE
SQL> -- or set the Oracle pid
SQL> oradebug setorapid 13
Windows thread id: 864, image: ORACLE.EXE
SQL> -- set the trace file size to unlimitd
SQL> oradebug unlimit
Statement processed.
SQL> -- now turn on trace for SCOTT
SQL> oradebug event 10046 trace name context forever, level 12
Statement processed.
SQL> -- run some queries in another session and then turn trace off
SQL> oradebug event 10046 trace name context off
Statement processed.
sql_trace=true
timed_statistics=true
max_dump_file_size=unlimited
#sql_trace=true
sql_trace=false
# set the event in the init.ora
event = "10046 trace name context forever, level 12"
# to turn off the event simply comment out the line as follows:
# event = "10046 trace name context forever, level 12"
SQL> alter session set sql_trace=true;
Session altered.
SQL> -- execute some code
SQL> alter session set sql_trace=false;
Session altered.
SQL>
SQL> alter session set timed_statistics=true;
Session altered.
SQL> alter session set max_dump_file_size=unlimited;
Session altered.
SQL>
SQL> alter session set events '10046 trace name context forever, level 12';
Session altered.
SQL> -- execute some code
SQL> alter session set events '10046 trace name context off';
Session altered.
SQL>
Connected to:
Personal Oracle9i Release 9.2.0.1.0 - Production
With the Partitioning, OLAP and Oracle Data Mining options
JServer Release 9.2.0.1.0 - Production
SQL> create or replace trigger set_trace after logon on database
2 begin
3 if user not in ('SYS','SYSTEM') then
4 execute immediate 'alter session set timed_statistics=true';
5 execute immediate 'alter session set max_dump_file_size=unlimited';
6 execute immediate 'alter session set sql_trace=true';
7 end if;
8 exception
9 when others then
10 null;
11 end;
12 /
Trigger created.
SQL> sho errors
No errors.
SQL>
SQL> alter system set sql_trace=true scope=spfile;
System altered.
SQL>
SQL> -- to turn it off again do:
SQL> alter system set sql_trace=false scope=spfile
System altered.
SQL>
-- check who has access to dbms_system
who_can_access: Release 1.0.0.0.0 - Production on Fri Feb 27 12:53:24 2004
Copyright (c) 2004 PeteFinnigan.com Limited. All rights reserved.
get user input
NAME OF OBJECT TO CHECK [USER_OBJECTS]: dbms_system
OWNER OF THE OBJECT TO CHECK [USER]: sys
OUTPUT METHOD Screen/File [S]:
FILE NAME FOR OUTPUT [priv.lst]:
OUTPUT DIRECTORY [/tmp]:
Checking object => SYS.DBMS_SYSTEM
====================================================================
Object type is => PACKAGE (TAB)
Privilege => EXECUTE is granted to =>
Role => OEM_MONITOR which is granted to =>
User => SYS
PL/SQL procedure successfully completed.
For updates please visit http://www.petefinnigan.com/tools.htm
SQL>
-- check who has access to dbms_support
who_can_access: Release 1.0.0.0.0 - Production on Fri Feb 27 12:54:29 2004
Copyright (c) 2004 PeteFinnigan.com Limited. All rights reserved.
get user input
NAME OF OBJECT TO CHECK [USER_OBJECTS]: dbms_support
OWNER OF THE OBJECT TO CHECK [USER]: sys
OUTPUT METHOD Screen/File [S]:
FILE NAME FOR OUTPUT [priv.lst]:
OUTPUT DIRECTORY [/tmp]:
Checking object => SYS.DBMS_SUPPORT
====================================================================
PL/SQL procedure successfully completed.
For updates please visit http://www.petefinnigan.com/tools.htm
SQL>
-- check who has access to dbms_session
who_can_access: Release 1.0.0.0.0 - Production on Fri Feb 27 12:55:31 2004
Copyright (c) 2004 PeteFinnigan.com Limited. All rights reserved.
get user input
NAME OF OBJECT TO CHECK [USER_OBJECTS]: dbms_session
OWNER OF THE OBJECT TO CHECK [USER]: sys
OUTPUT METHOD Screen/File [S]:
FILE NAME FOR OUTPUT [priv.lst]:
OUTPUT DIRECTORY [/tmp]:
Checking object => SYS.DBMS_SESSION
====================================================================
Object type is => PACKAGE (TAB)
Privilege => EXECUTE is granted to =>
Role => PUBLIC
PL/SQL procedure successfully completed.
For updates please visit http://www.petefinnigan.com/tools.htm
SQL>
SQL> select s.sid,s.serial#,s.username
2 from v$session s, v$process p
3 where s.paddr=p.addr
SQL> /
...
SID SERIAL# USERNAME
---------- ---------- ------------------------------
248 153 SCOTT
258 61 DBSNMP
251 418 SYSMAN
255 961 SYS
249 215
27 rows selected.
SQL>
SQL> exec dbms_monitor.session_trace_enable(248,153,TRUE,FALSE);
PL/SQL procedure successfully completed.
SQL> -- execute some sql
SQL> -- in the other session
SQL> -- turn trace off
SQL> exec dbms_monitor.session_trace_disable(248,153);
PL/SQL procedure successfully completed.
SQL>
SQL> exec dbms_monitor.session_trace_enable(248);
PL/SQL procedure successfully completed.
SQL> -- execute some sql in the other session
SQL> -- turn off trace
SQL> exec dbms_monitor.session_trace_disable(248);
PL/SQL procedure successfully completed.
SQL> -- or you can turn it on with
SQL> exec dbms_monitor.session_trace_enable(248,null);
PL/SQL procedure successfully completed.
SQL> -- turn off again with:
SQL> exec dbms_monitor.session_trace_disable(248,null);
PL/SQL procedure successfully completed.
SQL>
SQL> -- trace the current session
SQL> exec dbms_monitor.session_trace_enable(null,null);
PL/SQL procedure successfully completed.
SQL> -- execute some code
SQL> -- turn it off again
SQL> exec dbms_monitor.session_trace_disable(null,null);
PL/SQL procedure successfully completed.
SQL> -- to get waits and binds do
SQL> exec dbms_monitor.session_trace_enable(null,null,true,true);
PL/SQL procedure successfully completed.
SQL> -- execute some code
SQL> -- then turn off tracec
SQL> exec dbms_monitor.session_trace_disable(null,null);
PL/SQL procedure successfully completed.
SQL> -- or turn it on like this
SQL> exec dbms_monitor.session_trace_enable();
PL/SQL procedure successfully completed.
SQL> -- execute some SQL and then turn off trace
SQL> exec dbms_monitor.session_trace_disable();
PL/SQL procedure successfully completed.
SQL>
SQL> exec dbms_session.set_identifier('pete id');
PL/SQL procedure successfully completed.
SQL>
SQL> select s.username,s.client_identifier
2 from v$session s,v$process p
3 where s.paddr=p.addr
4 and client_identifier is not null;
USERNAME
------------------------------
CLIENT_IDENTIFIER
----------------------------------------------------------------
SCOTT
pete id
SQL>
SQL> exec dbms_monitor.client_id_trace_enable('pete id',true,false);
PL/SQL procedure successfully completed.
SQL> -- wait for the client session to do something
SQL> -- turn off trace as follows:
SQL> exec dbms_monitor.client_id_trace_disable('pete id');
PL/SQL procedure successfully completed.
SQL>
SQL> exec dbms_service.create_service('Test Service','test network');
PL/SQL procedure successfully completed.
SQL> -- it can be deleted with
SQL> exec dbms_service.delete_service('Test Service');
PL/SQL procedure successfully completed.
SQL>
SQL> -- set action
SQL> exec dbms_application_info.set_action('PAYMENT');
PL/SQL procedure successfully completed.
SQL> -- set the module
SQL> exec dbms_application_info.set_module('ACCOUNTS','PAYMENT');
PL/SQL procedure successfully completed.
SQL>
SQL> col service_name for a15 wrapped
SQL> col username for a15 wrapped
SQL> col module for a15 wrapped
SQL> col action for a15 wrapped
SQL> select s.username,s.service_name,s.module,s.action
2 from v$session s,v$process p
3 where s.paddr=p.addr;
...
USERNAME SERVICE_NAME MODULE ACTION
--------------- --------------- --------------- ---------------
SYSMAN SANS
SYSMAN SANS OEM.SystemPool
DBSNMP SYS$USERS emagent@emil (T
NS V1-V3)
DBSNMP SYS$USERS emagent@emil (T
NS V1-V3)
SYS$USERS
SYS SANS ACCOUNTS PAYMENT
SCOTT SANS SQL*Plus
...
29 rows selected.
SQL>
SQL> -- set trace for all modules and actions for SANS service name
SQL> exec dbms_monitor.serv_mod_act_trace_enable('SANS',DBMS_MONITOR.ALL_MODULES,DBMS_MONITOR.ALL_ACTIONS,TRUE,FALSE,NULL);
PL/SQL procedure successfully completed.
SQL> -- turn it off
SQL> exec dbms_monitor.serv_mod_act_trace_disable('SANS');
PL/SQL procedure successfully completed.
SQL> -- now trace all actions for service SANS and module accounts
SQL> exec dbms_monitor.serv_mod_act_trace_enable('SANS','ACCOUNTS',DBMS_MONITOR.ALL_ACTIONS,TRUE,FALSE,NULL);
PL/SQL procedure successfully completed.
SQL> -- now turn it off
SQL> exec dbms_monitor.serv_mod_act_trace_disable('SANS','ACCOUNTS');
PL/SQL procedure successfully completed.
SQL> -- finally test service SANS, module ACCOUNTS and action PAYMENT
SQL> exec dbms_monitor.serv_mod_act_trace_enable('SANS','ACCOUNTS','PAYMENT',TRUE,FALSE,NULL);
PL/SQL procedure successfully completed.
SQL> -- turn it off
SQL> exec dbms_monitor.serv_mod_act_trace_disable('SANS','ACCOUNTS','PAYMENT');
PL/SQL procedure successfully completed.
SQL> -- you can turn on or off binds and waits as well or use the waits=>true
SQL> -- syntax instead.
SQL>
- set autotrace off - The default - no output
- set autotrace off - The default - no output
- set autotrace on explain - This shows only the optimizer path
- set autotrace on explain - This shows only the optimizer path
- set autotrace on statistics - This only shows SQL statistics
- set autotrace on statistics - This only shows SQL statistics
- set autotrace on - Includes both of the above
- set autotrace on - Includes both of the above
- set autotrace traceonly - As above but the query output is not displayed
- set autotrace traceonly - As above but the query output is not displayed
Session altered.
SQL> -- execute some SQL to create a CBO trace.
SQL> -- turn CBO trace off
SQL> alter session set events '10053 trace name context off';
Session altered.
SQL>
SQL> exec dbms_system.set_bool_param_in_session(10,20,'timed_statistics',true);
SQL> alter session set events '10053 trace name context forever, level 1
If the user you are using has access to the base views then you can do the following instead.
Making trace files available
There is an undocumented parameter _trace_files_public that if set to true changes the file permissions in the user_dump_dest directory when trace files are created to allow everyone to read them. This parameter can be checked with the following SQL. Beware that this is an undocumented parameter and should not be routinely set to true as some information in trace files can be used by hackers or malicious users. You can set this parameter by adding the following line to the init.ora file:
Here is the SQL to check the value of this parameter:
Let's start with some examples of how to check trace for another session that is connected to the database.
Now find the SID and SERIAL# of the other session
We are using a simple example and the session we are looking for is for the user SCOTT and we are logged into this session with AS SYSDBA. We need to be logged in as SYS or AS SYSDBA so that we can access the packages DBMS_SUPPORT and DBMS_SYSTEM needed to set trace in another session or in our own session. Again as with the first example about access to v$parameter a user with access to the views V$SESSION and V$PROCESS is needed. First lets find the SID and SERIAL#
great the SID and SERIAL# that we need are 10 and 20.
A word about trace levels
Before we use the DBMS_SYSTEM package to set trace in SCOTT's session we need to discuss what levels are. Trace in fact sets an event in the Oracle kernel (what is an event? - An event is simply a flag to the Oracle kernel to tell it to emit some trace messages or to add some additional processing or to activate some new functionality. Some events are used by support analysts and developers to force certain conditions to occur for testing purposes). In our case we want to look at event number 10046 - This event tells the Oracle kernel to emit trace lines and timings. The levels available in Oracle through some of the interfaces used to set trace are:
For a complete list of events that can be set look at the file $ORACLE_HOME/rdmbs/mesg/oraus.msg on Unix or Linux. This file is not shipped on Windows systems. Also setting any event other that trace (10046) should not be done without the guidance of Oracle support.
Set trace in another session using DBMS_SYSTEM
First lets set trace in SCOTT's session using the DBMS_SYSTEM package. Before we do let's turn on timed statistics so that the trace files get timing info and also set the dump file size so that there is plenty of room for the trace being generated.
OK, here we set trace in SCOTT's session
A second way to set trace in another session - This time setting trace level as well
Next we can again use the DBMS_SYSTEM interface but this time use the set event syntax. This allows us to set any event in the database. This is of course not sanctioned by Oracle support and can cause damage to your database if not done correctly. Use this interface with care and just set 10046 (trace) events. Here is how it is done:
Installing the DBMS_SUPPORT package
Using the example above we set trace to level 8, you can of course set it to any level you wish from the list we discussed above. Next we will use the DBMS_SUPPORT package to set trace. This package is not installed by default and is in fact undocumented and indeed on some platforms and versions its not even shipped and you will need to talk to Oracle support and get it from metalink. First we will install the package:
Use DBMS_SUPPORT to set trace in another users session
Next use the interface to again set trace for SCOTT's session that we found earlier. here it is:
use DBMS_SUPPORT to set trace in your own session
OK, that's how to set trace in SCOTT's session. How do we set trace in our own session. Well first we can use all of the approaches seen above and pass in the SID and SERIAL# for our own session. There are other methods for setting trace in your own session though. The first is again using the DBMS_SUPPORT package. Here it is:
Use DBMS_SESSION to set trace in your own session
The next method for setting trace in our own session also is done using a built in package, this time DBMS_SESSION. here it is:
using oradebug to set trace through SQL*Plus
oradebug is a debugging utility that is essentially undocumented and is intended for use by Oracle support analysts for various tasks one of which is that it can be used to set trace. oradebug is available from svrmgrl before Oracle 9i and from SQL*Plus after. The first step in using this tool is to find the OS PID or the Oracle PID of the process you want to analyse. You can do this as follows:
Now that we have found the Operating System PID and Oracle PID (values 864 and 13 in this case) of SCOTT's session we can use this to set trace with the oradebug tool as follows:
Some things to be aware of
You should be aware that some of these methods allow setting of extended trace and some do not. Those that allow extended trace are easy to spot. These methods include ways to set the trace level or include variables suitably named such as waits or binds which again enable extended trace facilities. Some trace methods have a default level such as set sql_trace=true which sets trace to level 8. The rest set trace to normal trace levels.
One other point to note is that we have looked first at ways to set trace in another session to the one you are logged into and also now at ways of setting trace in your own session, there is a third option, which is to set trace for the whole system (i.e for all users sessions), This is not recommended unless you know what you are doing and are monitoring trace as you can quickly fill the file system.
Setting trace at the instance level using the init.ora
Trace can be set in the database initialization file the init.ora file. If you use spfile then you can still use the init.ora file and then copy it to the spfile. Simply add the following line to the init.ora file:
You can also set timed_statistics and max_dump_file_size in the init.ora file in the same way. i.e
Trace can also be disabled at the instance level by simply commenting out the same parameter or by deleting it. A commented line is shown next:
Or you can set the same parameter to false:
A second instance level method - setting events
Another method that can be used to set trace at the instance level is to add an event (or multiple events)to the initialization file, theinit.ora as described above. Again if you use spfile's then you can copy the init.ora to spfile or use ALTER SYSTEM to set the value in the spfile. Here is an example of setting the trace event 10046 to level 12 in the initialization file:
Using ALTER SESSION to set trace in your own session
The alter session command can be used to set trace for the current session as follows:
This method can also be used to set timing and dump file size for the current session as follows:
Using ALTER SESSION to set extended trace using events
One last method I want to demonstrate is the alter session syntax to set events. Again stick to 10046 (trace) and do not attempt to set any of the other events that are available without Oracles say so in a supported system. Here is the example of setting trace to level 12, including binds and waits:
A sample logon trigger to set trace
Quite often you would like trace to be set for a session as soon as the user logs on. Also you may want to be able to set trace for a specific set of users when they log in. This can easily be done with a database logon trigger. Here is a sample trigger.
OK, that was easy. You can also use the alter session set events '10046 trace name context forever,level 12' syntax if you prefer You can also enable other checks within the trigger if need by using any valid PL/SQL logic that you prefer. One tip is that if you have any troubles with your system trigger and it causes logins to fail is to always include, as I have, an exception handler that calls null; for any error condition. If all else fails you can disable system triggers by setting the parameter _system_trig_enabled=false in the initialisation file. This undocumented / hidden parameter stops the processing of system triggers such as logon triggers.
Using ALTER SYSTEM to set trace at the instance level
Finally you can also use the alter system syntax to set trace at the system level. Here is a simple example:
Checking the privileges of the packages used to set trace
Some of the packages used in this example have to be run as SYS or you need to be logged in AS SYSDBA or specific privileges need to be granted against those packages for the user that will run them. The default privileges for DBMS_SYSTEM, DBMS_SUPPORT and for DBMS_SESSION are showed next in output from who_can_access.sql (A script that shows privileges hierarchically for an object who's name is passed in). Here they are:
That's it, there are many ways to set trace in your session, in others sessions and at system level. Also many ways to enable extended trace. Beware of the privileges needed to run some of them and beware of setting events explicitly.
New tracing methods in Oracle 10g - DBMS_MONITOR
Oracle 10g offers a new package to allow sessions to be traced end to end in multi-tier architectures that share sessions using connection pooling or multi-threading. This package allows applications written using for instance JDBC / Java or something like Forte to be traced where it would normally be very difficult to identify a database session belonging to a client as the sessions / clients pairings change with time.
The new functionality works in three levels. You can use the old SID / SERIAL# pairings to identify a session but you can also use aclient identifier or a service name / module / action to identify a client session to be traced. The package also offers a set of procedures to allow statistics to be gathered for the same groups. These statistics can then be selected from dynamic views.
let's now take a look at some of the features of this package.
Setting trace with DBMS_MONITOR using SID / SERIAL#
Trace can be set for the current user session, for the current session or for another users session. First lets look at tracing another users session. First we need to get the SID and SERIAL# - we will use SCOTT connected through SQL*Plus as our sample session:
OK as with previous methods we can use a SID / SERIAL# pair of 248 and 153. lets set trace for this user session:
Setting trace at the session level using DBMS_MONITOR
The same procedures can be used to set trace for the session by omitting the serial#. This is demonstrated next:
Setting trace for the current session using DBMS_MONITOR
Setting trace for the current user session is done by leaving out the SID and SERIAL# altogether by setting them to NULL. Here is an example:
That completes some of the ways to use DBMS_MONITOR to set trace using SID, SERIAL#, or at the session level or for the current session.
Set trace using a client identifier
Tracing using the client identifier allows trace to be set across multiple sessions as many Oracle shadow processes can work on behalf of one client. Also trace is persistent across all instances and restarts. First we need to see how the client identifier is set. This can be done using the DBMS_SESSION package as follows:
We can check now for a specific identifier in the V$SESSION view with the client_identifier column.
OK, now we can use this information to set trace for this client identifier as follows:
That was quite easy!. next let's look at setting trace at the service, module action levels.
Setting trace for service/module/action with DBMS_MONITOR
This method of setting trace acts hierarchically. The first level is that trace is set globally for the whole database (all instances) You can override this by setting an instance name in the call to turn on trace. For this example as I am on a single instance database I will leave this parameter at its default. There are three levels to the hierarchy. If we set ACTION to NULL then all actions for the module and service are traced. The next level, if we set MODULE to NULL then all actions for all modules for the specified service name are traced. The trace will be collected into multiple trace files and the new tool trcsess must be used to collate all the trace files into one usable file.
The service name can be set using the package DBMS_SERVICE and the procedure CREATE_SERVICE. Here is an example:
The service name can quite often be set already by the tool. It could be used to group together a set of programs / modules that perform some business task. Next let's see how the module and actions can be set.
To view the relevant service names, modules and actions for sessions in the database you can use the v$SESSION view as follows:
As we deleted our sample service name set up with DBMS_SERVICE.CREATE_SERVICE we will just use the default value SANS inserted by Oracle in our test case. Let's test some of the methods of setting trace with this functionality.
OK, that wraps up the new procedures in 10g that can be used to turn on trace in different ways to capture true end to end trace for multi-tier applications. You should also be aware that DBMS_MONITOR also provides procedures to enable statistic gathering at the same levels of client identifier and service name/module/action. These statistics are stored and can then be accessed by selecting from V$SERV_MOD_ACT_STATS and V$CLIENT_STATS views. I will not detail those procedures here as this short paper is concentrating on trace only.
One last idea - use AUTOTRACE in SQL*Plus
OK, one final way to set and get trace, is to use the SQL*Plus AUTOTRACE facilities. There are a few settings that you can use. These are as follows:
One more final item - CBO trace 10053
One other event that you might like to try and experiment with is the 10053 event. This event traces the Cost Based Optimizer (CBO) and shows all of the plans and costs assigned to them that it tried in its search for the best cost and also is shows how it came to its decision. The 10053 event has two levels 1 and 2. More detail is emitted if level 1 is used rather than level 2. The output is again sent to a trace file in the directory specified by user_dump_dest. The trace is only generated if the SQL is hard parsed and also obviously uses the CBO. To get a trace file you can use any of the methods above that allow the event number to be specified. An example is:
An excellent document describing how to interpret CBO trace files called "A Look under the Hood of CBO - the 10053 Event.pdf" has been written by Wolfgang Breitling of Centrex Consulting Corporation. The URL for Wolfgangs site is http://www.centrexcc.com/papers.html
==============================================================
There are lots of methods to trace oracle sessions.
1. alter session set events ‘10046 trace name context forever,level 12′;
alter session set tracefile_identifier=’10046′;
alter session set timed_statistics = true;
alter session set statistics_level=all;
alter session set max_dump_file_size = unlimited;
Start trace:
alter session set events ‘10046 trace name context forever,level 12′;
Stop trace:
alter session set events ‘10046 trace name context off';
Note: level can be 4,8,12, only trace your own session
2. Using package DBMS_MONITOR
EXECUTE DBMS_MONITOR.SESSION_TRACE_ENABLE(session_id => 27, serial_num => 60,waits => TRUE, binds => TRUE);
EXECUTE DBMS_MONITOR.SESSION_TRACE_DISABLE(session_id => 27, serial_num => 60);
Trace a module:
EXECUTE DBMS_MONITOR.SERV_MOD_ACT_TRACE_ENABLE(
service_name=>'vasont.world', module_name=>'VasontU.exe',
action_name=>DBMS_MONITOR.ALL_ACTIONS,waits=>TRUE,
binds=>TRUE,instance_name=>NULL);
EXECUTE DBMS_MONITOR.SERV_MOD_ACT_TRACE_DISABLE(
service_name=>'vasont.world',module_name=>'VasontU.exe');
Note: not available before 10g, can trace any session
3. Using package DBMS_SESSION
EXECUTE DBMS_SESSION.SESSION_TRACE_ENABLE(waits => TRUE,
binds => TRUE);
EXECUTE DBMS_SESSION.SESSION_TRACE_DISABLE();
Note: only trace your own session
4. Using package DBMS_SYSTEM
execute DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION (sid=>507,
serial#=>4957,sql_trace=>TRUE);
execute DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION (sid=>507,
serial#=>4957,sql_trace=>FALSE);
Note: available in 8i/9i/10g, can trace any session, package is wrapped.
5. oradebugTrace session sid=58;select p.PID,p.SPID from v$process p,v$session s where s.paddr = p.addr and s.sid = 58;
PID SPID
———- ———
32 12943
connect / as sysdba
oradebug setospid 12943 //or oradebug setorapid 32
oradebug unlimit
oradebug event 10046 trace name context forever,level 12
Stop trace:
oradebug event 10046 trace name context off
Note: available in 8i/9i/10g, can trace any session
6. Using DBMS_SUPPORT
exec DBMS_SUPPORT.START_TRACE_IN_SESSION(&SID,
waits=>true, binds=>true );
exec DBMS_SUPPORT.STOP_TRACE_IN_SESSION( &SID , null );
NOTE: need to install before use
SQL> connect / AS SYSDBA
SQL> @?\rdbms\admin\dbmssupp.sql
SQL> GRANT execute ON dbms_support TO schema_owner;
SQL> CREATE PUBLIC SYNONYM dbms_support FOR dbms_support;
7. Using trcsess
trcsess [output=output_file_name]
[session=session_id]
[clientid=client_id]
[service=service_name]
[action=action_name]
[module=module_name]
[trace_files]
Trace a module:
trcsess service=vasont.world module=VasontU.exe trc.log
8. Tracing whole system
alter system set events '10046 trace name context forever,level 12';
or
event="10046 trace name context forever,level 12"
Stop system wider trace:
alter system set events '10046 trace name context off';
9. Using trigger to start traces
There may be some situations where it is necessary to trace
the activity of a specific user. In this case a logon trigger
could be used.
An example is provided below:
CREATE OR REPLACE TRIGGER SYS.set_trace
AFTER LOGON ON DATABASE
WHEN (USER like '&USERNAME')
DECLARE
lcommand varchar(200);
BEGIN
EXECUTE IMMEDIATE 'alter session set statistics_level=ALL';
EXECUTE IMMEDIATE 'alter session set max_dump_file_size=UNLIMITED';
EXECUTE IMMEDIATE 'alter session set events ''10046 trace
name context forever, level 12''';
END set_trace;
/
Last step, after trace processing, using tkprof
tkprof vasont_ora_22103.trc vasont_ora_22103.trc.log sys=no
waits=yes sort=(prscnt, execnt)
=================================================================
trcsess Tips
When solving tuning problems, session traces are very useful and offer vital information. Traces are simple and straightforward for dedicated server sessions, but for shared server sessions, many processes are involved. The trace pertaining to the user session is scattered across different trace files belonging to different processes. This makes it difficult to get a complete picture of the life cycle of a session.
Now there is a new tool, a command line utility called trcsess to help read the trace files. The trcsess command-line utility consolidates trace information from selected trace files, based on specified criteria. The criteria include session id, client id, service name, action name and module name.
The trcsess command-line utility offers the DBA a way to combine or consolidate several trace files into a single trace file based upon the following criteria:
Session Id
Client Id
Service name
Action name
Module name
When using dedicated server processes, monitoring only a single session and not doing parallel operations, there is little need for the trcsess utility. But when using shared server processes, monitoring several sessions concurrently, and/or doing parallel DML, the workload can span multiple trace files. In fact, it can be located on different nodes in a RAC environment if the parallel operations cross nodes. The command syntax is as follows:
$ trcsess [options] trace_files
Where the options are:
< output=
|
< Consolidated output trace file
|
< session=
|
< Consolidates the trace information by session id
|
< clientid=
|
< Consolidates the trace information by client id
|
< service=
|
< Consolidates the trace information by service name
|
< action=
|
< Consolidates the trace information by action name
|
< module=
|
< Consolidates the trace information by module name
|
In the following example, all the trace files in the temporary directory are consolidated into one big trace file and are doing so just for SELECT statements:
C:\Temp>trcsess output=one_big.trc service=ORDB1 *.trc
Examining the contents of the resulting one_big.trc file, this shows that the trcsessutility has consolidated five separate trace files into one.
one_big.trc consolidated trace file
*** [ Windows thread id: 4860 ]
*** 2008-08-03 10:06:16.796
*** 2008-08-03 10:06:16.796
*** 2008-08-03 10:06:16.796
…
*** TRACE CONTINUED FROM FILE c:\oracle\diag\rdbms\ordb1\ordb1\trace\ordb1_ora_4860.trc ***
…
*** TRACE CONTINUED FROM FILE c:\oracle\diag\rdbms\ordb1\ordb1\trace\ordb1_ora_3412.trc ***
…
*** TRACE CONTINUED FROM FILE c:\oracle\diag\rdbms\ordb1\ordb1\trace\ordb1_ora_1072.trc ***
…
*** TRACE CONTINUED FROM FILE c:\oracle\diag\rdbms\ordb1\ordb1\trace\ordb1_ora_1716.trc ***
…
*** TRACE CONTINUED FROM FILE c:\oracle\diag\rdbms\ordb1\ordb1\trace\ordb1_ora_2432.trc ***
…
Also note that beginning with Oracle 10g, Oracle Trace functionality is no longer available. For tracing database activity, use SQLTrace or TKPROF instead.
The syntax for the trcsess utility is:
trcsess [output=output_file_name]
[session=session_Id]
[clientid=client_Id]
[service=service_name]
[action=action_name]
[module=module_name]
[trace_files]
where:
- output specifies the file where the output is generated. When this option is not specified, the standard output is used for the output.
- session consolidates the trace information for the session specified. The session Id is a combination of session index and session serial number.
- clientid consolidates the trace information given client Id.
- service consolidates the trace information for the given service name.
- action consolidates the trace information for the given action name.
- module consolidates the trace information for the given module name.
- trace_files is a list of all trace file names, separated by spaces, in which trcsess will look for trace information. The wild card character * can be used to specify the trace file names. If trace files are not specified, all the files in the current directory are checked by trcsess.
Once the trace files have been consolidated,
tkprof can be run against the consolidated trace file for reporting purposes.
Utilities for Analyzing Oracle Trace Files
There are several utilities for analyzing Oracle trace files. These include trace assist (trcasst), session tracer (trcsess), trace analyzer (trcanlzr.sql) and tkprof. Many DBAs are very familiar with the Oracle trace facility, but just in case, here are some brief instructions for using this powerful Oracle utility. Before tracing can be enabled, the environment must first be configured by performing the following steps:
Enable Timed Statistics: This parameter enables the collection of certain vital statistics such as CPU execution time, wait events, and elapsed times. The resulting trace output is more meaningful with these statistics. The command to enable timed statistics is:
ALTER SYSTEM SET TIMED_STATISTICS = TRUE;
Check the User Dump Destination Directory: The trace files generated by Oracle can be numerous and large. These files are placed by Oracle in the user_dump_dest directory as specified in the init.ora. The user dump destination can also be specified for a single session using the alter session command. Make sure that enough space exists on the device to support the number of trace files that you expect to generate.
Turn Tracing On: The next step in the process is to enable tracing. By default, tracing is disabled due to the burden (5-10%) it places on the database. Tracing can be defined at the session level:
ALTER SESSION SET SQL_TRACE = TRUE;
DBMS_SESSION.SET_SQL_TRACE(TRUE);
A DBA may enable tracing for another user’s session by using the following statement:
DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION (sid,serial#,true);
The sid (Session ID) and serial# can be obtained from the v$session view. Once tracing with Oracle tkprof is enabled, Oracle generates and stores the statistics in the trace file. The trace file name is version specific.
Enable Oracle tkprof tracing only on those sessions that are having problems. Explain Plan is not as useful when used in conjunction with tkprof since the trace file contains the actual execution path of the SQL statement. Use Explain Plan when anticipated execution statistics are desired without actually executing the statement.
When tracing a session, remember that nothing in v$session indicates that a session is being traced. Therefore, trace with caution and remember to disable tracing after an adequate amount of trace data has been generated.
Tkprof does not control the contents of a trace file, it simply formats them. Oracle provides multiple ways to actually generate the trace file. Tkprof is valuable for detailed trace file analysis. For those DBAs that prefer a simpler tracing mechanism with instant feedback, the autotrace utility should be used.
The trace assist (trcasst) utility is used to analyze Oracle trace files generated by most Oracle error messages. This utility will analyze the trace file and put it into a readable format.
Using the Trace Analyzer Utility
Trace Analyzer (trcanlzr) is an application from Oracle with much the same purpose as tkprof. It is also designed to help analyze the trace files generated by SQL tracing. Trace Analyzer offers enhancements over tkprof in a number of areas. Several of the key improvements are as follows:
Trace Analyzer provides a more detailed list of wait events for every SQL statement that is part of the trace file. Only in recent versions has tkprof provided at least limited wait information. Older versions provide no information on wait events regardless of the trace data.
Trace Analyzer reports totals for statements that execute multiple times; whereas tkprof would report each execution separately. This is important when tracing a process that is updating many records, but doing it one row at a time. Identifying this with tkprof requires more manual effort.
Trace Analyzer provides the values used by bind variables, as long as the trace file was generated at a level that includes bind variables; whereas this feature is not available with tkprof.
Installation of Trace Analyzer is fairly straightforward as long as the instructions are followed completely. It is very similar to installing Statspack. Metalink document 224270.1 provides an adequate explanation for finding the files to accomplish the installation as well as how to install and use it. Be very careful to follow the instructions exactly.
Executing Trace Analyzer
First, tracing needs to be enabled at the appropriate level. For example, to provide maximum trace data, a Level 12 trace can be started for the current session:
SQL> ALTER SESSION SET EVENTS '10046 TRACE NAME CONTEXT FOREVER, LEVEL 12';
After the session executes for enough time to gain needed data, the trcanlzr.sql script can be executed. It requires the name of the directory object. This object points to the physical operating system directory for the user_dump_dest. The installation of the utility will automatically create the directory object required (named UDUMP).
SQL>@d:\trcanlzr.sql UDUMP asg920xr_ora_13033.trc
Once executed, the output will be displayed on the screen and
a spool file is created in the current directory. It is possible to change the output spool file by modifying the trcanlzr.sql script.
Using the trcsess utility
When solving tuning problems, session traces are very useful and offer vital information. Traces are simple and straightforward for dedicated server sessions, but for shared server sessions, many processes are involved. The trace pertaining to the user session is scattered across different trace files belonging to different processes. This makes it difficult to get a complete picture of the life cycle of a session.
The trcsess command-line utility consolidates trace information from selected trace files based on specified criteria. The criteria include session id, client id, service name, action name and module name. This allows the compilation of multiple trace files into a single output file.
The syntax for the trcsess utility is:
trcsess [output=output_file_name]
[session=session_Id]
[clientid=client_Id]
[service=service_name]
[action=action_name]
[module=module_name]
[trace_files]
Where:
output specifies the file where the output is generated. When this option is not specified, the standard output is used for the output.
session consolidates the trace information for the session specified. The session ID is a combination of session index and session serial number.
clientid consolidates the trace information given client ID.
service consolidates the trace information for the given service name.
action consolidates the trace information for the given action name.
module consolidates the trace information for the given module name.
trace_files is a list of all trace file names, separated by spaces, in which trcsess will look for trace information. The wild card character * can be used to specify the trace file names. If trace files are not specified, all the files in the current directory are checked by trcsess.
Activating trace on multiple sessions means that trace information is spread throughout many trace files. For this reason, Oracle 10g introduced the trcsess utility, allowing trace information from multiple trace files to be identified and consolidated into a single trace file. The trcsess usage is listed below.
trcsess [output=
Use Oracle’s trcsess command-line utility to consolidate the information from all the trace files into a single output file.
Then run tkprof
against the consolidated trace file to generate a report. It is recommended that one experiments some with tkprof to become familiarized with the options available in this useful utility.
..\udump> tkprof hr_report.trc
output=hr_trc_report SORT=(EXEELA, PRSELA,FCHELA)
Comments
Post a Comment
Oracle DBA Information