Oracle 10046事件
10046 事件
Oracle 10046是一個Oracle內部事件。最常用的是在Session層級設定sql_trace(alter session set sql_trace=true)即是開啟了層級為1的10046調試事件。當設定了10046事件之後,Oracle 將產生一個dump檔案。通過得到的dump檔案進行進一步分析,可以得到Oracle 內部執行系統解析、調用、等待、綁定變數等詳細的trace資訊,對於分析系統的效能有著舉足輕重的作用。
當SQL語句操作出現效能問題時,我們可以用SQL_TRACE 或者10046事件進行跟蹤是最合適的。 如果是資料庫整體效能下降,就需要使用statspack或者AWR對資料庫進行分析。
1.10046事件的相關參數
該事件需要設定一些參數以控制dump檔案的輸出:
TIMED_STATISTICS
用於控制計時資訊,可以設定為true和false。當設定為true時,計時資訊將會被添加到trace檔案中。
MAX_DUMP_FILE_SIZE
用於控制trace檔案的最大尺寸。當使用10046事件時,建議將該參數設定為unlimited。
USER_DUMP_DEST
用於設定trace檔案寫入到哪個檔案目錄
STATISTICS_LEVEL
用於控制統計資訊的收集度。此參數有3個選擇,baisc,typical,all。
basic:僅收集滿足trace所需的最基本的資訊,象Timed statistics,Object level statistics,以及一些advisory會被忽略。
typical:此為預設值。此設定將在basic的基礎上增加一些額外的統計資訊,象作業系統耗用時間的統計資訊,執行計畫的統計資訊都會被收集
all:當設定為all時,所有與該session相關的資訊全部會被收集。
TRACEFILE_IDENTIFIER
用於設定識別Trace檔案的字串,便於更快捷的找到產生的Trace檔案。
以上參數可以基於系統層級以及會話層級進行修改。
ALTER SESSION/SYSTEM SET timed_statistics=true
ALTER SESSION/SYSTEM SET max_dump_file_size=unlimited
ALTER SESSION SET tracefile_identifier='trace_sql_example' -->僅session層級
2. 10046調試事件的等級
10046調試事件可以分為多個不同的等級,不同的等級輸出不同的trace資訊。
等級 作用
0 禁止調試事件
1 調試事件處於啟用狀態。針對每個被處理的資料庫調用,輸出SQL語句,APPNAME(應用程式名稱),PARSING IN CURSOR,PARSE ERROR(SQL解析)
,EXEC(執行),FETCH(擷取資料),UNMAP,SORT UNMAP(排序,臨時段),ERROR,STAT(執行計畫),XCTEND(事務)等行。
4 包括等級1的輸出,加上BIND行(綁定變數資訊)
8 包括等級1的輸出,加上WAIT行(等待事件資訊)。對於處理過程中的每個等待,提供如下資訊:等待時間的名字,期間,以及一些額外
的參數,可表明所等待的資源。
12 輸出等級4以及等級8的所有資訊
3. 產生trace檔案
[oracle@server8 trace]$ sqlplus / as sysdba
SQL*Plus: Release 11.2.0.3.0 Production on Tue Feb 10 16:20:39 2015
sys@GHSJDB> alter session set tracefile_identifier='10046';
Session altered.
sys@GHSJDB>alter session set events '10046 trace name context forever,level 12';(如果沒有許可權賦予 alter session 許可權)
Session altered.
sys@GHSJDB> select code,name,to_char(parent_code) parent,to_char(connect_by_isleaf) isleaf,lev
2 from ghsj_xm.v_organdataset
3 where level = 1 connect by prior code = parent_code start with code = '14142' order siblings by code
4 ;
CODE NAME
------------------------------------------------------------------------------------------ -----------------------------------
PARENT ISLEAF LEV
------------------------------------------------------------------------------------------ ---------------------------------------- ----------------------------------------
14142 國網湖北省電力公司
14000
sys@GHSJDB>alter session set events '10046 trace name context off';
Session altered.
4. 擷取追蹤檔案
方法1:
sys@GHSJDB> show parameter dump
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
background_core_dump string partial
background_dump_dest string /home/u01/app/oracle/diag/rdbm
s/ghsjdb/ghsjdb/trace
core_dump_dest string /home/u01/app/oracle/diag/rdbm
s/ghsjdb/ghsjdb/cdump
max_dump_file_size string unlimited
shadow_core_dump string partial
user_dump_dest string /home/u01/app/oracle/diag/rdbm
s/ghsjdb/ghsjdb/trace
去相應的目錄下:
cd /home/u01/app/oracle/diag/rdbms/ghsjdb/ghsjdb/trace
尋找標識符10046:
ls | grep 10046
ghsjdb_ora_9481_10046.trc
ghsjdb_ora_9481_10046.trm
方法2:
取得目前使用者的sid,根據ID取得tracefile的地址
sys@GHSJDB> select * from v$mystat where rownum=1;
SID STATISTIC# VALUE
----- ---------- ----------
247 0 ##########
sys@GHSJDB> SELECT tracefile FROM v$process WHERE addr IN (SELECT paddr FROM v$session WHERE sid='247');
TRACEFILE
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
/home/u01/app/oracle/diag/rdbms/ghsjdb/ghsjdb/trace/ghsjdb_ora_9481_10046.trc
5. 格式化輸出tkprof
[oracle@server8 ~]$ tkprof
Usage: tkprof tracefile outputfile [explain= ] [table= ]
[print= ] [insert= ] [sys= ] [sort= ]
table=schema.tablename Use 'schema.tablename' with 'explain=' option.
explain=user/password Connect to ORACLE and issue EXPLAIN PLAN.
print=integer List only the first 'integer' SQL statements.
aggregate=yes|no
insert=filename List SQL statements and data inside INSERT statements.
sys=no TKPROF does not list SQL statements run as user SYS.
record=filename Record non-recursive statements found in the trace file.
waits=yes|no Record summary for any wait events found in the trace file.
sort=option Set of zero or more of the following sort options:
prscnt number of times parse was called
prscpu cpu time parsing
prsela elapsed time parsing
prsdsk number of disk reads during parse
prsqry number of buffers for consistent read during parse
prscu number of buffers for current read during parse
prsmis number of misses in library cache during parse
execnt number of execute was called
execpu cpu time spent executing
exeela elapsed time executing
exedsk number of disk reads during execute
exeqry number of buffers for consistent read during execute
execu number of buffers for current read during execute
exerow number of rows processed during execute
exemis number of library cache misses during execute
fchcnt number of times fetch was called
fchcpu cpu time spent fetching
fchela elapsed time fetching
fchdsk number of disk reads during fetch
fchqry number of buffers for consistent read during fetch
fchcu number of buffers for current read during fetch
fchrow number of rows fetched
userid userid of user that parsed the cursor
tkprof /home/u01/app/oracle/diag/rdbms/ghsjdb/ghsjdb/trace/ghsjdb_ora_9481_10046.trc 10046.log sys=no
[oracle@server8 ~]$ more 10046.log
TKPROF: Release 11.2.0.3.0 - Development on Tue Feb 10 17:11:04 2015
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
Trace file: /home/u01/app/oracle/diag/rdbms/ghsjdb/ghsjdb/trace/ghsjdb_ora_11266_10046.trc
Sort options: default
********************************************************************************
count = number of times OCI procedure was executed
cpu = cpu time in seconds executing
elapsed = elapsed time in seconds executing
disk = number of physical reads of buffers from disk
query = number of buffers gotten for consistent read
current = number of buffers gotten in current mode (usually for update)
rows = number of rows processed by the fetch or execute call
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 4 0.00 0.00 0 0 0 0
Execute 4 0.00 0.00 0 0 0 2
Fetch 2 0.25 0.26 0 22123 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 10 0.25 0.26 0 22123 0 3
Misses in library cache during parse: 0
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 5 0.00 0.00
SQL*Net message from client 5 18.65 27.67
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 0 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 0 0.00 0.00 0 0 0 0
Misses in library cache during parse: 0
3 user SQL statements in session.
0 internal SQL statements in session.
3 SQL statements in session.
********************************************************************************
Trace file: /home/u01/app/oracle/diag/rdbms/ghsjdb/ghsjdb/trace/ghsjdb_ora_11266_10046.trc
Trace file compatibility: 11.1.0.7
Sort options: default
1 session in tracefile.
3 user SQL statements in trace file.
0 internal SQL statements in trace file.
3 SQL statements in trace file.
3 unique SQL statements in trace file.
115 lines in trace file.
27 elapsed seconds in trace file.