如何收集和查看用来诊断性能问题的Tracev.docx

《如何收集和查看用来诊断性能问题的Tracev.docx》由会员分享，可在线阅读，更多相关《如何收集和查看用来诊断性能问题的Tracev.docx（10页珍藏版）》请在得力文库 - 分享文档赚钱的网站上搜索。

1、一、何为trace10046Event 10046是为Oracle session收集扩展的sql_trace信息的标准方法。每逢与遇到SQL相关性能，我们总是需要收集10046的，来查看和诊断问题。因为10046真实的反响的SQL语句执行的时候的真实信息，解析，执行，获取的时间消耗，row source operation的具体情况，具体等待事件，每个时间具体的时间消耗等等。二、Trace文件的位置11gR1以前:如果是用户进程，10046 trace文件会被生成在user_dump_dest下；如果是后台进程，trace文件会被生成在background_dump_dest下。下面的命令可

2、以显示user_dump_dest: SQL show parameter user_dump_dest11g R1以后:从11gR1开场，Oracle引入了新的诊断构造，以参数DIAGNOSTIC_DEST控制存放trace文件与core文件的路径。可以用以下命令，获取DIAGNOSTIC_DEST的位置： SQL show parameter diagnostic_dest注：下面的某些例子中会设定trace，通过这个设置可以帮助我们更容易的找到生成的trace文件。三、trace10046的使用方法1.基于session/system收集信息：alter session/system s

3、et trace10046;alter session/system set timed_statistics = true;alter session/system set statistics_level=all;alter session/system set max_dump_ = unlimited;alter session/system(慎用) set events 10046 trace name context forever, level 12;- 执行需要被trace的SQL -select * from dual;exit;Alter session/system(慎用

4、) set events 10046 trace name context off;注：1如果session没有被彻底地关闭并且跟踪被停顿了，某些重要的trace信息的可能会丧失。2这里我们将statistics_level设置为all，这是因为有可能这个参数在系统级不是默认值TYPICAL比方 BASIC。为了收集性能相关问题的信息我们需要翻开某个级别的statistics。我们推荐在 session 级将这个参数设置成 ALL 以便于收集更多的信息，尽管这不是必须的。2. 在system级别指定sql_id收集信息： SQL alter system set events sql_trac

5、e sql: 5qcyrymp65fak level=12;关闭 event +：SQL alter system set events sql_trace sql: 5qcyrymp65fak off;注释：event+在system级别指定sql_id,对新起的会话和当前的会话有效， 对其他已经存在的会话无效3. event + 指定某个process的sql_id收集信息：指定检测的会话的spidselect spid from V$process, V$session where audsid=userenv(SESSIONID) and paddr=addr; SQL oradebu

6、g setospid SQL oradebug unlimitSQL oradebug traceSQL oradebug event sql_trace sql: 5qcyrymp65fak level=12关闭 event +：SQL oradebug event sql_trace sql: 5qcyrymp65fak off4. 当不知道SQL_ID时手动执行SQL收集信息：SQLconnect username/passwordSQLalter session set timed_statistics = true;SQLalter session set statistics_le

7、vel=all;SQLalter session set max_dump_ = unlimited;SQL select value from v$diag_info where name=Default Trace File; variable a1 ; exec :a1 := 123123或abded; alter session set events 10046 trace name context forever, level 12;SQLUPDATE /*+ RESTRICT_ALL_REF_CONS */ LBI_ODS.T_O_CUSTOMER_ACCOUNT SET ACCO

8、UNT_TYPE_ID = :a1 WHEREACCOUNT_NO = 1234565; -执行sql重现问题SQLalter session set events 10046 trace name context off; 5.使用Trigger设置10046收集信息：Use a Logon TriggerTo start tracing: create or replace trigger user_logon_trg after logon on database begin if USER = xxxx then execute immediate Alter session set

9、events 10046 trace name context forever, level 8; end if; end; / /* Login a new session as User xxxx and execute your selects to be traced */ To stop tracing: via LogOff Trigger (needs to be created before logging off) create or replace trigger user_logoff_trg before logoff on database begin if USER

10、 = xxxx then execute immediate Alter session set events 10046 trace name context off; end if; end; /的10046收集信息：1 请翻开auto purge的trace begin (service_name=SYS$BACKGROUND, module_name=MMON_SLAVE, action_name=Auto-Purge Slave Action); end; /2 请至少等待一天，请您明天查看时候auto purge被执行，并产生m00x trace文件包含100463关闭auto p

11、urge的trace begin (service_name=SYS$BACKGROUND, module_name=MMON_SLAVE, action_name=Auto-Purge Slave Action); end; /8.Data pump 10046收集信息：1. enable 10046 trace for DM/DW process alter system set events sql_traceprocess: pname=dw | pname=dm level=12;2. Please reproduce the issue, then add TRACE=480300

