ITPub博客

首页 > Linux操作系统 > Linux操作系统 > Oracle 11g新SQL Trace 10046方法

Oracle 11g新SQL Trace 10046方法

原创 Linux操作系统 作者:realkid4 时间:2013-08-22 22:07:44 0 删除 编辑

 

10046是每一个研究Oracle、进行SQL调优的朋友非常熟悉的工具。1004610053两个诊断事件,可以方便的帮助我们了解Oracle CBO优化器行为和SQL执行行为。在商业非开源的Oracle情况下,我们很多的Internal知识都是源于这两个利器。

 

进入11g之后,Oracle提供了10046的替代Trace方法,原有event方法依然支持。本篇就着重介绍一下新的SQL Trace手段。

 

1、环境和背景介绍

 

我们依然选择Oracle 11gR2作为实验对象,同时创建实验数据表T

 

 

SQL> select * from v$version;

 

BANNER

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

Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - Production

PL/SQL Release 11.2.0.1.0 - Production

CORE        11.2.0.1.0         Production

 

TNS for Linux: Version 11.2.0.1.0 - Production

NLSRTL Version 11.2.0.1.0 – Production

 

 

创建数据表,并且清理shared poolbuffer cache信息。

 

 

SQL> create table t as select * from dba_objects;

Table created

 

SQL> create index idx_t_id on t(object_id);

Index created

 

SQL> exec dbms_stats.gather_table_stats(user,'T',cascade => true);

PL/SQL procedure successfully completed

 

SQL> alter system flush shared_pool;

System altered

 

SQL> alter system flush buffer_cache;

System altered

 

 

2SQL_TRACE方法

 

首先我们查看新接口方法的默认手段。在之前的Oracle版本中,我们有大致上下面几种手段。

 

ü  Alter session set events

ü  Dbms_跟踪包;

ü  Oradebug设置跟踪事件;

ü  初始化参数sql_trace

 

应该说,这几种方法对于Oracle的跟踪非常彻底。在事件10046作用的范围内,所有的SQL,除了目标SQL还有recursive SQL,都会被记录下来到跟踪文件。所以,我们明明发出了一条SQL语句,但是跟踪文件里面包括了很多对数据字典的检索。由此,我们经常需要使用tkprof进行raw文件处理。

 

我们先看下新接口方法使用。先定位到Trace文件位置。

 

 

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

VALUE

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

/u01/diag/rdbms/wilson/wilson/trace/wilson_ora_3663.trc

 

 

开启跟踪。

 

--标记

SQL> alter session set tracefile_identifier='10046';

会话已更改。

 

SQL> alter session set timed_statistics = true;

会话已更改。

 

SQL> alter session set statistics_level=all;

会话已更改。

 

SQL> alter session set max_dump_file_size = unlimited;

会话已更改。

 

--跟踪接口

SQL> alter session set events 'sql_trace level 12';

 

会话已更改。

 

SQL> select /*+demo*/count(*) from t where object_id=1000;

 

  COUNT(*)

----------

         1

 

SQL> alter session set events 'sql_trace off';

 

会话已更改。

 

 

10046有若干的跟踪level,其中level 12包括了所有信息,一般我们作为初学者,把尽可能多的信息获取到比较方便。在sql_trace跟踪接口中,我们可以设置level取值。

 

目标SQL在其中执行。在我们看SQL Trace文件之前,我们先从shared pool中找到这个缓存SQLsql_id。这个id做什么用,我们先留一个话头。

 

 

SQL> select sql_id, executions from v$sqlarea where sql_text like 'select /*+demo*/count(*)%';

 

SQL_ID        EXECUTIONS

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

94wk1cqs4g2f5          1

 

 

我们可以在目录中找到Trace File了。

 

 

[root@bspdev ~]# su - oracle

[oracle@bspdev ~]$ cd /u01/diag/rdbms/wilson/wilson/trace/

[oracle@bspdev trace]$ ls -l | grep 3663

-rw-r----- 1 oracle oinstall    16783 Aug 22 05:55 wilson_ora_3663_10046.trc

-rw-r----- 1 oracle oinstall      158 Aug 22 05:55 wilson_ora_3663_10046.trm

 

 

打开Trace文件,可以发现与目标SQL相关的Recursive SQL都在其中。

 

 

*** 2013-08-22 05:54:47.257

WAIT #1: nam='SQL*Net message from client' ela= 66502048 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=1377122087257296

CLOSE #1:c=0,e=10,dep=0,type=1,tim=1377122087257461

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

