Call now: 252-767-6166  
Oracle Training Oracle Support Development Oracle Apps

 
 Home
 E-mail Us
 Oracle Articles
New Oracle Articles


 Oracle Training
 Oracle Tips

 Oracle Forum
 Class Catalog


 Remote DBA
 Oracle Tuning
 Emergency 911
 RAC Support
 Apps Support
 Analysis
 Design
 Implementation
 Oracle Support


 SQL Tuning
 Security

 Oracle UNIX
 Oracle Linux
 Monitoring
 Remote s
upport
 Remote plans
 Remote
services
 Application Server

 Applications
 Oracle Forms
 Oracle Portal
 App Upgrades
 SQL Server
 Oracle Concepts
 Software Support

 Remote S
upport  
 Development  

 Implementation


 Consulting Staff
 Consulting Prices
 Help Wanted!

 


 Oracle Posters
 Oracle Books

 Oracle Scripts
 Ion
 Excel-DB  

Don Burleson Blog 


 

 

 


 

 

 

 
 

Analyzing the Oracle 10046 Trace File

Oracle Tips by Robert Freeman


Note: Here are related Oracle 10046 trace file notes:
Loading and Analyzing the 10046 Event
 
Oracle provides us with a tool, TKPROF, that will analyze a trace file generated via a 10046 event. In fact, it collects summary wait information for each event for you to look at. Often, this might be sufficient, but it would be nice to be able to load critical 10046 trace information into the database to do some analysis both current and even historical. I can even envision some trending that could be done with such data.
 
To conclude this white paper, I present my first attack at making this information available within the database. I have created 3 external tables that load specific event information from within the trace file. You may well find ways to improve this code, or build on it. I?d love to see what you do to it.
 
These external tables have been tested on Oracle Database 10g on a Windows XP platform. They should work on other 10g databases. I have not tested them in Oracle9i, so I can't guarantee they will work there.
 
The Wait Event External Table
 
The first external table is designed to load the wait events listed in the 10046 trace file. Notice that in each of the external tables I use the TRACE_ROW_NUM pseudo column to track the actual row number of the event in the trace file. This will allow us to reconstruct the records in the order that they appear in the trace file, which is very important!
 
Also note that you will need to use the create directory command to create the LOAD_DIRECTORY directory that is referenced in these external tables. Here is the SQL for that command:
 
create directory load_directory
as 'c:\oracle\product\admin\BOOKTST\udump';
 
And here is the first external table DDL code. Note that I load in all of the variables related to the particular events to external table columns:
 
drop table ext_10046_table_wait_events;
 
create table ext_10046_table_wait_events
(event_type            varchar2(10),
 cursor_number         number,
 wait_event_name       varchar2(60),
 total_elapsed_time    number,
 p1                    varchar2(100),
 p2                    varchar2(100),
 p3                    varchar2(100),
 trace_row_num         number
 )
 ORGANIZATION EXTERNAL
 (TYPE oracle_loader
  DEFAULT DIRECTORY load_directory
  access parameters
            ( RECORDS DELIMITED BY NEWLINE
              badfile load_directory:'bad_10046.log'
              logfile load_directory:'load_10046.log'
              skip 24
              LOAD WHEN event_type="WAIT"
              FIELDS RTRIM
                 (
                      event_type CHAR terminated by '#',
                      cursor_number CHAR terminated by ': nam=',
                      wait_event_name CHAR terminated by 'ela=',
                      total_elapsed_time CHAR terminated by 'p1=',
                      p1  CHAR terminated by 'p2=',
                      p2  CHAR terminated by 'p3=',
                      p3  CHAR terminated by WHITESPACE,
                      trace_row_num recnum
                  )
            )
       location ('booktst_ora_3640.trc')
 )
reject limit unlimited;
 
The Parse, Execute and Fetch Events External Table
 
Because the parse, execute and fetch record formats are pretty much the same, I loaded them up into a single external table. Here is the code for that table.
 
drop table ext_10046_table_pef_events;
 
