首页 » ORACLE » Adaptive Cursor Sharing in 11R2 performance issues(自适应游标共享问题案例)

Adaptive Cursor Sharing in 11R2 performance issues(自适应游标共享问题案例)

今天开发的同事找我说是一个报表系统的SQL执行第一次很快,再执行就慢的几乎查询无响应,找他要来了SQL,也是常见的表关连LIFT JOIN 、GROUP BY的统计报表, 出于篇幅原因不再贴SQL, 把SQL放到TOAD 中问题依然可以再现, 在同一窗口连续查询两次,第一次瞬间返回,第二次等待了有4分多钟 ,对会话设置了10046 SQL TRACE, 下面有Trace 的结果

sys@anbob>select * from v$version;

BANNER
--------------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
PL/SQL Release 11.2.0.3.0 - Production
CORE    11.2.0.3.0      Production
TNS for Linux: Version 11.2.0.3.0 - Production
NLSRTL Version 11.2.0.3.0 - Production

sys@ORCL>show parameter cursor_shar

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
cursor_sharing                       string      EXACT

SQL>  select       
  2       plan_hash_value,
  3       BUFFER_GETS,ROWS_PROCESSED,CHILD_NUMBER,ELAPSED_TIME,cpu_TIME,
  4       is_bind_sensitive,
  5       is_bind_aware,LAST_ACTIVE_TIME
  6     from   v$sql WHERE SQL_ID='6vd7zxpj6qd8h';

PLAN_HASH_VALUE BUFFER_GETS ROWS_PROCESSED CHILD_NUMBER ELAPSED_TIME   CPU_TIME I I LAST_ACTIVE_TIME
--------------- ----------- -------------- ------------ ------------ ---------- - - -------------------
      841592968      233739              6            0       672757     670899 N N 2013-12-05 15:28:54
     3830877904     4336911              6            1    172400111  172367796 N N 2013-12-05 15:31:47

Note:
From above output you can see the SQL parsing the two cursors and generated different execution plan, and ELAPSED_TIME, CPU_TIME also reflects the time required to perform before and after the gap between the two

sys@anbob>oradebug short_stack;
ksedsts()+461<-ksdxfstk()+32<-ksdxcb()+1876<-sspuser()+112<-__sighandler()<-kxhrHash()+386<-qerhjSplitProbe()+184<-qerhjInnerProbeHashTable()+74<-qerixFetchFastFullScan()+2476<-rwsfcd()+103<-qerhjFetch()+593<-qerflFetch()+135<-rwsfcd()+103<-qeruaFetch()+574<-qervwFetch()+139<-qerjotRowProc()+353<-qertbFetchByRowID()+3236<-qerjotRowProc()+353<-qertbFetchByRowID()+3236<-qerjotRowProc()+353<-qerixtFetch()+800<-qerjotFetch()+1155<-qerjotFetch()+1961<-qerjotFetch()+1961<-qerjotFetch()+1961<-qerflFetch()+135<-qergsFetch()+775<-qervwFetch()+139<-qergsFetch()+775<-qervwFetch()+139<-qerjoFetch()+390<-rwsfcd()+103<-qerhjFetch()+3187<-qercoFetch()+205<-opifch2()+2995<-kpoal8()+2934<-opiodr()+916<-ttcpip()+2242<-opitsk()+1673<-opiino()+966<-opiodr()+916<-opidrv()+570<-sou2o()+103<-opimai_real()+133<-ssthrdmain()+252<-main()+201<-__libc_start_main()+244<-_start()+36

Note:
When I dump the call stack of slowly oracle process , the display is also doing HASH related operations

trace file of formated by tkprof utility

--note execution plan had truncated

PLAN_HASH_VALUE:841592968

Rows		     Operation
---------      ---------------------
38,045	    NESTED LOOPS (cr=134876 pr=0 pw=0 time=286598 us cost=6 size=45 card=1)
38,045	       TABLE ACCESS BY INDEX ROWID ICME_PROJECT_SCORE (cr=53372 pr=0 pw=0 time=160677 us cost=5 size=31 card=1)
38,045	          INDEX RANGE SCAN IDX_ICME_PROJECT_SCORE_M (cr=23985 pr=0 pw=0 time=66046 us cost=4 size=0 card=1) (object id 17468)
38,045	       INDEX UNIQUE SCAN PK_ICME_SUBJECT (cr=81504 pr=0 pw=0 time=93357 us cost=1 size=14 card=1) (object id 17554)


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.14       0.15          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        1      0.74       0.74          0     233737          0           6
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      0.89       0.89          0     233737          0           6

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.08          0.09
********************************************************************************