12、 in data pump importing command3. Please upload data pump importing log and the generated DM/DW process trace To disable the tracing by issuing: alter system set events sql_trace process : pname = dw | pname = dm off; 9.其他方式设置10046：1)DBMS_SUPPORT To start tracing: exec sys.dbms_support.start_trace ;

13、 /* execute your selects to be traced */ To stop tracing: exec sys.dbms_support.stop_trace ; Tracing from Another SessionThe examples below demonstrate how to trace session with SID=18 and Serial# =226 obtained from V$SESSION.2)Using dbms_system.SET_BOOL_PARAM_IN_SESSIONTo start tracing: exec sys.db

14、ms_system.SET_BOOL_PARAM_IN_SESSION(18, 226, sql_trace, TRUE); /* execute your selects to be traced */ To stop tracing: exec sys.dbms_system.SET_BOOL_PARAM_IN_SESSION(18, 226, sql_trace, FALSE);3)Using dbms_system.set_evTo start tracing: exec dbms_system.set_ev(18, 226, 10046, 12, ); To stop tracing

15、: exec dbms_system.set_ev(18, 226, 10046, 0, );4)Using dbms_system.set_sql_trace_in_sessionTo start tracing: exec dbms_system.set_sql_trace_in_session(18,226,TRUE); /* execute your selects to be traced */ To stop tracing: exec dbms_system.set_sql_trace_in_session(18,226,FALSE);5)Using sys.dbms_monit

16、orTo start tracing: exec sys.dbms_monitor.session_trace_enable(session_id=18,serial_num=226, waits=true, binds=true); /* execute your selects to be traced */ To stop tracing: exec sys.dbms_monitor.session_trace_disable(session_id=18,serial_num=226);6)Using Oradebug (as SYS)To start tracing: oradebug

17、 setospid xxxx oradebug event 10046 trace name context forever, level 12; /* In the session being traced execute the selects */ To stop tracing:oradebug event 10046 trace name context off ;四、跟踪一个已经开场的进程如果需要跟踪一个已经存在session，可以用 oradebug连接到session上，并发起10046 trace。首先，用某种方法找到需要被跟踪的session.下面是一个实验的例子:会话1：

