Analyzing the Oracle 10046 Trace File

本文介绍如何使用Oracle提供的工具TKPROF分析10046事件产生的跟踪文件,并通过创建外部表将关键跟踪信息加载到数据库中进行深入分析。

摘要生成于 C知道 ,由 DeepSeek-R1 满血版支持, 前往体验 >

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

评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值