oracle 10046详解,10046事件详解

最新推荐文章于 2024-05-10 22:13:11 发布

突驰

最新推荐文章于 2024-05-10 22:13:11 发布

阅读量3.6k

点赞数

文章标签： oracle 10046详解

10046事件详解

一、10046事件概述

10046是一个Oracle的内部事件(event)，通过设置这个事件可以得到Oracle内部执行系统解析、调用、等待、绑定变量等详细的trace信息，即帮助我们解析一条/多条SQL、PL/SQL语句的运行状态，这些状态包括：Parse/Fetch/Execute三个阶段中遇到的等待事件、消耗的物理和逻辑读、CPU时间、执行计划等。它不仅为我们揭示了一条、多条SQL的运行情况，同时还能帮我们分析一些DDL维护命令的内部工作原理，RMAN、Data Pump Expdp/impdp等工具缓慢问题。对于SQL性能优化、分析系统的性能有着非常重要的作用。

二、10046运行级别

Level 0

停用SQL跟踪，相当于SQL_TRACE=FALSE，无任何输出

Level 1

标准SQL跟踪，相当于SQL_TRACE=TRUE;

输出…APPNAME(应用程序名),PARSING IN CURSOR,PARSE ERROR(SQL解析),EXEC(执行),FETCH(获取数据),UNMAP,SORT UNMAP(排序，临时段),ERROR,STAT(执行计划),XCTEND(事务)等行

Level 4

在level

1的基础上增加绑定变量的信息，即好含1信息+binding events

Level 8

在level

1的基础上增加等待事件的信息，即包含1信息+waiting events

Level 12

在level 1的基础上增加绑定变量和等待事件的信息，即包含1、4、8的信息

三、10046 trace文件路径

从11gR1开始，Oracle引入了新的诊断结构，以参数DIAGNOSTIC_DEST控制存放trace文件与core文件的路径。可以用以下命令，获取DIAGNOSTIC_DEST的位置：

SQL> show

parameter diagnostic_dest;

11gR1以前,如果是用户进程，10046 trace文件会被生成在user_dump_dest下,如果是后台进程，trace文件会被生成在background_dump_dest下,下面的命令可以显示user_dump_dest:

SQL> show

parameter user_dump_dest ;

SQL> show

parameter background_dump_dest;

注意：通过设定tracefile_identifier即alter session set

tracefile_identifier='mytrace'，通过这个设置可以帮助我们更容易的找到生成的trace文件。

扩展：

(1)可以通过SQL获取当前session的跟踪文件位置：

select

a.value || '/' ||

b.instance_name || '_ora_' || c.spid || '.trc' trace_file

from

(select value from v$parameter

where name= 'user_dump_dest') a,

(select instance_name from

v$instance) b,

(select spid from v$process

where addr=(select paddr from v$session where sid=(select distinct sid from

v$mystat))) c;

或者

select tracefile from v$process

where addr=(select paddr from v$session where sid=(select distinct sid from

v$mystat));

四、10046 trace相关参数

1.timed_statistics

timed_statistics这个参数决定了是否收集与时间相关的统计信息，如果这个参数为FALSE的话，那么SQL Trace的结果基本没有多大的用处，默认情况下这个参数设置为TRUE。

show parameter

timed_statistics ;

ALTER SESSION

SET timed_statistics=true ;

2.max_dump_file_size

max_dump_file_size这个参数指定dump文件的大小，也就是决定是否限制SQL Trace文件的大小，在一个很忙的系统上面做SQL Trace的话可能会生成很多的信息，因此最好在会话级别将这个参数设置成unlimited。

show parameter

max_dump_file_size;

ALTER SESSION

SET max_dump_file_size=unlimited ;

3.tracefile_identifier

tracefile_identifier这个参数给Trace文件设置识别字符串，是个非常有用的参数，设置一个易读的字串能更快的找到Trace文件。

show

parametertracefile_identifier;

ALTER SESSION

SET tracefile_identifier=’my_trace_session’;

4.diagnostic_dest

diagnostic_dest这个参数11g新增的，用于控制存放trace文件与core文件的路径，默认是$ORACLE_BASE目录。

show parameter

diagnostic_dest;命令用于查看其目录

5.user_dump_dest

user_dump_dest参数指定用户进程trace文件目录。

show parameter