18、angel用户conn angel/angel查出会话1的spid即进程idSQL select spid from v$process where addr in (select paddr from v$session where sid in (select sid from v$mystat where rownum =1);SPID18709SPID是操作系统的进程标识符os pidPID是Oracle的进程标识符(ora pid)一旦找到OS PID，就可以用以下命令初始化跟踪：假设需要被跟踪的OSPID是18709。会话2以sysdba的身份登录到SQL*Plus并执行下面的命令

19、：会话2：connect / as sysdbaoradebug setospid 18709这里的18709是进程idoradebug unlimitoradebug event 10046 trace name context forever,level 12会话1：执行查询语句在angel用户下执行查询的语句select * from object where object_id=54530;跟踪过程完成以后，关闭oradebug跟踪：oradebug event 10046 trace name context off查看输出的trace文件的路径oradebug trace!tail

20、 -100f 输出的trace文件用tkprof命令对trace文件进展格式化，使得trace文件的可读性更强。oracleoracle1 trace$ cd /oracle/app/oracle/diag/rdbms/rac/rac1/trace/output = trace_object这里输入希望生成的文件名查看生成的trace10046文件tail -200f trace_object.prf五、如何查trace10046文件oracleoracle1 trace$ cat trace_object.prf TKPROF: Release 11.2.0.4.0 - Developmen

21、t on Tue Nov 8 15:47:41 2021Copyright (c) 1982, 2021, Oracle and/or its affiliates. All rights reserved.Sort options: default-下面这里是指对各个指标的解释*count = number of times OCI procedure was executedcpu = cpu time in seconds executing elapsed = elapsed time in seconds executingdisk = number of physical read

22、s of buffers from diskquery = number of buffers gotten for consistent readcurrent = number of buffers gotten in current mode (usually for update)rows = number of rows processed by the fetch or execute call*-下面是对sql递归查询的解析，即系统表查询的消耗比方select表的时候，它会先去查数据字典查询表的构造的消耗比方去system表空间里面的dba_tables查询所要查询的表这一局部的

23、消耗，相当于文件尾部的OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS ，可以对照看一下SQL ID: 1y2dmwsz263gg Plan Hash: 1359689960-下面的复杂sql可以说是系统解析出来的它如何执行的详解，通俗一点就是指它解析出来自己可以识别出来的语言SELECT /* OPT_DYN_SAMP */ /*+ ALL_ROWS IGNORE_WHERE_CLAUSE NO_PARALLEL(SAMPLESUB) opt_param(parallel_execution_enabled, false) NO_PARALLEL_IND

24、EX(SAMPLESUB) NO_SQL_TUNE */ NVL(SUM(C1),:SYS_B_0), NVL(SUM(C2),:SYS_B_1) FROM (SELECT /*+ IGNORE_WHERE_CLAUSE NO_PARALLEL(OBJECT) FULL(OBJECT) NO_PARALLEL_INDEX(OBJECT) */ :SYS_B_2 AS C1, CASE WHEN OBJECT.OBJECT_ID=:SYS_B_3 THEN :SYS_B_4 ELSE :SYS_B_5 END AS C2 FROM ANGEL.OBJECT SAMPLE BLOCK (:SYS_

25、B_6 , :SYS_B_7) SEED (:SYS_B_8) OBJECT) SAMPLESUBcall count cpu elapsed disk query current rows- - - - - - - -Parse 1 0.00 0.00 0 0 0 0Execute 1 0.00 0.00 0 0 0 0Fetch 1 0.00 0.00 0 65 0 1- - - - - - - -total 3 0.00 0.00 0 65 0 1Misses in library cache during parse: 1-指在library cache解析的次数，相当于上面的pars

26、eMisses in library cache during execute: 1-指在library cache执行的次数，相当于上面的Execute Optimizer mode: ALL_ROWSParsing user id: 84 (recursive depth: 1这里指递归的深度是1)Number of plan statistics captured: 1Rows (1st) Rows (avg) Rows (max) Row Source Operation- - - - 1 1 1 SORT AGGREGATE (cr=65 pr=0 pw=0 time=1624 us

27、)cr一致性读 4162 4162 4162 TABLE ACCESS SAMPLE OBJECT (cr=65 pr=0 pw=0 time=256 us cost=19 size=128650 card=5146)*SQL ID: 1vutkh44h5q2z Plan Hash: 4096911683主要看sqlid下面这一段，指非递归的查询消耗不包括查系统表的消耗，相当于trace文件后面的OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS因为主要的消耗是sql本身执行的消耗，关于系统表解析消耗比拟小，但是关于递归的查询系统表等系统有关的解析也

28、要看一下正不正常，有时候一些bug或者特殊情况也会使递归的解析偏大select * from object where object_id=54530-执行的sql语句parse count: 指在library cache解析的次数，相当于下面的parseexecute count：指在library cache执行次数，相当于下面的Executefetch count：是指select返回的次数像insert，update，delete这种dml，返回的次数是0total count：parse count+execute count+fetch count，即总的count消耗次数cpu

29、：消耗的cputimeelapsed：dbtimecputime+wait不包括非空闲等待disk：物理读query：逻辑读rows：返回的行数call count cpu elapsed disk query current rows- - - - - - - -Parse 1 0.00 0.00 0 66 0 0Execute 1 0.00 0.00 0 0 0 0Fetch 2 0.02 0.25 1232 1236 0 1- - - - - - - -total 4 0.03 0.26 1232 1302 0 1Misses in library cache during parse:

30、 1-在library cache中解析的次数Optimizer mode: ALL_ROWSParsing user id: 84 -解析的useridNumber of plan statistics captured: 1在trace的这段时间中只采样到一次执行方案-执行方案Rows (1st) Rows (avg) Rows (max) Row Source Operation- - - - 1 1 1 TABLE ACCESS FULL OBJECT (cr=1236 pr=1232 pw=0 time=206070 us cost=344 size=4140 card=20)-等待

31、事件Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited - Waited - -*OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS-非递归查询，不包括系统表的查询的消耗，即只sql本身的执行消耗call count cpu elapsed disk query current rows- - - - - - - -Parse 1 0.00 0.00 0 66 0 0Execute 1 0.00 0.00 0 0

32、 0 0Fetch 2 0.02 0.25 1232 1236 0 1- - - - - - - -total 4 0.03 0.26 1232 1302 0 1Misses in library cache during parse: 1Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited - Waited - -OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS-递归查询，系统表查询的消耗call count cpu

33、elapsed disk query current rows- - - - - - - -Parse 1 0.00 0.00 0 0 0 0Execute 1 0.00 0.00 0 0 0 0Fetch 1 0.00 0.00 0 65 0 1- - - - - - - -total 3 0.00 0.00 0 65 0 1Misses in library cache during parse: 1Misses in library cache during execute: 1 2 user SQL statements in session. 0 internal SQL state

34、ments in session. 2 SQL statements in session.*Sort options: default 1 session in tracefile. 2 user SQL statements in trace file. 0 internal SQL statements in trace file. 2 SQL statements in trace file. 2 unique SQL statements in trace file. 136 lines in trace file. 0 elapsed seconds in trace file.六、总结Trace10046的结果相对来说算比拟准确的，在生产中，假设要比对执行方案的优劣，也可以通过trace10046工具，将两个执行方案不同的一样sql放到同一个trace文件中，利用ue等工具截取出主要的局部进展比对。参考文档：sr参考博客：E6%81%AF%E7%9A%84%E6%94%B6%E9%9B%86