PARSING IN CURSOR #2 len=202 dep=1 uid=0 ct=3 lid=0 tim=1377122087259383 hv=3819099649 ad='525e44f4' sqlid='3nkd3g3ju5ph1'

select obj#,type#,ctime,mtime,stime, status, dataobj#, flags, oid$, spare1, spare2 from obj$ where owner#=:1 and name=:2 and namespace=:3 and remoteowner is null and linkname is null and subname is null

END OF STMT

(省略……

CLOSE #2:c=0,e=14391,dep=1,type=3,tim=1377122087295194

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

 

PARSING IN CURSOR #1 len=52 dep=0 uid=0 ct=3 lid=0 tim=1377122087365631 hv=2957478341 ad='525a33fc' sqlid='94wk1cqs4g2f5'

select /*+demo*/count(*) from t where object_id=1000

END OF STMT

(省略……

CLOSE #1:c=0,e=36,dep=0,type=0,tim=1377122102531891

 

 

至此,SQL_TRACE新接口和原来的10046方法就相同了。SQL_TRACE的新功能体现在有针对性SQL语句的跟踪上。

 

3、特定SQL语句跟踪

 

借助新功能,我们可以对特定一个SQL语句进行跟踪,而不是全部SQL的跟踪。

 

我们重新登录,定位跟踪文件。

 

 

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

 

VALUE

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

/u01/diag/rdbms/wilson/wilson/trace/wilson_ora_3858.trc

 

 

跟踪过程。

 

 

SQL> alter session set tracefile_identifier='10046';

会话已更改。

 

SQL> alter session set timed_statistics = true;

会话已更改。

 

SQL> alter session set statistics_level=all;

会话已更改。

 

SQL> alter session set max_dump_file_size = unlimited;

会话已更改。

 

SQL> alter session set events 'sql_trace [sql:94wk1cqs4g2f5] level 12';

会话已更改。

 

SQL> select /*+demo*/count(*) from t where object_id=1000;

  COUNT(*)

----------

         1

 

SQL> alter session set events 'sql_trace off';

会话已更改。

 

 

我们在sql_trace后面写上SQL_ID,就可以实现对特定SQL的跟踪。如果是多条SQL,可以使用|分割。

 

目录上已经形成了Trace文件。

 

 

[oracle@bspdev trace]$ ls -l | grep 3858

-rw-r----- 1 oracle oinstall     2592 Aug 22 06:03 wilson_ora_3858_10046.trc

-rw-r----- 1 oracle oinstall       98 Aug 22 06:03 wilson_ora_3858_10046.trm

 

 

跟踪文件中只有目标SQL

 

 

*** 2013-08-22 06:03:02.369

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

PARSING IN CURSOR #1 len=52 dep=0 uid=0 ct=3 lid=0 tim=1377122582369595 hv=2957478341 ad='525a33fc' sqlid='94wk1cqs4g2f5'

select /*+demo*/count(*) from t where object_id=1000

END OF STMT

EXEC #1:c=0,e=79,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1700799834,tim=1377122582369592

WAIT #1: nam='SQL*Net message to client' ela= 3 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=1377122582369804

FETCH #1:c=0,e=162,p=0,cr=2,cu=0,mis=0,r=1,dep=0,og=1,plh=1700799834,tim=1377122582370006

STAT #1 id=1 cnt=1 pid=0 pos=1 bj=0 p='SORT AGGREGATE (cr=2 pr=0 pw=0 time=0 us)'

STAT #1 id=2 cnt=1 pid=1 pos=1 bj=78013 p='INDEX RANGE SCAN IDX_T_ID (cr=2 pr=0 pw=0 time=0 us cost=1 size=5 card=1)'

FETCH #1:c=0,e=3,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=1700799834,tim=1377122582370884

WAIT #1: nam='SQL*Net message to client' ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=1377122582370936

 

*** 2013-08-22 06:03:08.802

WAIT #1: nam='SQL*Net message from client' ela= 6431961 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=1377122588802921

CLOSE #1:c=0,e=34,dep=0,type=0,tim=1377122588803099

 

 

跟踪目标成功。

 

4、结论

 

Oracle 11g推出了新的跟踪接口,为我们进一步了解执行过程,进行调优提供了基础。

来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/17203031/viewspace-769076/,如需转载,请注明出处,否则将追究法律责任。

请登录后发表评论 登录
全部评论
求道~

注册时间:2010-11-30

  • 博文量
    545
  • 访问量
    7629951