user_dump_dest ;命令可以产看其目录

alter system set user_dump_dest ='/U01/app/oracle/diag/rdbms/masterdb/masterdb/trace'

scope=both;命令用于更改其目录

6.background_dump_dest

background_dump_dest参数用于后台进程产生的trace文件存储目录下。

show parameter background_dump_dest ;命令可以查看其目录

alter system set

background_dump_dest='/U01/app/oracle/diag/rdbms/masterdb/masterdb/trace'

scope=both;命令用于更改其目录

注意：如果想要设置其他进程的上述参数，需要通过DBMS包设置，但tracefile_identifier是无法在别的会话中修改。

具体设置命令为：

SYS.DBMS_SYSTEM.SET_BOOL_PARAM_IN_SESSION(:sid,

:serial,'timed_statistics', true) ;

SYS.DBMS_SYSTEM.SET_INT_PARAM_IN_SESSION(:sid,

:serial,'max_dump_file_size', 2147483647) ;

五、10046 trace设置方法

1.10046事件会话级别

这种方法适用于SQL语句可以在新的session创建后再运行。

语法：

alter session set events

'[eventnumber|immediate] trace name eventname [forever] [, level levelnumber] :

.......'

1.1开启session sql

trace

alter session set tracefile_identifier='10046';

alter session set timed_statistics = true; --默认是true

alter session set statistics_level=all;--实例级别设置需要注意，会消耗大量的CPU

alter session set max_dump_file_size = unlimited; --默认是unlimited

alter session set events '10046 trace name context forever,level 12'; --常用的级别是12

set serveroutput off;

alter session set

tracefile_identifier='10046';

alter session set timed_statistics

= true;

alter session set

statistics_level=all;

alter session set

max_dump_file_size = unlimited;

alter session set events '10046

trace name context forever,level 12';

1.2执行要trace的SQL

select * from scott.dept;

1.3关闭session sql

trace

alter session set events '10046 trace name

context off';

或者直接退出session

exit

1.4查看session sql

trace路径

select tracefile from v$process

where addr=(select paddr from v$session where sid=(select distinct sid from

v$mystat));

或者

select

a.value || '/' ||

b.instance_name || '_ora_' || c.spid || '.trc' trace_file

from

(select value from v$parameter

where name= 'user_dump_dest') a,

(select instance_name from

v$instance) b,

(select spid from v$process

where addr=(select paddr from v$session where sid=(select distinct sid from

v$mystat))) c;

或者

show parameter user_dump_dest ;

1.5分析session sql

trace

(1)直接查看

/U01/app/oracle/diag/rdbms/masterdb/masterdb/trace/masterdb_ora_20596_10046.trc

=====================

PARSING IN CURSOR #47019101509648 len=24 dep=0

uid=0 oct=3 lid=0 tim=1477908470545403 hv=911793802 ad='74c73648'

sqlid='f6hhpzwv5jrna'

select * from scott.dept

END OF STMT

PARSE#47019101509648:c=33995,e=65940,p=14,cr=62,cu=0,mis=1,r=0,dep=0,og=1,plh=3383998547,tim=1477908470545401

EXEC#47019101509648:c=0,e=17,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=3383998547,tim=1477908470545479

WAIT #47019101509648:

nam='SQL*Net message to client' ela= 14 driver id=1650815232 #bytes=1 p3=0

obj#=-1 tim=1477908470545527

WAIT #47019101509648: nam='Disk

file operations I/O' ela= 115 FileOperation=2 fileno=4 filetype=2 obj#=87106

tim=1477908470545730

WAIT #47019101509648: nam='db

file sequential read' ela= 24 file#=4 block#=130 blocks=1 obj#=87106

tim=1477908470545780

WAIT #47019101509648: nam='db

file scattered read' ela= 60 file#=4 block#=131 blocks=5 obj#=87106

tim=1477908470545972

FETCH#47019101509648:c=0,e=510,p=6,cr=6,cu=0,mis=0,r=1,dep=0,og=1,plh=3383998547,tim=1477908470546076

WAIT #47019101509648:

nam='SQL*Net message from client' ela= 644 driver id=1650815232 #bytes=1 p3=0

obj#=87106 tim=1477908470546764

WAIT #47019101509648:

nam='SQL*Net message to client' ela= 0 driver id=1650815232 #bytes=1 p3=0