PLAN_HASH_VALUE:3830877904

Rows		     Operation
---------      ---------------------
38,045		      HASH JOIN (cr=4220506 pr=0 pw=0 time=346507995 us cost=216 size=1727775 card=38395)
38,045		         TABLE ACCESS BY INDEX ROWID ICME_PROJECT_SCORE (cr=53338 pr=0 pw=0 time=262176 us cost=5 size=1179395 card=38045)
38,531		            INDEX RANGE SCAN IDX_ICME_PROJECT_SCORE_IDS (cr=23496 pr=0 pw=0 time=102193 us cost=4 size=0 card=1) (object id 17470)
1,771,236,310	              INDEX FAST FULL SCAN PK_ICME_SUBJECT (cr=4167168 pr=0 pw=0 time=231040457 us cost=209 size=4569180 card=326370) (object id 17554)



call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.15       0.15          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        1    371.90     371.97          0    4336909          0           6
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3    372.06     372.13          0    4336909          0           6


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.05          0.05

Note:
从上面的trace显示sql两次的执行计划发生了改变有NL join 转为 Hash join,解决可以使用 Sql hint 的use_nl 强置指定执行计划, 可是为什么同一sql 在几乎样的环境(资源空闲)里执行
会产生两个执行计划, 猜测应该与11G 优化器的游标生成有关, 尝试禁用自适应游标共享(Adaptive Cursor Sharing), reference to disable 11gr2 problem feature list by Maclean 's and to disable the feature recommended.

And in this book there is a suggestion , the following excerpt from <>

Adaptive Cursor Sharing is enabled by default. In OnLine Transaction Processing (OLTP) databases, there is often only one optimal
execution plan, regardless of the actual value of binding variables. In this kind of database, we probably want to disable the
Adaptive Cursor Sharing feature to eliminate the related overhead. To disable it, you need to set the CURSOR_SHARING
initialization parameter to EXACT and the hidden _OPTIMIZER_EXTENDED_CURSOR_SHARING_REL initialization parameter to NONE, as follows:

ALTER SYSTEM SET CURSOR_SHARING = EXACT SCOPE = BOTH;
ALTER SYSTEM SET _OPTIMIZER_EXTENDED_CURSOR_SHARING_REL = NONE SCOPE = BOTH;

Then I try to modify a hidden parameter of ECS,

alter system set "_OPTIMIZER_EXTENDED_CURSOR_SHARING_REL" = NONE

Solve the above problem of slow second execute slowly , and next execute used the "NL join" execution plan , usually , We to use another disabled ACS only(
"_optimizer_adaptive_cursor_sharing" =FALSE ), Burleson Consulting have introduced about The relationship between ECS and ACS .

The extended cursor_sharing (ECS) working with adaptive cursor_sharing to allow real-time bind peeking to see if the bind variable value influences the execution plan for the SQL statement.
According to the Oracle optimizer group. "Bind Aware Cursor Sharing" (BASC) is a complex technology that consists of Adaptive Cursor Sharing (ACS) and Extended Cursor Sharing (ECS) technologies:

Adaptive cursor_sharing monitors queries where extended cursor_sharing is "applicable" (e.g. binds were peeked, predicate shape).

  • Adaptive cursor_sharing identify queries with variable data volume.
  • Adaptive cursor_sharing requires you to enable extended. cursor_sharing (bind_aware hint).

According to Oracle, if any of the following checks fail, extended cursor_sharing will be disabled:

  1. other hints are used in the query
  2. Stored outlines (plan stability) is in-use
  3. There are more than 14 binds in the SQL statement
  4. Parameters such as bind_peeking=false is set
  5. The release of Oracle does not support extended cursor sharing
打赏

,

目前这篇文章有1条评论(Rss)评论关闭。

  1. 李建卫 | #1
    2013-12-05 at 19:04

    很好,顶顶