Skip to content

performance tuning

性能优化的一点体会

1、优化是基于目标的,我们的最终目的是达到一个目标,而不是做优化。目标的合理性决定了优化项目的成败。刚刚开始给用户优化的时候,我会把所有能够调整的东西一次性全部调整完毕。哪怕有些调整给系统性能带来的好处不到0.1%。对于生产系统,不确定因素十分多,而很多参数方面的调整本身就是双刃剑,如果你无法预期其调整的影响,那么这种调整是存在风险的,在实施的时候就应该慎重考虑。现在我做优化的项目,往往会根据用户的优化目标,然后在此基础上进行分析,制定方案,实施的结果虽然一般会超出客户的期望,但是我不会在生产系统上做一些没把握的事情。锦上添花的事情,有时候也要考虑考虑,是否值得,因为弄不好,锦上添花会变成画蛇添足。
2、1+1不一定大于1,在优化过程中,抓住主要矛盾,解决主要问题,而不要胡子眉毛一把抓。很多调整之间有关联性,甚至是互斥的,不合理的调整可能带来更坏的结果。
3、客户需要的是系统的优化,而不仅仅是DB的优化。客户的目标里,看到的是一个系统,而不是一个孤立的DB。在10年前,我可能会说,OS的问题,你们还是找一下厂家。而现在,我会对客户说,你放心,我们做的是系统优化。
4、用适当的方式和应用开发厂商配合。很多优化项目由于无法和应用厂商有效的配合,其效果大打折扣。因为应用是和系统性能关系最为紧密的。如果应用开发厂商不能很好的配合,那么优化项目将举步维艰。如果你和开发厂商说,“你这个SQL开销太大,需要修改一下”,那么得到可能就是强烈的反对。如果你说“这个SQL开销太大,我给你们提供了几个方案,第一是,。。。”,这样你很可能会得到比较好的结果。你是优化专家,找出几个TOP SQL这样的工作,不需要专家来完成,而专家的职责,不仅仅是发现TOP SQL,而是如何解决掉TOP SQL。
5、不要相信什么优化规则,实际上并没有条条框框限制你,实现目标的任何方法你都可以使用。对于一个初级DBA来说,可能老DBA会告诉你,什么是对的,什么是不对的。而对错都是相对的,如果你已经深刻的理解了Oracle以及系统优化,那么就像金庸小说里的内功高手一样,无招胜有招。

对于老白的几个观点,深深的赞同!

SPM固定执行计划以及踩bug事一件

原有2个sql语句有多个表连接,执行计划一直在走错误的执行计划.表级统计信息以及索引规划都已经是最新(这里统计信息有狗血不做描述),只是SQL里还有六个绑定变量以及字段的柱状图影响了执行计划,在这个优化里没有删除柱状图和对绑定变量的影响进行处理(星形连接不建议使用绑定变量),现场环境微妙最终选择通过sql profile以及spm对这2个sql的执行计划进行固定处理.先用sqlprofile固定后让sql重新解析后发现未能生效,逐用spm的方式固定.

这里以其中一个sql_id为bwwnw7r1gzhdf的语句为例,这是收集到对应1个小时内的sqlrpt,其中plan_hash_value为711942702执行计划为正确的执行计划,从报告中可以看到这个sql选择了错误的执行计划,并且从中也可以看到sql有多个执行计划.当中执行计划正确与否的判断方式就不做描述.
 

SQL ID: bwwnw7r1gzhdf

# Plan Hash Value Total Elapsed Time(ms) Executions 1st Capture Snap ID Last Capture Snap ID
1 3052678239 13,512,877 10 25060 25060
2 3392573872 0 0 25060 25060
3 4134955434 0 0 25060 25060
4 1564064893 0 0 25060 25060
5 2504448979 0 0 25060 25060
6 147966509 0 0 25060 25060
7 711942702 0 0 25060 25060

 
通过coe_xfr_sql_profile.sql脚本对bwwnw7r1gzhdf的sql进行固定711942702,生成sql profile的名字为coe_bwwnw7r1gzhdf_711942702.
(该部分可以参考
1.Using Sqltxplain to create a ‘SQL Profile’ to consistently reproduce a good plan (文档 ID 1487302.1)
2.Automatic SQL Tuning and SQL Profiles (文档 ID 271196.1)
3.Correcting Optimizer Cost Estimates to Encourage Good Execution Plans Using the COE XFR SQL Profile Script (文档 ID 1955195.1))

让sql从新解析后从v$sql视图中的sql profile字段没有看到生效的迹象,原因是在脚本coe_xfr_sql_profile.sql中对创建的sqlprofile默认的生效是false的,所以创建出来的profile不会失效,监控中的执行计划未变(现场我对此处的profile drop).

 

SQL>  select name,created,status from dba_sql_profiles;

NAME                           CREATED                        STATUS
------------------------------ ------------------------------ --------
coe_bwwnw7r1gzhdf_711942702    26-JUN-15 02.09.30.000000 PM   ENABLED
coe_g87an0j5djjpm_334801256    26-JUN-15 11.30.25.000000 AM   ENABLED

SQL>  select SQL_ID, SQL_PROFILE,PLAN_HASH_VALUE from V$SQL where SQL_ID='bwwnw7r1gzhdf' and sql_profile is not null;

no rows

SQL>  select sql_profile,EXECUTIONS,PLAN_HASH_VALUE,parse_calls,ELAPSED_TIME/1000000,
ELAPSED_TIME/1000000/EXECUTIONS,LAST_LOAD_TIME,ROWS_PROCESSED
from v$sql where EXECUTIONS>0 and sql_id='bwwnw7r1gzhdf' order by LAST_LOAD_TIME desc;
...

逐对profile进行disable并drop

=====disable profile==============
BEGIN
DBMS_SQLTUNE.ALTER_SQL_PROFILE(
name => 'coe_bwwnw7r1gzhdf_711942702',
attribute_name => 'STATUS',
value => 'DISABLED');
END;
/

BEGIN
DBMS_SQLTUNE.ALTER_SQL_PROFILE(
name => 'coe_g87an0j5djjpm_334801256',
attribute_name => 'STATUS',
value => 'ENABLED');
END;
/

=====drop profile=================
begin
DBMS_SQLTUNE.DROP_SQL_PROFILE(name => 'coe_bwwnw7r1gzhdf_711942702');
end;
/