obj#=87106 tim=1477908470546816

FETCH#47019101509648:c=0,e=36,p=0,cr=1,cu=0,mis=0,r=3,dep=0,og=1,plh=3383998547,tim=1477908470546841

STAT #47019101509648 id=1 cnt=4

pid=0 pos=1 obj=87106 op='TABLE ACCESS FULL DEPT (cr=7 pr=6 pw=0 time=498 us

cost=3 size=80 card=4)'

*** 2016-10-31 18:08:35.900

WAIT #47019101509648:

nam='SQL*Net message from client' ela= 45353246 driver id=1650815232 #bytes=1

p3=0 obj#=87106 tim=1477908515900182

#47019101509648:c=0,e=13,dep=0,type=0,tim=1477908515900388

=====================

从上面的trace文件我们可以看出sql语句经过了parse(解析) -> exec(执行) -> fetch(从游标中获取数据)几个过程,其中第一句说明了当前跟踪执行的sql语句的概况,比如使用游标号, sql语句的长度,递归深度等等基本信息:

其中下面含义解释：

(1)第一部分整体trace概览含义

PARSING IN CURSOR

#47019101509648 len=24 dep=0 uid=0 oct=3 lid=0 tim=1477908470545403

hv=911793802 ad='74c73648' sqlid='f6hhpzwv5jrna'

cursor

cursor number

len

sql语句长度

dep

sql语句递归深度

uid

user id

oct

oracle command

type

lid

privilege user id

tim

timestamp，时间戳

hash id

sql address地址,用在v$sqltext

sqlid

sql id

(2)第二部分SQL具体执行过程以及CPU等性能指标含义

PARSE #47019101509648:c=33995,e=65940,p=14,cr=62,cu=0,mis=1,r=0,dep=0,og=1,plh=3383998547,tim=1477908470545401

EXEC

#47019101509648:c=0,e=17,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=3383998547,tim=1477908470545479

FETCH #47019101509648:c=0,e=510,p=6,cr=6,cu=0,mis=0,r=1,dep=0,og=1,plh=3383998547,tim=1477908470546076

FETCH

#47019101509648:c=0,e=36,p=0,cr=1,cu=0,mis=0,r=3,dep=0,og=1,plh=3383998547,tim=1477908470546841

CPU消耗的时间

Elapsed time

number of physical

reads物理读的次数

number of buffers

retrieved for CR reads逻辑读的数据块

number of buffers

retrieved in current mode (current模式读取的数据块)

mis

cursor missed in

the cache库缓存中丢失的游标,硬解析次数

number of rows

processed处理的行数

dep

递归深度

optimizer mode【1：all_rows, 2：first_rows, 3：rule, 4：choose】

plh

plan hash value

tim

timestamp时间戳

(3)第三部分执行过程中发生的等待含义

WAIT #47019101509648: nam='SQL*Net message from client' ela= 644

driver id=1650815232 #bytes=1 p3=0 obj#=87106 tim=1477908470546764

nam

an event that we

waited for等待事件

ela

此操作消耗的时间

block块号

trm

timestamp时间戳

(4)第四部分游标执行计划含义

STAT #47019101509648 id=1 cnt=4 pid=0 pos=1 obj=87106 op='TABLE

ACCESS FULL DEPT (cr=7 pr=6 pw=0 time=498 us cost=3 size=80 card=4)'

cnt

当前行源返回的行数

pid

parent id of this

row source当前行源的父结点id

pos

position in

explain plan执行计划的位置

obj

object id of row

source (if this is a base object)

the row source

access operation

上述逻辑读为7，物理读为6，消耗时间为498us，消耗3，返回记录大小80B，记录数4

(2)tkprof查看

tkprof /U01/app/oracle/diag/rdbms/masterdb/masterdb/trace/masterdb_ora_20596_10046.trc10046_tkprof.trc

TKPROF: Release 11.2.0.4.0 -

Development on Mon Oct 31 18:41:56 2016

Oracle and/or its affiliates.All rights

reserved.

Trace file:

/U01/app/oracle/diag/rdbms/masterdb/masterdb/trace/masterdb_ora_20687_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

********************************************************************************

SQL ID: f6hhpzwv5jrna Plan

Hash: 3383998547

select *

from

scott.dept

