Oracle 10046事件介绍(一)

407次阅读

共计 6858 个字符，预计需要花费 18 分钟才能阅读完成。

做 Oracle 方面的工作时间长了，经常会听人提起 10046 事件，尤其是涉及到 SQL 调优的时候更甚。那 10046 事件到底是什么呢，先做一个简单的介绍。

1、什么是 10046 事件

10046 事件是 Oracle 提供的一个用于分析性能的工具，它能帮助我们解析一条 / 多条 SQL、PL/SQL 语句的运行状态，这些状态包括：Parse/Fetch/Execute 三个阶段中遇到的等待事件、消耗的物理和逻辑读、CPU 时间、执行计划等等。

2、10046 事件的 Level

不同的 Level 对应不同的跟踪级别

1 启用标准的 SQL_TRACE 功能 (默认) 包含了 SQL 语句、响应时间、服务时间、处理的行数，物理读和写的数目、执行计划以及其他一些额外信息。到版本 10.2 中执行计划写入到 trace 的条件是仅当相关游标已经关闭时，且与之相关的执行统计信息是所有执行次数的总和数据。到版本 11.1 中仅在每次游标的第一次执行后将执行计划写入到 trace，执行统计信息仅仅和这第一次执行相关

4 比 level 1 时多出绑定变量的 trace

8 比 level 1 多出等待事件，特别对于 9i 中指出 latchfree 等待事件很有用，对于分析全表扫描和索引扫描也很有用

12 比 level 1 多出绑定变量和等待事件

11g 及以上版本

16 在 11g 中为每一次执行生成 STAT 信息

32 比 level 1 少执行计划

11.2.0.2 及以上版本

64 和 level 1 相比在第一次执行后还可能生成执行计划信息；条件是某个游标在前一次执行的前提下运行耗时变长了一分钟。

3、启用 10046 事件

1)对本 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

其中能修改的只有 level 级别

2)对其他 session 启用 10046 事件

oradebug setospid|setorapid xxx

oradebug event 10046 trace name context ,level 12

4、停用 10046 事件

分别对应上面不同的启用方式

alter session set events ‘10046 trace name context forever off’

oradebug event 10046 trace name context off

或者退出启用 10046 事件的 session

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

a. 对于 11g 及以上的版本，使用如下语句可以轻松得到

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

b. 对于 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 命令则使用相对应的 oradebug tracefile_name 即可得到 trace 文件

6、格式化 trace 文件

10046 事件所产生的原始 trace 文件习惯称之为裸 trace 文件(raw trace)，Oracle 记录在裸 trace 文件中的内容一眼看上去并不是那么观，也不是那么容易看懂。为了祼 trace 文件能够以一种更直观、更容易懂的方式展现出来，Oracle 提供了 tkprof 命令，这个命令是 Oracle 自带的，可以用它来翻译祼 trace 文件。

tkprof 的语法如下：

[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、简单示例，数据库版本 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
********************************************************************************
…… 省略部分内容
********************************************************************************

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
********************************************************************************

…… 省略部分内容