Identifying sessions to Trace

posted Jul 27, 2011, 11:27 AM by Sachchida Ojha   [ updated Jul 27, 2011, 11:27 AM by Sachchida Ojha ]
It is expected that the session/s to be traced have already been identified using information elsewhere in this set of articles. Below is a reminder of some of the forms of statement which may be used when isolating a session to be traced:

Finding user/s of a particular SQL statement given the "ADDRESS" and "HASH_VALUE" from V$SQLAREA:

  SELECT s.sid , s.serial#, s.status, s.server, s.username
    FROM v$session s
   WHERE s.sql_address='&ADDRESS'
     AND s.sql_hash_value='&HASH_VALUE'
  ;

Finding the SID/SERIAL# of a user showing a particular type of wait:

  SELECT s.sid , s.serial#, s.status, s.server, s.username, 
	e.event, e.time_waited
    FROM v$session_event e, v$session s
   WHERE e.sid=s.sid
     AND e.event like '&WAITEVENT_TO_CHECK'
     AND e.time_waited > '&WAIT_TIME_THRESHOLD'
  ;
  
  ( or use e.total_waits > '&NUM_WAITS_THRESHOLD')

  Eg: Replace &WAITEVENT_TO_CHECK with "buffer busy waits" to show
      sessions exhibiting lots of buffer busy waits.

Finding the SID/SERIAL# of a user showing a particular count for a given statistic:

  SELECT s.sid , s.serial#, s.status, s.server, s.username, 
	 n.name, t.value
    FROM v$statname n, v$sesstat t, v$session s
   WHERE t.sid=s.sid
     AND t.statistic#=n.statistic#
     AND n.name like '&STATISTIC_TO_CHECK'
     AND t.value > '&VALUE_THRESHOLD'
  ;
  
  Eg: Replace &STATISTIC_TO_CHECK with "sorts (disk)" to show sessions 
      exhibiting lots of disk sorts.

Tracing your own Session

To start tracing your own session simply execute the PL/SQL call:
  DBMS_SUPPORT.START_TRACE; 

Tracing another Session

Once a session has been isolated then you need to know the SID of the target session (and possibly the SERIAL#). To start tracing the target session simply call:
  DBMS_SUPPORT.START_TRACE_IN_SESSION( SID , NULL );

If it is important to capture an exact session you should specify both the SID and SERIAL# . Eg:

  DBMS_SUPPORT.START_TRACE_IN_SESSION( SID , SERIAL# );

This PL/SQL procedure will ask the target session to start writing trace output. The trace may NOT start immediately as there are certain points in the Oracle code where a session checks to see if it has been asked to do something (like writing trace output) - the target session only starts tracing once it has seen the request.

Stopping Trace

To stop tracing in your own session call:
  DBMS_SUPPORT.STOP_TRACE;

To stop tracing another session call:

  DBMS_SUPPORT.STOP_TRACE_IN_SESSION( SID , NULL );

Trace Output File Format

Output files contain RAW trace output and can be found in the USER_DUMP_DEST directory for user sessions and BACKGROUND_DUMP_DEST for background processes. A summary of the RAW format can be found in Note:39817.1 . In this section we mention some of the important points about the trace file along with some tools which can be used to interpret the output for you.

Raw Trace File

The raw trace file is described in Note:39817.1. Important points to note are:
  1. Most lines refer to a CURSOR number. Eg: PARSING IN CURSOR #3
  2. EXECutes, FETCHes and WAITs are recorded against a cursor. The information applies to the most recently parsed statement within that cursor.
    Eg: FETCH #3 indicates a fetch from the most recently parsed and executed statement in cursor 3.
  3. All timing information in the trace file is in 1/100ths of a second.
  4. A time of ZERO in the trace file indicates LESS THAN 1/100th of a second.
  5. The information in the WAIT lines is the same as is found in V$EVENT_NAME (or V$SESSION_WAIT).

    Eg: WAIT #1: nam="db file scattered read" ela= 5 p1=4 p2=1435 p3=25

    implies a wait while using cursor #1 for "db file scattered read" V$EVENT_NAME shows P1 is "file#", P2 is "block#" and P3 is "blocks" so in this case this indicates a wait for a read to complete from file# 4, block#1435 for 25 blocks. The WAIT took 5/100 seconds or 50mS to complete.
  6. STAT lines indicate that the cursor has been closed. From Oracle 7.3.3 onwards the STAT lines give the ACTUAL execution plan for the statement.
Example
There are many ways to process a raw trace file but most require text processing filters such as GREP, AWK, NAWK, SED or PERL to extract the required information. As an example consider that several sessions have been showing waits for 'buffer busy waits'. By tracing a session the actual waits are written to the trace file. These could then be processed to list the file# and block# being waited for.
  Eg: In Unix one could process the waits using a command like: 

	grep 'buffer busy waits' trace_file | \
	 awk ' { print substr($0,9); } ' | \
	 sort > sorted_buffer_wait_list
The actual waits may then be mapped back to an object using SQL like:
  SELECT segment_owner, segment_name
    FROM dba_extents 
   WHERE file_id=&FILE_ID 
     AND &BLOCK_ID between block_id and block_id+blocks-1
Comments