callcountcpuelapseddiskquerycurrentrows

------- -------------- ---------- ---------- ----------

--------------------

Parse10.030.06146200

Execute10.000.000000

Fetch20.000.006704

------- -------------- ---------- ---------- ----------

--------------------

total40.030.06206904

Misses in library cache during

parse: 1

Optimizer mode: ALL_ROWS

Parsing user id: SYS

Number of plan statistics

captured: 1

Rows (1st) Rows (avg) Rows

(max)Row Source Operation

---------- ----------

-------------------------------------------------------------

444TABLE ACCESS FULL DEPT (cr=7 pr=6 pw=0 time=498 us cost=3 size=80 card=4)

Elapsed times include waiting

on following events:

Event waited onTimesMax. WaitTotal Waited

----------------------------------------Waited----------------------

SQL*Net message to client20.000.00

Disk file operations I/O10.000.00

db file sequential read10.000.00

db file scattered read10.000.00

SQL*Net message from client245.3545.35

********************************************************************************

其中有Misses in library cache during parse：1则表明解析的时候库缓存丢失游标,也就是说发生了一次硬解析。

注意：

如果session没有被彻底地关闭并且跟踪被停止了，某些重要的trace信息的可能会丢失。这里我们将"statistics_level"设置为all，这是因为有可能这个参数在系统级不是默认值"TYPICAL"(比如BASIC)。为了收集性能相关问题的信息我们需要打开某个级别的statistics。我们推荐在session级将这个参数设置成ALL以便于收集更多的信息，尽管这不是必须的。

2.10046事件进程级别跟踪

如果需要跟踪一个已经存在session，可以用oradebug连接到session上，并发起10046 trace。也可以通过DBMS_SYSTEM.SET_EV系统包来实现。

2.1Oradebug分析其他用户进程trace

查找要跟踪的session信息：

SQL> select

sid,serial#,username from v$session where username is not null;

SIDSERIAL# USERNAME

---------- ----------

------------------------------

18663 SYS

13517081 SYS

19738741 SCOTT

2051491 SCOTT

根据session信息找到对应的进程号SPID：

select p.PID,p.SPID,s.SID from

v$process p,v$session s

where

s.paddr = p.addr and s.sid = &SESSION_ID ;

Enter value for session_id: 205

PID SPIDSID

----------

------------------------ ----------

39 25620205

开启进程追踪：

SQL> oradebug setospid 25620

Oracle pid: 39, Unix process

pid: 25620, image: oracle@node4 (TNS V1-V3)

SQL> oradebug unlimit

Statement processed.

SQL> oradebug event 10046

trace name context forever,level 12

Statement processed.

###也可以通过oradebug使用'setorapid'命令连接到一个session，即oradebug setorapid 39

执行查询：

SQL> select * from dept

where deptno=10;

DEPTNO DNAMELOC

---------- --------------

-------------

10 ACCOUNTINGNEW

YORK

关闭oradebug跟踪：

oradebug event 10046 trace name

context off

查看追踪文件并分析：

SQL>select tracefile from v$process where

addr=(select paddr from v$session where sid=205);

TRACEFILE

--------------------------------------------------------------------------------

/U01/app/oracle/diag/rdbms/masterdb/masterdb/trace/masterdb_ora_25620.trc

可以通过直接查看或者tkprof分析上述trace文件，原理同上。

2.2DBMS_SYSTEM.SET_EV分期其他用户进程trace

语法格式：

exec DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION(SID,SERIAL#,

SQL_TRACE) ;

sid:会话sid

serial#:会话serial#

sql_trace:true or false

exec dbms_system.SET_EV(si,se,ev,le,nm) ;

si：会话sid,来自v$session

se:会话serial#,来自v$session

ev:跟踪事件Num,如10046

le:跟踪事件级别，如1,2,4,8,12

nm:会话用户名，来自v$session

注意：如果想要设置其他进程的上述参数，需要通过DBMS包设置，但tracefile_identifier是无法在别的会话中修改。

具体设置命令为：

SYS.DBMS_SYSTEM.SET_BOOL_PARAM_IN_SESSION(:sid,

:serial,'timed_statistics', true) ;

SYS.DBMS_SYSTEM.SET_INT_PARAM_IN_SESSION(:sid,

:serial,'max_dump_file_size', 2147483647) ;