begin
DBMS_SQLTUNE.DROP_SQL_PROFILE(name => 'coe_g87an0j5djjpm_334801256');
end;
/

由于已经存在了正确的执行计划,所以通过DBMS_SPM直接创建baseline,并通过DBMS_SPM包对该sql的baseline的enable,accept,fixed三个属性指定为yes.

该部分可以参考:
Plan Stability Features (Including SQL Plan Management (SPM)) (文档 ID 1359841.1)

为sql创建baseline

variable cnt number;
execute :cnt :=DBMS_SPM.LOAD_PLANS_FROM_CURSOR_CACHE(SQL_ID => 'bwwnw7r1gzhdf', PLAN_HASH_VALUE => 711942702) ;

验证该baseline已经生成

SQL> set linesize 200
SQL> Select Sql_Handle, Plan_Name, Origin, Enabled, Accepted,Fixed,Optimizer_Cost,Sql_Text
From Dba_Sql_Plan_Baselines
Where Sql_Text Like '%FROM P1EDBADM.MES_PROCESSOPERATIONSPEC%' Order By Last_Modified;


SQL_HANDLE                     PLAN_NAME                      ORIGIN         ENA ACC FIX OPTIMIZER_COST SQL_TEXT
------------------------------ ------------------------------ -------------- --- --- --- -------------- --------------------------------------------------------------------------------
SQL_995463d3d1edd710           SQL_PLAN_9kp33ug8yvpsh4af503b5 MANUAL-LOAD    YES YES NO              69 SELECT D.LOTNAME LOT, D.PRODUCTNAME GLASS, TO_CHAR(D.CREATETIME, 'YYYY-MM-DD HH2

为sqlbaseline的fixed属性改为yes

variable cnt number;
execute :cnt :=DBMS_SPM.LOAD_PLANS_FROM_CURSOR_CACHE(SQL_ID => 'bwwnw7r1gzhdf', PLAN_HASH_VALUE => 711942702,fixed => 'yes') ;
验证修改完成
SQL> set linesize 200
SQL> Select Sql_Handle, Plan_Name, Origin, Enabled, Accepted,Fixed,Optimizer_Cost,Sql_Text
  2  From Dba_Sql_Plan_Baselines
  3  Where Sql_Text Like '%FROM P1EDBADM.MES_PROCESSOPERATIONSPEC%' Order By Last_Modified;

SQL_HANDLE                     PLAN_NAME                      ORIGIN         ENA ACC FIX OPTIMIZER_COST SQL_TEXT
------------------------------ ------------------------------ -------------- --- --- --- -------------- --------------------------------------------------------------------------------
SQL_995463d3d1edd710           SQL_PLAN_9kp33ug8yvpsh4af503b5 MANUAL-LOAD    YES YES YES            574 SELECT D.LOTNAME LOT, D.PRODUCTNAME GLASS, TO_CHAR(D.CREATETIME, 'YYYY-MM-DD HH2

最终验证生效

SQL> Select Sql_Handle, Plan_Name, Origin, Enabled, Accepted,Fixed,Optimizer_Cost,Sql_Text
  2  From Dba_Sql_Plan_Baselines
  3  Where Sql_Text Like '%FROM P1EDBADM.MES_PROCESSOPERATIONSPEC%' Order By Last_Modified;

SQL_HANDLE                     PLAN_NAME                      ORIGIN         ENA ACC FIX OPTIMIZER_COST SQL_TEXT
------------------------------ ------------------------------ -------------- --- --- --- -------------- --------------------------------------------------------------------------------
SQL_995463d3d1edd710           SQL_PLAN_9kp33ug8yvpsh4af503b5 MANUAL-LOAD    YES YES YES            574 SELECT D.LOTNAME LOT, D.PRODUCTNAME GLASS, TO_CHAR(D.CREATETIME, 'YYYY-MM-DD HH2
SQL_2e1c8025edb165b3           SQL_PLAN_2w7404rqv2tdm56eb6fa8 MANUAL-LOAD    YES YES YES            311 SELECT 1 " ", D.LOTNAME LOT, D.PRODUCTNAME GLASS, TO_CHAR(MAX(H.EVENTTIME), 'YYY

SPM主要和2个参数有关,一个是baseline生效(optimizer_user_sql_plan_baselines,前提是accept属性要为yes,否则会产生干扰),一个是捕获sql语句生成baseline(optimizer_cature_sql_plan_baselines).在数据库中我一般不开启捕获,但是开启baseline生效.
开启的语法:

alter system set optimizer_user_sql_plan_baselines=true scope=both;
alter system set optimizer_cature_sql_plan_baselines=true scope=both;

关闭的语法:

alter system set optimizer_user_sql_plan_baselines=false scope=both;
alter system set optimizer_cature_sql_plan_baselines=false scope=both;

开启捕获的情况在一些11g版本中会触发该bug
Bug 9910484 – SQL Plan Management Capture uses excessive space in SYSAUX (文档 ID 9910484.8)
此bug会造成sysaux的表空间暴增,主要为sqllob$data,我遇见的是在一天内从2g增长到4g.关闭了捕获后,该现象消失.
删除掉不必要的baseline后可以通过shrink的方式回收sysaux的空间,具体可以参考
Reducing the Space Usage of the SQL Management Base in the SYSAUX Tablespace (文档 ID 1499542.1)

Cardinality Feedback与_optimizer_use_feedback的使用建议

该参数与Cardinality Feedback特性有关,优化器可以估算基数不正确的原因有很多,如缺少的统计信息,不准确的统计数据,或复杂的谓词,基数统计反馈有助于优化器生成更合理的执行计划.对于此特性我不作科普了,比较详细的资料可以参考以下文档:

1.Tuning-by-Cardinality-Feedback.pdf
2.Statistics (Cardinality) Feedback – Frequently Asked Questions (文档 ID 1344937.1)

该特性其实从10g版本就已经开始引入,只是它的应用受限于optimizer_dynamic_sampling参数,在11g以前的10g版本中,只有在optimizer_dynamic_sampling=4以上的情况下才会被用到该特性.这个在10g版本中可以通过HINT语法
/*+ dynamic_sampling (customer 4) */或者在session/system中将optimizer_dynamic_sampling设置为4进行测试.

判断SQL是否使用了CF可以通过sql的执行计划中的note提示或者视图V$SQL_SHARED_CURSOR的USE_FEEDBACK_STATS字段进行.

执行计划中的note提示

Predicate Information (identified by operation id):
---------------------------------------------------

 6 - filter(ROWNUM>0)
 8 - access("DATA"."OBJECT_NAME"="T"."COLUMN_VALUE")

Note
-----
- Cardinality Feedback used for this statement

V$SQL_SHARED_CURSOR


column use_feedback_stats format a18
column sql_text format a80

select c.child_number, c.use_feedback_stats , s.sql_text from v$sql_shared_cursor c,v$sql s
where s.sql_id=c.sql_id and c.sql_id = 'an4zdfz0h7513'
and s.child_number= c.child_number;

CHILD_NUMBER USE_FEEDBACK_STATS SQL_TEXT
------------ ------------------ ------------------------------------------------------------
           0 Y                   select * from TABLE(cast( str_func('A,B,C' ) as s_type) ) t
           1 N                   select * from TABLE(cast( str_func('A,B,C' ) as s_type) ) t

对使用了基数统计回馈特性的sql,可以在10053的trace文件中发现sql被转化成带了hint opt_estimate的语法.
CF特性的功能是非常不错的,oracle在使用了cf反馈评估后更准确的统计数据后会根据此数据生成对于的plan,在再次的执行中还会持续评估统计信息是否准确,以此重复解析,参考如下:

When a cursor is found to be a candidate for Statistics Feedback it will be hard parsed again using the new estimates. The child cursor will be marked as not being shareable and USE_FEEDBACK_STATS set to ‘Y’ in V$SQL_SHARED_CURSOR.
Note: As the need for Statistics Feedback was only detected while execution of this cursor, Statistics Feedback will not actually be used for this child. However it will be used for all further child cursors created.

At the next execution, as a result of the cursor being marked as not shareable, a hard parse will again be performed and a new child created with the optimizer having used the new estimates for creating an optimizer plan.

但是由于cf的评估结果数据只存在内存中(重启之后就需要重新来过),在session之间是不可共用的,并且由于在11g中存在了过多的bug,常见的问题就是在第二次执行sql时候性能下降较多.因此我在11g的数据库中往往会对11.2.0.4以下的数据库会将该特性关闭.

部分bug list

feedback bug

关闭CF特性的方法即是将_optimizer_use_feedback设置为false.

alter session set "_optimizer_use_feedback" = false;
或者
alter system set "_optimizer_use_feedback" = false;

skip_unusable_indexes参数使用建议

​SKIP_UNUSABLE_INDEXES的使用与索引失效是相关的,该参数10g开始引入,11g默认为TRUE.
当为TRUE时候,如果数据库中存在usable状态的索引,则会自动忽略该索引生成新的执行计划(不走该索引,也不提示该索引的异常);当为False时候,则会报错.我所运维的数据库在一些关键系统中,会将此参数设成False,让系统及时发现索引的异常以便及时去介入修复.
环境各有所异,设置值也可依据实际情况设置.如果sql使用了hint或者涉及到唯一索引的对应DML,该参数会失效.

该参数的一些使用场景可以参考如下的测试:

创建测试表和索引

SQL> conn test/test
已连接。
SQL> drop table a;
表已删除。
SQL> create table a(id number);
表已创建。
SQL> create unique index idx_a_id on a(id);
索引已创建。
SQL> declare
  2  begin
  3  for a in 1..1000 loop
  4  insert into a(id) values(a);
  5  end loop;
  6  end;
  7  /
PL/SQL 过程已成功完成。
SQL> commit;
提交完成。
SQL> show parameter SKIP_UNUSABLE_INDEXES;
NAME                                 TYPE        VALUE
------------------------------------ ----------- -------------------
skip_unusable_indexes                boolean     TRUE
SQL> select * from a where id=1;

执行计划
----------------------------------------------------------
Plan hash value: 277080427
------------------------------------------------------------------------------
| Id  | Operation         | Name     | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |          |     1 |    13 |     1   (0)| 00:00:01 |
|*  1 |  INDEX UNIQUE SCAN| IDX_A_ID |     1 |    13 |     1   (0)| 00:00:01 |
------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
   1 - access("ID"=1)

统计信息
----------------------------------------------------------
          1  recursive calls
          0  db block gets
          4  consistent gets
          0  physical reads
        124  redo size
        402  bytes sent via SQL*Net to client
        385  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

修改skip_unusable_indexes为false

SQL> alter system set skip_unusable_indexes=false scope=memory;
系统已更改。
将索引修改为不可用
SQL> alter index idx_a_id unusable;
索引已更改。
出现错误提示索引不可用
SQL> select * from a where id=1;
select * from a where id=1
*
第 1 行出现错误:
ORA-01502: 索引 'TEST.IDX_A_ID' 或这类索引的分区处于不可用状态

将skip_unusable_indexes修改为true

SQL> alter system set skip_unusable_indexes=true scope=memory;
系统已更改。

对于查询操作此时该sql能够正常运行,但是此时进行的是全表扫描

SQL> select * from a where id=1;

执行计划
----------------------------------------------------------
Plan hash value: 2248738933
--------------------------------------------------------------------------
| Id  | Operation         | Name | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |      |     4 |    52 |     3   (0)| 00:00:01 |
|*  1 |  TABLE ACCESS FULL| A    |     4 |    52 |     3   (0)| 00:00:01 |
--------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter("ID"=1)

统计信息
----------------------------------------------------------
          1  recursive calls
          0  db block gets
          8  consistent gets
          0  physical reads
          0  redo size
        402  bytes sent via SQL*Net to client
        385  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

使用hint强制使用索引,此时会提示索引无效

SQL> select /*+index(a)*/ * from a where id=1;
select /*+index(a)*/ * from a where id=1
*
第 1 行出现错误:
ORA-01502: 索引 'TEST.IDX_A_ID' 或这类索引的分区处于不可用状态
--插入操作会出错
SQL> insert into a values(1002);
insert into a values(1002)
*
第 1 行出现错误:
ORA-01502: 索引 'TEST.IDX_A_ID' 或这类索引的分区处于不可用状态
SQL> delete from a where id=1;
delete from a where id=1
*
第 1 行出现错误:
ORA-01502: 索引 'TEST.IDX_A_ID' 或这类索引的分区处于不可用状态

SQL>

解决方法,重建索引

SQL> alter index test.idx_a_id rebuild;
索引已更改。
SQL> select /*+index(a)*/ * from a where id=1;

执行计划
----------------------------------------------------------
Plan hash value: 277080427
------------------------------------------------------------------------------
| Id  | Operation         | Name     | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |          |     1 |    13 |     1   (0)| 00:00:01 |
|*  1 |  INDEX UNIQUE SCAN| IDX_A_ID |     1 |    13 |     1   (0)| 00:00:01 |
------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
   1 - access("ID"=1)

统计信息
----------------------------------------------------------
         15  recursive calls
          0  db block gets
          5  consistent gets
          1  physical reads
          0  redo size
        402  bytes sent via SQL*Net to client
        385  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

SQL> drop index test.idx_a_id;
索引已删除。
SQL> create index test.idx_a_id on a(id);
索引已创建。
SQL> alter index test.idx_a_id unusable;
索引已更改。
SQL> insert into a values(1002);
已创建 1 行。
SQL> commit;

测试证明SKIP_UNUSABLE_INDEXES对于使用hint强制使用索引的语句和唯一索引的插入、删除语句却不能生效。

该测试摘自互联网,同时做了一些修改.

Oracle full table scan 的跟踪监视

最近一个客户的数据库反应不定时的性能问题,经过跟踪发现是一系列的全表扫相关SQL,其中还碰到了比较诡异的全表扫都是顺序读的情况.和周亮以前也讨论过此类情况只是当时这方面的事情并没有太多的眉目,这次跟踪发现了是和undo一致性读有关,还存在大量的row chains.当然这里不讨论这个case,这个case可能会在新书中描述.这个文章不描述具体的原理,只是作为一个对数据库全表扫相关信息收集诊断建议.

在跟踪某一特定的事件时候,有时候没有监控系统或者其他相关捕获信息的手段,则诊断起来比较耗时间,比如跟踪系统中全表扫的情况,默认情况下是只能获取当时时刻具体的情况,这里介绍通过AWR记录中来获取相关的信息,由于AWR从v$sql里面获取的sql是有条件限制的,因此该方法并不能补全数据库中所有的全表扫相关sql(其他情况也是),因为awr收集sql的情况是以statistics_level 的设置为依赖,typical(top 30)或者all(top 100)收集的top sql信息不同.

 

1.周期的全表扫信息

col c1 heading "Day|Hour" format a20
col c2 heading "Full TABLE scan|Count" format 999,999
BREAK ON c1 skip 2
BREAK ON c2 skip 2
SELECT TO_CHAR(sn.begin_interval_time,'hh24') c1,
COUNT(1) c2
FROM dba_hist_sql_plan p,
dba_hist_sqlstat s,
dba_hist_snapshot sn,
dba_segments o
WHERE p.object_owner <> 'SYS'
AND p.object_owner = o.owner
AND p.object_name = o.segment_name
AND o.blocks > 1000
AND p.operation LIKE '%TABLE ACCESS%'
AND p.options LIKE '%FULL%'
AND p.sql_id = s.sql_id
AND s.snap_id = sn.snap_id
GROUP BY TO_CHAR(sn.begin_interval_time,'hh24')
ORDER BY 1;

查询结果类似如下:

Large Full-table scans Per Snapshot Period
Begin
 Interval FTS
 time Count
 -------------------- --------
 04-10-18 11 4
 04-10-21 17 1
 04-10-21 23 2
 04-10-22 15 2
 04-10-22 16 2
 04-10-22 23 2
 04-10-24 00 2

2.每小时的全表扫信息

col c1 heading "Day|Hour" format a20
col c2 heading "Full TABLE scan|Count" format 999,999
BREAK ON c1 skip 2
BREAK ON c2 skip 2
SELECT TO_CHAR(sn.begin_interval_time,'hh24') c1,
  COUNT(1) c2
FROM dba_hist_sql_plan p,
  dba_hist_sqlstat s,
  dba_hist_snapshot sn,
  dba_segments o
WHERE  p.object_owner <> 'SYS'
AND p.object_owner                                    = o.owner
AND p.object_name                                     = o.segment_name
AND o.blocks                                          > 1000
AND p.operation LIKE '%TABLE ACCESS%'
AND p.options LIKE '%FULL%'
AND p.sql_id  = s.sql_id
AND s.snap_id = sn.snap_id
GROUP BY TO_CHAR(sn.begin_interval_time,'hh24')
ORDER BY 1;

查询结果类似如下:

Large Table Full-table scans
Averages per Hour

Day                       FTS
Hour                    Count
-------------------- --------
00                          4
10                          2
11                          4
12                         23
13                         16
14                          6
15                         17
16                         10
17                         17
18                         21
19                          1
23                          6

3.基于星期的全表扫信息

col c1 heading "Week|Day" format a20
col c2 heading "Full TABLE scan|Count" format 999,999
BREAK ON c1 skip 2
BREAK ON c2 skip 2
SELECT TO_CHAR(sn.begin_interval_time,'day') c1,
  COUNT(1) c2
FROM dba_hist_sql_plan p,
  dba_hist_sqlstat s,
  dba_hist_snapshot sn,
  dba_segments o
WHERE  p.object_owner <> 'SYS'
AND p.object_owner                                    = o.owner
AND p.object_name                                     = o.segment_name
AND o.blocks                                          > 1000
AND p.operation LIKE '%TABLE ACCESS%'
AND p.options LIKE '%FULL%'
AND p.sql_id  = s.sql_id
AND s.snap_id = sn.snap_id
GROUP BY TO_CHAR(sn.begin_interval_time,'day')
ORDER BY 1;

查询结果类似如下:

Week                      FTS
Day                     Count
-------------------- --------
sunday                      2
monday                     19
tuesday                    31
wednesday                  34
thursday                   27
friday                     15
Saturday                    2

以上脚本作者为Donald K. Burleson.
我对此脚本做了些变更,除了生成html格式外额外加入索引类的信息,变更的脚本未在blog上发布.

索引块上递归事务专用的itl slot争用的识别判断

承接《Oracle10g版本后enq: TX – allocate ITL entry等待事件的根源以及解决思路》

由于itl争用主要是initrans不足(10g后今本不受此影响maxtrans失效),块空间不足原因引起,但是特殊的情况下的索引递归事务引起的itl争用的识别也是需要掌握的技术,虽然大量的递归情况较少见,但如何区分相比前面的2种情况就相对复杂点。主要的思路是根据索引块的itl信息来识别,因为上一篇中讲到在索引的枝节点上,有且只有一个ITL slot,它是用于当发生节点分裂的递归事务(Recursive Transaction)。在叶子节点上,第一条ITL Slot也是用于分裂的递归事务的。只要根据相关索引块的负责递归事务的itl事务槽的使用情况就可以判断争用的情况。

思路如下:
1.找出被阻塞的事务
2.根据阻塞的事务找到相关的回滚块以及相关事务起始回滚编号
3.根据回滚块的内容识别相关的索引块
4.dump出相关的索引块识别对应的itl争用情况

例子:

1.测试阻塞

session 1 更新61080块的100行

SQL> update luda set a=a
  2  where dbms_rowid.ROWID_BLOCK_NUMBER(rowid)=61080
  3  and dbms_rowid.ROWID_ROW_NUMBER(rowid)=100;

1 row updated.

commit;

session 2 更新61080块的200行

SQL> update luda set a=a
  2  where dbms_rowid.ROWID_BLOCK_NUMBER(rowid)=61080
  3  and dbms_rowid.ROWID_ROW_NUMBER(rowid)=200;

1 row updated.

commit;

session 3 更新61080块的300行

SQL> update luda set a=a
  2  where dbms_rowid.ROWID_BLOCK_NUMBER(rowid)=61080
  3  and dbms_rowid.ROWID_ROW_NUMBER(rowid)=300;

1 row updated.

session 4 更新61080块的400行

SQL> update luda set a=a
  2  where dbms_rowid.ROWID_BLOCK_NUMBER(rowid)=61080
  3  and dbms_rowid.ROWID_ROW_NUMBER(rowid)=400;

1 row updated.

session 5 更新61080块的500行hang住

2.找出被阻塞的事务以及相关回滚段信息

确认itl阻塞:

SQL> select s.sid, s.event, s.row_wait_obj#
  2  from v$session s where s.sid=151;

       SID EVENT                          ROW_WAIT_OBJ#
---------- ------------------------------ -------------
       148 enq: TX - allocate ITL entry              -1

确认对应的阻塞事务的回滚相关信息,可以发现阻塞事务对应的回滚在2号数据文件的2109数据块中,起始的回滚记录是0x2e(46的16进制)

SQL> select l.sid req_session, s.sid lock_session, l.lmode, l.request, t.xidusn, t.xidslot, t.start_ubafil, t.start_ubablk, t.start_ubarec
  2  from v$lock l, v$transaction t, v$session s
  3  where l.type = 'TX'
  4  and trunc(id1/power(2,16)) = t.xidusn
  5  and l.id2 = t.xidsqn
  6  and id1 - power(2,16)*trunc(id1/power(2,16)) = t.xidslot
  7  and t.addr = s.taddr
  8  and l.request = 4;

REQ_SESSION LOCK_SESSION      LMODE    REQUEST     XIDUSN    XIDSLOT START_UBAFIL START_UBABLK START_UBAREC
----------- ------------ ---------- ---------- ---------- ---------- ------------ ------------ ------------
        148          159          0          4          5         26            2         2109           46

dump出2号数据文件的2109号数据块

SQL> alter system dump datafile 2 block 2109;

System altered.

确认相关对象的object_id

SQL> select object_name,object_id,data_object_id from dba_objects where object_name in ('LUDA','IDX_TEST') and owner='SYS';

OBJECT_NAME                               OBJECT_ID DATA_OBJECT_ID
---------------------------------------- ---------- --------------
IDX_TEST                                      51980          51980
LUDA                                          51978          51978

分析2号数据文件的2109号数据块dump文件,从Rec #0x2e部分开始到结束只有0x2e此条与对象号51980,51978相关回滚记录

*-----------------------------
* Rec #0x2e  slt: 0x1a  objn: 51978(0x0000cb0a)  objd: 51978  tblspc: 0(0x00000000)
*       Layer:  11 (Row)   opc: 1   rci 0x00
Undo type:  Regular undo    Begin trans    Last buffer split:  No
Temp Object:  No
Tablespace Undo:  No
rdba: 0x00000000
*-----------------------------
uba: 0x0080083d.014b.2d ctl max scn: 0x0000.000bb362 prv tx scn: 0x0000.000bb37b
txn start scn: scn: 0x0000.000bcdc1 logon user: 0
 prev brb: 8388917 prev bcl: 0
KDO undo record:
KTB Redo
op: 0x04  ver: 0x01
op: L  itl: xid:  0x0002.010.0000013b uba: 0x00800051.0100.3c
                      flg: C---    lkc:  0     scn: 0x0000.000bcd90
KDO Op code: URP row dependencies Disabled
  xtype: XAxtype KDO_KDOM2 flags: 0x00000080  bdba: 0x0040ee98  hdba: 0x0040ee91
itli: 1  ispac: 0  maxfr: 4863
tabn: 0 slot: 400(0x190) flag: 0x2c lock: 0 ckix: 71
ncol: 1 nnew: 1 size: 0
Vector content:
col  0: [ 3]  c2 31 06

End dump data blocks tsn: 1 file#: 2 minblk 2109 maxblk 2109

从bdba地址分析可以获得当前更新对象对luda,前面更新提交的1条语句的部分就是luda的61080号块。

SQL> select dbms_utility.data_block_address_file(TO_NUMBER('0040ee98', 'XXXXXXXX')) file_id,
  2  dbms_utility.data_block_address_block(TO_NUMBER('0040ee98', 'XXXXXXXX')) block_id from dual;

   FILE_ID   BLOCK_ID
---------- ----------
         1      61080

在回滚信息中没有发现索引块类型,事务对象只有objno为51978的luda表,类似的索引对象也是用此方法分析。

Oracle10g版本后enq: TX – allocate ITL entry等待事件的根源以及解决思路

客户昨日一套核心系统有进程挂住,top等待事件为enq: TX – allocate ITL entry,判断为itl争用的原因,这方面以前做了不少测试并没有整理,这里顺便做个整理作为诊断手段用。该内容主要分为主要的三个部分:

一.itl的解释以及原理
二.数据块上的initrans不能扩展分配slot导致的itl争用测试
三.索引块上递归事务专用的itl slot争用的识别判断

 

一.ITL原理解释

ITL(Interested Transaction List)是Oracle数据块内部的一个组成部分,用来记录该块所有发生的事务,一个itl可以看作是一个记录,在一个时间,可以记录一个事务(包括提交或者未提交事务)。当然,如果这个事务已经提交,那么这个itl的位置就可以被反复使用了,因为itl类似记录,所以,有的时候也叫itl槽位。Oracle的每个数据块中都有一个或者多个事务槽,每一个对数据块的并发访问事务都会占用一个事务槽。 表和索引的事务槽ini_trans是1、max_trans是255,在oracle10g中,不能修改max_trans这个参数,因为oracle10g忽略了这个参数。如果一个事务一直没有提交,那么,这个事务将一直占用一个itl槽位,itl里面记录了事务信息,回滚段的嵌入口,事务类型等等。如果这个事务已经提交,那么,itl槽位中还保存的有这个事务提交时候的SCN号。如dump一个块,就可以看到itl信息:

Itl           Xid                  Uba         Flag  Lck        Scn/Fsc
0x01   0x0006.002.0000158e  0x0080104d.00a1.6e  --U-  734  fsc 0x0000.6c9deff0
0x02   0x0000.000.00000000  0x00000000.0000.00  ----    0  fsc 0x0000.00000000

如果在并发量特别大的系统中,最好分配足够的itl个数(10g之前的版本),其实它并浪费不了太多的空间,或者,设置足够的pctfree,保证itl能扩展,但是pctfree有可能是被行数据给消耗掉的,如update可能一下占满块空间,所以,也有可能导致块内部的空间不够而导致itl等待,所以在通常情况下,10g版本后引起itl等待的原因往往是因为块的空间不足导致,并不是tran事务槽数量不足,在正常情况下2k的数据块最多可以拥有41个itl,4k数据块最多拥有83,8k最多用友169个itl(以itl 24byte为单位)。INITRANS不足的问题不会出现在索引数据块上,当发现没有足够空间分配ITL slot时,无论是枝点块还是叶子块,数据块会发生分裂(Index Block Split)。

有一种特殊情况也会引起ITL的等待,就是在索引上的递归事务itl争用,这种情况比较特殊。在索引的枝节点上,有且只有一个ITL slot,它是用于当发生节点分裂的递归事务(Recursive Transaction)。在叶子节点上,第一条ITL Slot也是用于分裂的递归事务的。在一个用户事务中,如果发生多次分裂,每一次分裂都是由一个单独的递归事务控制的,如果下层节点分裂导致其父节点分裂,它们的分裂则由同一个递归事务控制。当2个事务同时需要分裂一个枝节点或者叶子节点时,或者枝节点下的2个子节点分别被2个事务分裂,就会造成这种ITL等待。

 

2.数据块上的initrans不能扩展分配slot导致的itl争用测试

我们做个测试关于如果数据块没有空间留给itl slot扩展时候的测试,创建表luda,指定pctfree为0,同时指定initrans为1然后填满相关数据块,再对块满的数据进行更新模拟出itl的等待。
创建表luda,并指定pctfree为0,initrans为1

SQL> create table luda(a int) pctfree 0 initrans 1;

Table created.

 

插入大量数据

SQL> begin
2 for i in 1..20000 loop
3 insert into luda values(i);
4 end loop;
5 end;
6 /

PL/SQL procedure successfully completed.

SQL> commit ;

Commit complete.

 

SQL> select f,b,count(*) from (select dbms_rowid.rowid_relative_fno(rowid) f,dbms_rowid.rowid_block_number(rowid) b
2 from luda) group by f,b order by 3;

F B COUNT(*)
---------- ---------- ----------
1 61101 200
1 61093 734
1 61089 734
1 61095 734
1 61085 734
1 61099 734
1 61074 734
1 61077 734
1 61080 734
1 61092 734
1 61100 734
1 61083 734
1 61091 734
1 61097 734
1 61098 734
1 61075 734
1 61076 734
1 61078 734
1 61081 734
1 61084 734
1 61087 734
1 61096 734
1 61079 734
1 61094 734
1 61088 734
1 61090 734
1 61082 734
1 61086 734

 

插入20018条数据后可以发现该表有26个数据块,填满了除了61101块意外的其他数据块。
接着导出已经填满的数据块61074.

SQL> alter system dump datafile 1 block 61074;

System altered.

 

Block header dump: 0x0040ee92
Object id on Block? Y
seg/obj: 0xcb0a csc: 0x00.bb6a1 itc: 2 flg: - typ: 1 - DATA
fsl: 0 fnx: 0x0 ver: 0x01

Itl Xid Uba Flag Lck Scn/Fsc
0x01 0x0005.020.0000013b 0x0080078c.013c.3a --U- 734 fsc 0x0000.000bb765
0x02 0x0000.000.00000000 0x00000000.0000.00 ---- 0 fsc 0x0000.00000000
--可以发现initrans为1的情况下默认是有2个事务槽,itc=2
data_block_dump,data header at 0xd7fe45c
===============
tsiz: 0x1fa0
hsiz: 0x5ce
pbl: 0x0d7fe45c
bdba: 0x0040ee92
76543210
flag=--------
ntab=1
nrow=734
frre=-1
fsbo=0x5ce
fseo=0xbf8

avsp=0x4
tosp=0x4
0xe:pti[0] nrow=734 offs=0

 

块满的情况测试slot的分配,根据前面的查询结果我们知道单个块的存储行数为734行,也可以通过dump中的nrow=734得知,所以我们在这部测试中依次更新第100,200,300行的数据。

session 1 更新第100行的数据:

SQL> update luda set a=a
2 where dbms_rowid.ROWID_BLOCK_NUMBER(rowid)=61074
3 and dbms_rowid.ROWID_ROW_NUMBER(rowid)=100;

1 row updated.

 

session 2更新第200行的数据:

SQL> update luda set a=a
2 where dbms_rowid.ROWID_BLOCK_NUMBER(rowid)=61074
3 and dbms_rowid.ROWID_ROW_NUMBER(rowid)=200;

1 row updated.

 

session 3更新第300行的数据,session3的sid为158,并且在执行过程中session 3 hang住:

SQL> select sid from v$mystat where rownum=1;

SID
----------
158

SQL> update luda set a=a
2 where dbms_rowid.ROWID_BLOCK_NUMBER(rowid)=61074
3 and dbms_rowid.ROWID_ROW_NUMBER(rowid)=300;
--此时进程hang住
 

alter system dump datafile 1 block 61074;

 

Block header dump: 0x0040ee92
Object id on Block? Y
seg/obj: 0xcb0a csc: 0x00.bb97e itc: 2 flg: - typ: 1 - DATA
fsl: 0 fnx: 0x0 ver: 0x01

Itl Xid Uba Flag Lck Scn/Fsc
0x01 0x0003.014.00000159 0x008006bb.01f1.12 ---- 1 fsc 0x0000.00000000
0x02 0x0005.00e.0000013c 0x0080083c.014b.20 ---- 1 fsc 0x0000.00000000
--通过此时的dump我们也可以发现原先为被占用的2个事务槽已经被占用而且事务未提交。
data_block_dump,data header at 0xd77645c
===============
tsiz: 0x1fa0
hsiz: 0x5ce
pbl: 0x0d77645c
bdba: 0x0040ee92
76543210
flag=--------
ntab=1
nrow=734
frre=-1
fsbo=0x5ce
fseo=0xbf8
avsp=0x4
tosp=0x4
0xe:pti[0] nrow=734 offs=0

 

 
--查询158进程的等待事件为itl的相关等待事件enq: TX - allocate ITL entry
SQL> select sid,event from v$session where sid=158;

SID EVENT
---------- ----------------------------------------------------------------
158 enq: TX - allocate ITL entry

从以上验证了空间不足的情况下会导致itl无法分配引起enq: TX – allocate ITL entry等待事件的产生。

接下来测试块不满的情况,在表luda中目前有数据的块为26个,其中块号为61101的块只有200条数据,只占用该块30%的空间,为了测试需要对61101号块采用4个session分别对第10,20,30,40行进行更新:

session 1:

 

SQL> update luda set a=a
2 where dbms_rowid.ROWID_BLOCK_NUMBER(rowid)=61101
3 and dbms_rowid.ROWID_ROW_NUMBER(rowid)=10;

1 row updated.

 

 

session2:

 

SQL> update luda set a=a
2 where dbms_rowid.ROWID_BLOCK_NUMBER(rowid)=61101
3 and dbms_rowid.ROWID_ROW_NUMBER(rowid)=20;

1 row updated.

 

session3:

 

SQL> update luda set a=a
2 where dbms_rowid.ROWID_BLOCK_NUMBER(rowid)=61101
3 and dbms_rowid.ROWID_ROW_NUMBER(rowid)=30;

1 row updated.

 

session4:

SQL> update luda set a=a
2 where dbms_rowid.ROWID_BLOCK_NUMBER(rowid)=61101
3 and dbms_rowid.ROWID_ROW_NUMBER(rowid)=40;

1 row updated.

 

以上4个session都没有遇到阻塞,导出61101号块可以发现该块有4个itl slot,自动扩展了2个slot,验证了在空间足够的情况下itl slot会自动扩展。

SQL> alter system dump datafile 1 block 61101;

System altered.

 

--

Block header dump: 0x0040eead
Object id on Block? Y
seg/obj: 0xcb0a csc: 0x00.bc003 itc: 4 flg: O typ: 1 - DATA
fsl: 0 fnx: 0x0 ver: 0x01

Itl Xid Uba Flag Lck Scn/Fsc
0x01 0x0003.014.00000159 0x008006bb.01f1.13 ---- 1 fsc 0x0000.00000000
0x02 0x0009.016.0000013b 0x0080075c.0143.37 ---- 1 fsc 0x0000.00000000
0x03 0x0005.00e.0000013c 0x0080083c.014b.21 ---- 1 fsc 0x0000.00000000
0x04 0x0002.026.00000139 0x00800130.00fc.09 ---- 1 fsc 0x0000.00000000
--itc=4,在61101块上存在4条未提交的事务,分别是我们刚才执行的sesson1-4.

data_block_dump,data header at 0xe17048c
===============
tsiz: 0x1f70
hsiz: 0x1a2
pbl: 0x0e17048c
bdba: 0x0040eead
76543210
flag=--------
ntab=1
nrow=200
frre=-1
fsbo=0x1a2
fseo=0x1957
avsp=0x16c6
tosp=0x16c6
0xe:pti[0] nrow=200 offs=0

 

以上测试说明了在Oracle10g以来,itl的争用事件产生在数据块上主要是受块空间的影响,如果大量事务在相关block上执行操作但是当块无法满足分配事务槽,则会产生itl相关争用。
下一节主要是区分是索引块还是表数据块的争用. http://www.ludatou.com/?p=1920

在Oracle监控中如何捕获执行计划变更的语句

在通常的数据库运维中,经常担心数据库一些重要的SQL的性能突然变差,导致整个数据库性能糟糕响应缓慢,甚至让数据库瘫痪的情况时有出现,往往这个时候要在事后通过awrsqrpt.sql脚本从top sql中去抓取分析执行变化的SQL语句,今天脑袋一闪想有没有办法有脚本可以自己去对比呢?回家就开始敲命令测试,测试的平台为11gr1版本,通过dba_hist_sqlstats数据字典中抓去sql id数据进行对比,通过对比获取相关的SQL_ID,以及此SQL的最优执行计划是什么。通过该sql可以设定一个固定的执行时间,通过分别查出来的数据进行监控,对执行计划产生误差的语句及时的通过SQL_PROFILE或者SPM(11g)调整成最优执行计划。

具体语句如下:

spool sql_have_logs_plan.txt
set lines 220 pages 9999 trimspool on
set numformat 999,999,999
column plan_hash_value format 99999999999999
column min_snap format 999999
column max_snap format 999999
column min_avg_ela format 999,999,999,999,999
column avg_ela format 999,999,999,999,999
column ela_gain format 999,999,999,999,999
select sql_id,
       min(min_snap_id) min_snap,
       max(max_snap_id) max_snap,
       max(decode(rw_num,1,plan_hash_value)) plan_hash_value,
       max(decode(rw_num,1,avg_ela)) min_avg_ela,
       avg(avg_ela) avg_ela,
       avg(avg_ela) - max(decode(rw_num,1,avg_ela)) ela_gain,
       -- max(decode(rw_num,1,avg_buffer_gets)) min_avg_buf_gets,
       -- avg(avg_buffer_gets) avg_buf_gets,
       max(decode(rw_num,1,sum_exec))-1 min_exec,
       avg(sum_exec)-1 avg_exec
from (
  select sql_id, plan_hash_value, avg_buffer_gets, avg_ela, sum_exec,
         row_number() over (partition by sql_id order by avg_ela) rw_num , min_snap_id, max_snap_id
  from
  (
    select sql_id, plan_hash_value , sum(BUFFER_GETS_DELTA)/(sum(executions_delta)+1) avg_buffer_gets,
    sum(elapsed_time_delta)/(sum(executions_delta)+1) avg_ela, sum(executions_delta)+1 sum_exec,
    min(snap_id) min_snap_id, max(snap_id) max_snap_id
    from dba_hist_sqlstat a
    where exists  (
       select sql_id from dba_hist_sqlstat b where a.sql_id = b.sql_id
         and  a.plan_hash_value != b.plan_hash_value
         and  b.plan_hash_value > 0)
    and plan_hash_value > 0
    group by sql_id, plan_hash_value
    order by sql_id, avg_ela
  )
  order by sql_id, avg_ela
  )
group by sql_id
having max(decode(rw_num,1,sum_exec)) > 1
order by 7 desc
/
spool off
clear columns
set numformat 9999999999

具体的执行结果参考如下:

SQL> spool sql_with_more_than_1plan.txt
set lines 220 pages 9999 trimspool on
SQL> SQL> set numformat 999,999,999
SQL> column plan_hash_value format 99999999999999
SQL> column min_snap format 999999
SQL> column max_snap format 999999
SQL> column min_avg_ela format 999,999,999,999,999
SQL> column avg_ela format 999,999,999,999,999
SQL> column ela_gain format 999,999,999,999,999
SQL> select sql_id,
2 min(min_snap_id) min_snap,
3 max(max_snap_id) max_snap,
4 max(decode(rw_num,1,plan_hash_value)) plan_hash_value,
5 max(decode(rw_num,1,avg_ela)) min_avg_ela,
6 avg(avg_ela) avg_ela,
7 avg(avg_ela) - max(decode(rw_num,1,avg_ela)) ela_gain,
8 -- max(decode(rw_num,1,avg_buffer_gets)) min_avg_buf_gets,
9 -- avg(avg_buffer_gets) avg_buf_gets,
10 max(decode(rw_num,1,sum_exec))-1 min_exec,
11 avg(sum_exec)-1 avg_exec
12 from (
13 select sql_id, plan_hash_value, avg_buffer_gets, avg_ela, sum_exec,
14 row_number() over (partition by sql_id order by avg_ela) rw_num , min_snap_id, max_snap_id
15 from
16 (
17 select sql_id, plan_hash_value , sum(BUFFER_GETS_DELTA)/(sum(executions_delta)+1) avg_buffer_gets,
18 sum(elapsed_time_delta)/(sum(executions_delta)+1) avg_ela, sum(executions_delta)+1 sum_exec,
19 min(snap_id) min_snap_id, max(snap_id) max_snap_id
20 from dba_hist_sqlstat a
21 where exists (
22 select sql_id from dba_hist_sqlstat b where a.sql_id = b.sql_id
23 and a.plan_hash_value != b.plan_hash_value
24 and b.plan_hash_value > 0)
25 and plan_hash_value > 0
26 group by sql_id, plan_hash_value
27 order by sql_id, avg_ela
28 )
29 order by sql_id, avg_ela
30 )
31 group by sql_id
32 having max(decode(rw_num,1,sum_exec)) > 1
33 order by 7 desc
34 /
spool off
clear columns
set numformat 9999999999
SQL_ID MIN_SNAP MAX_SNAP PLAN_HASH_VALUE MIN_AVG_ELA AVG_ELA ELA_GAIN MIN_EXEC AVG_EXEC
------------- -------- -------- --------------- -------------------- -------------------- -------------------- ------------ ------------
gfjvxb25b773h 192 204 3801470479 6,368 171,152 164,784 1 1
7asddw0r2wykx 192 211 3660107835 10,311 16,448 6,137 57 30
7ng34ruy5awxq 192 209 2606284882 117 320 204 426 1,371
g278wv0zzpn5j 195 211 3142739690 0 189 189 72 63
1gu8t96d0bdmu 192 209 2035254952 67 154 87 826 1,134
bsa0wjtftg3uw 193 211 2020579421 0 18 18 224 191
0kugqg48477gf 201 202 3321035584 0 0 0 19 27

7 rows selected.

通过以上查询我们发现了7个结果,其中MIN_SNAP和MAX_SNAP代表该sql_id所代表最早出现时候的快照和最后一次出现的快照;PLAN_HASH_VALUE代表着最佳的执行计划;ELA_GAIN字段代表如果使用最佳的执行计划,与平均执行时间能够提速多少时间。

在查出结果后,我们可以通过sql profile(参考老刘的《验证sql_profile的执行计划》),也可以通过11g的dbms_spm.load_plans_from_cursor_cache更改相关Sql_id的sql的执行计划,这里以11g为例子做如下变更,对上面查询到的7asddw0r2wykx语句执行计划改为最优:

SQL> variable v_sqlid number
SQL> begin
2 :v_sqlid :=
3 dbms_spm.load_plans_from_cursor_cache(
4 sql_id=>'&sql_id',
5 plan_hash_value=>&plan_hash,
6 fixed=>'YES');
7 end;
8 /
Enter value for sql_id: 7asddw0r2wykx
old 4: sql_id=>'&sql_id',
new 4: sql_id=>'7asddw0r2wykx',
Enter value for plan_hash: 3660107835
old 5: plan_hash_value=>&plan_hash,
new 5: plan_hash_value=>3660107835,

PL/SQL procedure successfully completed.