Friday, March 6, 2009

Oracle Trace Files

Guys! As a software engineer, you need to be ready to work around the clock, and equally prepared to sit idle for weeks, even months.

Throughout most of my career, I’ve experienced the former—non-stop work. But in the past couple of months, I found myself in the latter, far more boring phase. Luckily, I recognized it early on and discovered a remedy for this monotonous stretch. That remedy, my friends, was “Installation and Configuration of MetaSolv.”

I must admit, installing MetaSolv M6 from scratch was a real challenge. One of the most valuable lessons I learned along the way involved Oracle Trace Files. Although MetaSolv includes a trace option, I had to use Oracle’s native trace feature to troubleshoot some privilege issues.

What is Trace in Oracle?

Trace is a feature in Oracle that logs the smallest details of a session. When enabled, it generates trace files with the extension “.trc.” These files follow a standardized naming convention:

DB_NAME_ORA_SID.trc
  • DB_NAME: Global database name
  • SID: Session ID

Example:

mssdev_ora_2308.trc

Enabling Trace

Trace can be enabled at the session level, either through an ALTER statement or by using the DBMS_SUPPORTpackage.

Example:

sql
ALTER SYSTEM SET trace_enabled = TRUE; -- Enable trace ALTER SYSTEM SET trace_enabled = FALSE; -- Disable trace

If you want to enable tracing for another session, use the DBMS_SUPPORT package.

sql
SQL> desc dbms_support Element Type ---------------------- --------- PACKAGE_VERSION FUNCTION MYSID FUNCTION START_TRACE PROCEDURE STOP_TRACE PROCEDURE START_TRACE_IN_SESSION PROCEDURE STOP_TRACE_IN_SESSION PROCEDURE

The last two procedures allow you to start and stop tracing for any session in the database. Below is an example of enabling trace for all active sessions of a specific user using a BEGIN-END block.

Example:

sql
BEGIN FOR c IN (SELECT s.sid, s.serial# FROM v$session s WHERE s.username = 'ASAP' AND s.status = 'ACTIVE') LOOP dbms_support.start_trace_in_session(c.sid, c.serial); END LOOP; END;

To stop tracing, use:

sql
dbms_support.stop_trace_in_session(c.sid, c.serial);

Sample Trace File

Below is an excerpt from a sample trace file:

yaml
===================================================================== Dump file c:\oracle\admin\mssdev\udump\mssdev_ora_2308.trc Wed Feb 18 13:01:42 2009 ORACLE V9.2.0.1.0 - Production vsnsta=0, vsnsql=12, vsnxtr=3 Windows 2000 Version 5.1 Service Pack 2, CPU type 586 Instance name: mssdev Redo thread mounted by this instance: 1 Oracle process number: 15 Windows thread id: 2308, image: ORACLE.EXE *** SESSION ID:(9.23) 2009-02-18 13:01:42.000 PARSING IN CURSOR #2 len=79 dep=0 uid=73 oct=3 lid=73 tim=259898785365 hv=4060294543 ad='1cd62f00' SELECT global_name FROM global_name END OF STMT PARSE #8:c=15625,e=17422,p=0,cr=2,cu=0,mis=1,r=0,dep=0,og=4,tim=2592960232 BINDS #8: EXEC #8:c=0,e=1358,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=2592968343 =====================================================================

Every line in a trace file contains statistics. These statistics help decode session details. For example:

  • PARSE: Displays cursor length (len=79), user ID (uid=73), and parse time (tim=).
  • C: CPU time
  • E: Elapsed time
  • P: Number of database blocks read
  • CR: Consistent mode blocks read
  • CU: Current mode blocks read
  • MIS: Number of library cache misses
  • R: Number of rows fetched
  • OG: Optimizer goal (1 = all_rows, 2 = first_rows, 3 = rule, 4 = choose)

Understanding the Trace File

Trace files provide a detailed view of each session, including:

  1. The client used for execution
  2. Time and resources required for query execution
  3. The number of rows fetched, along with the optimizer goal

Reading trace files gives valuable insights into session performance, query optimization, and resource usage. For more information, you can explore Oracle’s documentation on trace file output formats.


This version retains the technical depth and structure of the original while improving clarity, consistency, and readability.

2 comments:

Guru said...

The post looks interesting. So, finding enough time at last.

Unknown said...

nice article.

I read the other link you mentioned and i noticed this statment.

"If there are TIMESTAMPS in the file you can use the difference between 'tim' values to determine an absolute time."

This is what i am trying to achieve..basically the absolute times between all the query's shown in the trace. Would you know what query or technique I could use extract that output?

thanks!