查询获得需要跟踪的session信息:

SQL>select sid,serial#,username from v$session

where username is not null;

SIDSERIAL# USERNAME

---------- ----------

------------------------------

13517081 SYS

19738741 SCOTT

执行现有会话进程跟踪:

SQL> exec

dbms_system.SET_EV(197,38741,10046,12,'SCOTT') ;

PL/SQL procedure successfully

completed.

SQL> exec

DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION(197,38741,true) ;

PL/SQL procedure successfully

completed.

执行查询操作：

SQL> select * from dept where

deptno<=30;

DEPTNO DNAMELOC

---------- --------------

-------------

10 ACCOUNTINGNEW YORK

20 RESEARCHDALLAS

30 SALESCHICAGO

结束会话跟踪：

SQL> exec

dbms_system.SET_EV(197,38741,10046,0,'SCOTT') ;

PL/SQL procedure successfully

completed.

SQL> exec

DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION(197,38741,false) ;

PL/SQL procedure successfully

completed.

跟踪文件分析：

SQL> select tracefile from

v$process where addr=(select paddr from v$session where sid=197);

TRACEFILE

--------------------------------------------------------------------------------

/U01/app/oracle/diag/rdbms/masterdb/masterdb/trace/masterdb_ora_24413.trc

或者

select pa.value || '/' ||

i.instance_name||'_ora_'||ps.spid||'.trc'

from (selectvalue from v$parameter where name=

'user_dump_dest') pa,

(select s.sid sid,p.spid spid from

v$session s,v$process p where s.PADDR=p.ADDR and s.sid=&&sid) ps,

(select instance_name from v$instance) i;

通过直接查看或者tkprof分析，原理同上。

3.10046事件实例级别跟踪

在实例层设置跟踪需要非常小心，这是因为整体性能会由于所有session都被跟踪而受到影响，这个设置将会跟踪在这个参数设置“以后”创建的每个session。已经存在的session不会被跟踪，系统层的10046跟踪适用于当我们知道问题session会出现，但是不能预先识别它的时候，在这种情况下，可以打开系统层跟踪一小段时间，当问题被重现以后立即将其关闭，然后从已经生成的trace中查找需要的信息，用以下命令打开系统层的跟踪：

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

用以下命令关闭在所有session中的10046跟踪：

alter system set events '10046 trace name context off';

4.10046初始化参数实例级别跟踪

设置以下参数并重新启动实例后，实例上所有的session都会打开跟踪。

event="10046

trace name context forever,level 12"

如果要关闭可以通过移除这个参数并且重启实例，或者使用下面的alter system命令可以关闭跟踪。

alter system set events '10046 trace name context off';

5.10046事件logon

trigger跟踪

有的时候当需要跟踪某个特定用户的操作时，可以使用logon trigger来打开跟踪

CREATE OR REPLACE TRIGGER SYS.set_trace

AFTER LOGON ON DATABASE

WHEN (USER like '&USERNAME')

DECLARE

lcommand varchar(200);

BEGIN

EXECUTE IMMEDIATE 'alter session set

tracefile_identifier=''From_Trigger''';

EXECUTE IMMEDIATE 'alter session set statistics_level=ALL';

EXECUTE IMMEDIATE 'alter session set max_dump_file_size=UNLIMITED';

EXECUTE IMMEDIATE 'alter session set events ''10046 trace name context

forever, level 12''';

END set_trace;

需要注意的事，为了能打开跟踪session,执行trigger的用户需要被显式地授予'alter session'权限

grant alter session to user_db

6.10046事件DBMS

Monitor跟踪

六、参考文档：

1、tkprof分析trace文件

2、10046 trace打开方法

突驰

关注

0
点赞
踩
3

收藏

觉得还不错? 一键收藏
0
评论
oracle 10046详解,10046事件详解

10046事件详解一、10046事件概述10046是一个Oracle的内部事件(event)，通过设置这个事件可以得到Oracle内部执行系统解析、调用、等待、绑定变量等详细的trace信息，即帮助我们解析一条/多条SQL、PL/SQL语句的运行状态，这些状态包括：Parse/Fetch/Execute三个阶段中遇到的等待事件、消耗的物理和逻辑读、CPU时间、执行计划等。它不仅为我们揭示了一条、多...
复制链接

扫一扫