create table ext_10046_table_pef_events
(event_type            varchar2(10),
 cursor_number         number,
 pef_cpu_time          number,
 pef_elap              number,
 pef_blocks            number,
 pef_blocks_cm         number,
 pef_blocks_curmode    number,
 pef_lib_cache_misses  number,
 pef_rows_returned     number,
 pef_depth             number,
 pef_goal              number,
 pef_tim               number,
 trace_row_num         number
 )
 ORGANIZATION EXTERNAL
 (TYPE oracle_loader
  DEFAULT DIRECTORY load_directory
  access parameters
            ( RECORDS DELIMITED BY NEWLINE
              badfile load_directory:'bad_10046.log'
              logfile load_directory:'load_10046.log'
              skip 24
              LOAD WHEN (    event_type="EXEC"
                          or event_type="FETCH"
                          or event_type="PARSE" )
              FIELDS RTRIM
                 (
                      event_type           CHAR terminated by '#',
                      cursor_number        CHAR terminated by ':c=',
                      pef_cpu_time         CHAR terminated by ',e=',
                      pef_elap             CHAR terminated by ',p=',
                      pef_blocks           CHAR terminated by ',cr=',
                      pef_blocks_cm        CHAR terminated by ',cu=',
                      pef_blocks_curmode   CHAR terminated by ',mis=',
                      pef_lib_cache_misses CHAR terminated by ',r=',
                      pef_rows_returned    CHAR terminated by ',dep=',
                      pef_depth            CHAR terminated by ',og=',
                      pef_goal             CHAR terminated by ',tim=',
                      pef_tim              CHAR terminated by WHITESPACE,
                      trace_row_num recnum
                  )
            )
       location ('booktst_ora_3640.trc')
 )
reject limit unlimited;
 
The Cursor Record External Table
 
Ok, now a story. I found out that I got accepted for this presentation about 30 days before it was to be given. I had about a week to put this all in place, get the presentation together and make all the code work. Unfortunately, I had to cut a corner or two, and it was on this table that most of the corners got cut.
 
I wanted the table to load the cursor related statistics, and the SQL statement itself. I just ran out of time, and could not get the SQL code to load in with the rest of the data. I?m going to try to work on this when I have time, but if you manage to get it working, please let me know and send me updated code if you like!
 
drop table ext_10046_table_cursor_events;
 
create table ext_10046_table_cursor_events
(event_type            varchar2(40),
 cursor_number         number,
 cur_length            number,
 cur_dependency        number,
 cur_uid               number,
 cur_oct               number,
 cur_lid               number,
 cur_tim               number,
 cur_hv                number,
 cur_ad                varchar2(30),
 trace_row_num         number
 )
 ORGANIZATION EXTERNAL
 (TYPE oracle_loader
  DEFAULT DIRECTORY load_directory
  access parameters
            ( RECORDS DELIMITED BY NEWLINE
              badfile load_directory:'bad_10046.log'
              logfile load_directory:'load_10046.log'
              skip 24
              LOAD WHEN ( event_type='PARSING IN CURSOR ' )
              FIELDS RTRIM MISSING FIELD VALUES ARE NULL
                 (
                      event_type           CHAR terminated by '#',
                      cursor_number        CHAR terminated by 'len=',
                      cur_length           CHAR terminated by 'dep=',
                      cur_dependency       CHAR terminated by 'uid=',
                      cur_uid              CHAR terminated by 'oct=',
                      cur_oct              CHAR terminated by 'lid=',
                      cur_lid              CHAR terminated by 'tim=',
                      cur_tim              CHAR terminated by 'hv=',
                      cur_hv               CHAR terminated by "ad='",
                      cur_ad               CHAR terminated by  "'",
                      trace_row_num recnum
                  )
            )
       location ('booktst_ora_2504.trc')
 )
reject limit unlimited;
 
Making it all work
 
Here are examples of the execution of this code:
 
select trace_row_num, event_type, cursor_number, wait_event_name
from ext_10046_table_wait_events
where rownum < 5;
 
TRACE_ROW_NUM EVENT_TYPE CURSOR_NUMBER WAIT_EVENT_NAME
------------- ---------- ------------- --------------------------------
           30 WAIT                   1 'SQL*Net message to client'
           31 WAIT                   1 'SQL*Net message from client'
           41 WAIT                   2 'SQL*Net message to client'
           43 WAIT                   2 'SQL*Net message from client'
 
 
select trace_row_num, event_type, cursor_number
from ext_10046_table_pef_events
where rownum < 5;
 
TRACE_ROW_NUM EVENT_TYPE CURSOR_NUMBER
------------- ---------- -------------
           29 EXEC                   1
           38 PARSE                  2
           40 EXEC                   2
           42 FETCH                  2
 
