Oracle 10046事件 介紹(一)

做Oracle方面的工作時(shí)間長(zhǎng)了，經(jīng)常會(huì)聽人提起10046事件，尤其是涉及到SQL調(diào)優(yōu)的時(shí)候更甚。那10046事件到底是什么呢，先做一個(gè)簡(jiǎn)單的介紹。

1、什么是10046事件

  10046事件是Oracle提供的一個(gè)用于分析性能的工具，它能幫助我們解析一條/多條SQL、PL/SQL語(yǔ)句的運(yùn)行狀態(tài)，這些狀態(tài)包括 ：Parse/Fetch/Execute三個(gè)階段中遇到的等待事件、消耗的物理和邏輯讀、CPU時(shí)間、執(zhí)行計(jì)劃等等。

2、10046事件的Level

不同的Level對(duì)應(yīng)不同的跟蹤級(jí)別

• 1 啟用標(biāo)準(zhǔn)的SQL_TRACE功能(默認(rèn))包含了SQL語(yǔ)句、響應(yīng)時(shí)間、服務(wù)時(shí)間、處理的行數(shù)，物理讀和寫的數(shù)目、執(zhí)行計(jì)劃以及其他一些額外信息。到版本10.2中執(zhí)行計(jì)劃寫入到trace的條件是僅當(dāng)相關(guān)游標(biāo)已經(jīng)關(guān)閉時(shí)，且與之相關(guān)的執(zhí)行統(tǒng)計(jì)信息是所有執(zhí)行次數(shù)的總和數(shù)據(jù)。到版本11.1中僅在每次游標(biāo)的第一次執(zhí)行后將執(zhí)行計(jì)劃寫入到trace，執(zhí)行統(tǒng)計(jì)信息僅僅和這第一次執(zhí)行相關(guān)

• 4 比level 1時(shí)多出綁定變量的trace

• 8 比level 1多出等待事件，特別對(duì)于9i中指出latchfree等待事件很有用，對(duì)于分析全表掃描和索引掃描也很有用

• 12 比level 1多出綁定變量和等待事件

11g及以上版本

• 16 在11g中為每一次執(zhí)行生成STAT信息

• 32 比level 1少執(zhí)行計(jì)劃

11.2.0.2及以上版本

• 64 和level 1相比在第一次執(zhí)行后還可能生成執(zhí)行計(jì)劃信息；條件是某個(gè)游標(biāo)在前一次執(zhí)行的前提下運(yùn)行耗時(shí)變長(zhǎng)了一分鐘。

3、啟用10046事件

1)對(duì)本session啟用10046事件

a.

 alter session set events '10046 trace name context forever,level 12'

b. 

 oradebug setmypid

 oradebug event 10046 trace name context ,level 12

其中能修改的只有l(wèi)evel級(jí)別

2)對(duì)其他session啟用10046事件

oradebug setospid|setorapid xxx

oradebug event 10046 trace name context ,level 12

4、停用10046事件

分別對(duì)應(yīng)上面不同的啟用方式

alter session set events '10046 trace name context forever off'

oradebug event 10046 trace name context off

或者退出啟用10046事件的session

5、獲取10046事件生成的trace文件

a.對(duì)于11g及以上的版本，使用如下語(yǔ)句可以輕松得到

select value from v$diag_info where name='Default Trace File';

b.對(duì)于10g及以前的版本中需要使用如下sql

SELECT D.VALUE || '' || LOWER(RTRIM(I.INSTANCE, CHR(0))) || '_ora_' ||
       P.SPID || '.trc' TRACE_FILE_NAME
  FROM (SELECT P.SPID
          FROM SYS.V$MYSTAT M, SYS.V$SESSION S, SYS.V$PROCESS P
         WHERE M.STATISTIC# = 1
           AND S.SID = M.SID
           AND P.ADDR = S.PADDR) P,
       (SELECT T.INSTANCE
          FROM SYS.V$THREAD T, SYS.V$PARAMETER V
         WHERE V.NAME = 'thread'
           AND (V.VALUE = 0 OR T.THREAD# = TO_NUMBER(V.VALUE))) I,
       (SELECT VALUE FROM SYS.V$PARAMETER WHERE NAME = 'user_dump_dest') D;

c.如果使用oradebug命令則使用相對(duì)應(yīng)的oradebug tracefile_name即可得到trace文件

6、格式化trace文件

 10046事件所產(chǎn)生的原始trace文件習(xí)慣稱之為裸trace文件(raw trace)，Oracle記錄在裸trace文件中的內(nèi)容一眼看上去并不是那么觀，也不是那么容易看懂。為了祼trace文件能夠以一種更直觀、更容易懂的方式展現(xiàn)出來，Oracle提供了tkprof命令，這個(gè)命令是Oracle自帶的，可以用它來翻譯祼trace文件。

tkprof的語(yǔ)法如下：

[oracle@rhel6 10046]$ 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

7、簡(jiǎn)單示例，數(shù)據(jù)庫(kù)版本11.2.0.4

zx@ORCL>alter session set events '10046 trace name context forever,level 12';

Session altered.

zx@ORCL>select * from scott.emp;

     EMPNO ENAME			  JOB				     MGR HIREDATE		    SAL       COMM     DEPTNO
---------- ------------------------------ --------------------------- ---------- ------------------- ---------- ---------- ----------
      7369 SMITH			  CLERK 			    7902 1980-12-17 00:00:00	    800 		   20
      7499 ALLEN			  SALESMAN			    7698 1981-02-20 00:00:00	   1600        300	   30
      ......

14 rows selected.

zx@ORCL>alter session set events '10046 trace name context off';

Session altered.

zx@ORCL>select value from v$diag_info where name='Default Trace File';

VALUE
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
/u02/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_3239.trc

zx@ORCL>!
[oracle@rhel6 trace]$ tkprof /u02/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_3239.trc 10046.trc

TKPROF: Release 11.2.0.4.0 - Development on Thu Feb 16 21:38:57 2017

Copyright (c) 1982, 2011, Oracle and/or its affiliates.  All rights reserved.


[oracle@rhel6 trace]$ cat 10046.trc

TKPROF: Release 11.2.0.4.0 - Development on Thu Feb 16 21:38:57 2017

Copyright (c) 1982, 2011, Oracle and/or its affiliates.  All rights reserved.

Trace file: /u02/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_3239.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
********************************************************************************
......省略部分內(nèi)容
********************************************************************************

SQL ID: ggqns3c1jz86c Plan Hash: 3956160932

select * 
from
 scott.emp


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2      0.00       0.00          0          7          0          14
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.00       0.00          0          7          0          14

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
        14         14         14  TABLE ACCESS FULL EMP (cr=7 pr=0 pw=0 time=81 us cost=3 size=532 card=14)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                       2        0.00          0.00
  SQL*Net message from client                     2        0.00          0.00
********************************************************************************

......省略部分內(nèi)容

參考文檔：https://blogs.oracle.com/askmaclean/entry/maclean教你讀oracle_10046_sql_trace

MOS文檔EVENT: 10046 "enable SQL statement tracing (including binds/waits)" (文檔 ID 21154.1)

How To Collect 10046 Trace (SQL_TRACE) Diagnostics for Performance Issues (文檔 ID 376442.1)

官方文檔：http://docs.oracle.com/cd/E11882_01/server.112/e41573/sqltrace.htm#PFGRF94981