select distinct b.trace_row_num, sql_text
from v$sql a, ext_10046_table_cursor_events b
where upper(b.cur_ad)=a.address (+)
order by b.trace_row_num;
 
TRACE_ROW_NUM
-------------
SQL_TEXT
-----------------------------------------------------------------------69
SELECT a.emp_first_name, b.job_name
FROM emp a, job b
WHERE a.job_key=b.job_key
END OF STMT
 
This join puts all the records together?Again, it isn't perfect, but what do you expect for free!! J (Ok, so you  probably paid to attend the conference, but you did get a 15 page paper from me!)
 
Column wait_time heading ?Wait Time|or|SQL Text?
Column wait_time format a30
select trace_row_num, event_type, cursor_number, wait_event_name, to_char(total_elapsed_time) wait_time
from ext_10046_table_wait_events
union
select trace_row_num, event_type, cursor_number , null, null
from ext_10046_table_pef_events
union
select distinct b.trace_row_num, null, null, null, sql_text
from v$sql a, ext_10046_table_cursor_events b
where upper(b.cur_ad)=a.address (+)
order by 1;
 
                                                                     
                                                                      Wait Time
                                                                      or
 
TRACE_ROW_NUM EVENT_TYPE CURSOR_NUMBER WAIT_EVENT_NAME                SQL Text
------------- ---------- ------------- ------------------------------ -------------------
           29 EXEC                   1                                alter session set 
                                                                      events '10046          
                                                                      trace name context 
                                                                      forever, level 12'
           30 WAIT                   1 'SQL*Net message to client'    9
           31 WAIT                   1 'SQL*Net message from client'  5913918
           38 PARSE                  2
           40 EXEC                   2                                SELECT 
                                                                      a.emp_first_name, 
                                                                      b.job_name
                                                                      FROM emp a, job b
                                                                      WHERE 
                                                                      a.job_key=b.job_key
           41 WAIT                   2 'SQL*Net message to client'    10
           42 FETCH                  2
           43 WAIT                   2 'SQL*Net message from client'  2120
           44 WAIT                   2 'SQL*Net message to client'    6
           45 FETCH                  2
           46 WAIT                   2 'SQL*Net message from client'  1353028
 
Let's summarize our waits?
 
select cursor_number, wait_event_name,
sum(total_elapsed_time)/1000000 wait_time
from ext_10046_table_wait_events
group by cursor_number, wait_event_name;
 
CURSOR_NUMBER WAIT_EVENT_NAME                 WAIT_TIME
------------- ------------------------------ ----------
            0 'log file sync'                   .108999
            0 'SQL*Net message to client'       .000417
            0 'SQL*Net message from client'  1259.44319
            3 'latch free'                      .000856
            3 'db file sequential read'       18.398237
            3 'SQL*Net message to client'      1.006712
            3 'log file switch completion'       .03704
            3 'SQL*Net message from client'  139.085542
            3 'SQL*Net more data from client   3.613657
 
Click here to read next section
Click here to read previous section

 
If you like Oracle tuning, see the book "Oracle Tuning: The Definitive Reference", with 950 pages of tuning tips and scripts. 

You can buy it direct from the publisher for 30%-off and get instant access to the code depot of Oracle tuning scripts.


 

 

��  
 
 
Oracle Training at Sea
 
 
 
 
oracle dba poster
 

 
Follow us on Twitter 
 
Oracle performance tuning software 
 
Oracle Linux poster
 
 
 

 

Burleson is the American Team

Note: This Oracle documentation was created as a support and Oracle training reference for use by our DBA performance tuning consulting professionals.  Feel free to ask questions on our Oracle forum.

Verify experience! Anyone considering using the services of an Oracle support expert should independently investigate their credentials and experience, and not rely on advertisements and self-proclaimed expertise. All legitimate Oracle experts publish their Oracle qualifications.

Errata?  Oracle technology is changing and we strive to update our BC Oracle support information.  If you find an error or have a suggestion for improving our content, we would appreciate your feedback.  Just  e-mail:  

and include the URL for the page.


                    









Burleson Consulting

The Oracle of Database Support

Oracle Performance Tuning

Remote DBA Services


 

Copyright © 1996 -  2020

All rights reserved by Burleson

Oracle ® is the registered trademark of Oracle Corporation.