LIKEのワイルドカード検索で性能劣化 [オプティマイザ]

 再びコロナの増加が気になる昨今、夏休みを頂き、しばらく更新できなかった本ブログに向き合う時間ができた。今回はOracleのコミュニティ(MOSC)で、索引を使うLIKE検索で性能劣化した事例のトラシューについて記載したい。オリジナルのスレッドはこちらを参照されたい。

1.事象


 今回発生したのは、SELECT文のプレディケート(WHERE句)に、ename LIKE '%ABC%' のようなあいまい検索をした場合で、ename列に張られたB-tree索引を使うときに、'%ABC%'がリテラルの場合は性能が良好なのに、これをバインド変数に置き換えると性能が悪化する、という事象である(実際の事象では、cursor_sharing=forceとして強制的にリテラルをバインド変数にしているが、本質的にはバインド変数を使う場合一般で発生する)。今回、この事象を私の手元の環境(Oracle 19.11)で再現することができたので、以下に再現手順とともに、具体的な問題と対処方法について考察したい。

2.再現ケース


 まず事象を確認するため、以下のようにemp/dept表を作成し、データ(emp表に100万件、dept表に10万件)を挿入、統計を取得する。ここで、emp表のename列にidx_emp_ename索引を作成する。
create table dept(  
  deptno     number(7,0),  
  dname      varchar2(14),  
  loc        varchar2(13),  
  constraint pk_dept primary key (deptno)  
);
create table emp(  
  empno    number(7,0),  
  ename    varchar2(10),  
  job      varchar2(9),  
  mgr      number(7,0),  
  hiredate date,  
  sal      number(7,2),  
  comm     number(7,2),  
  deptno   number(7,0),  
  constraint pk_emp primary key (empno),  
  constraint fk_deptno foreign key (deptno) references dept (deptno)  
);
create index idx1_emp on emp(deptno);
create index idx_emp_ename on emp(ename);

insert into dept select
rownum deptno,
dbms_random.string('u',14) dname,
dbms_random.string('u',13) loc
from dual connect by level <=100000;
commit;

insert into emp select
rownum,
dbms_random.string('u',10) ename,
dbms_random.string('u',9) job,
dbms_random.value(1,1000000) mgr,
sysdate - dbms_random.value(1,5000) hiredate,
dbms_random.value(3000,9999) sal,
dbms_random.value(3000,9999) comm,
dbms_random.value(1,100000) deptno
from dual connect by level <=1000000;
commit;

exec dbms_stats.gather_table_stats('SCOTT','EMP');
exec dbms_stats.gather_table_stats('SCOTT','DEPT');

 以下のようにバインドピークを有効にする(デフォルトは有効)。
alter session set "_optim_peek_user_binds"=true;

SQL> sho parameter _optim_peek_user_binds

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
_optim_peek_user_binds               boolean     TRUE

 以下のSQLはemp表、dept表を結合し、emp表のename列をLIKEで'%ABCD%'のようにあいまい検索する。結果10件、実行時間は0.20秒である。なお、ヒントを付与しているのは、恣意的にハッシュ結合を使い、ename列にIDX_EMP_ENAME索引を使うようにしている(これがないと、この例では索引は使われず、emp表を直接フルスキャンしてしまうため)。
◆リテラルの場合
SQL> select /*+ leading(t2 t1) use_hash(t1) index(t1 IDX_EMP_ENAME) */ * from emp t1, dept t2 where t1.deptno=t2.deptno and t1.ename like '%ABCD%';

     EMPNO ENAME      JOB              MGR HIREDATE         SAL       COMM     DEPTNO     DEPTNO DNAME          LOC
---------- ---------- --------- ---------- --------- ---------- ---------- ---------- ---------- -------------- -------------
    582720 AHIOABCDYT YXAQBMMYZ     874855 07-DEC-10    8436.11    5663.23      39434      39434 JSQOATEEMKCWZS RFPBWFMIAUUPN
    448911 CZDLGBABCD VALZNFZDN     638948 07-NOV-13     7589.9    3307.46      69381      69381 ZJEAOYUCOEDUFF UOFSOHXHTSXVH
    515098 DPOABCDIAB ATXDVQJXP     260849 13-JAN-10    4036.32    6729.36       3548       3548 JOTVEVFBTESCBZ UDODRZQVVMWQT
...
10 rows selected.

Elapsed: 00:00:00.20

 同じSQLをバインド変数を用いて実行する。結果は同じだが、実行時間が1.74秒と、リテラルの場合に比べ8~9倍遅い。これはなぜか、この遅い理由を以下で解析する。
◆バインド変数の場合
SQL> variable b2 varchar2(10);
SQL> begin
  2   :b2:='%ABCD%';
  3  end;
  4  /

PL/SQL procedure successfully completed.
SQL> select /*+ leading(t2 t1) use_hash(t1) index(t1 IDX_EMP_ENAME) */ * from emp t1, dept t2 where t1.deptno=t2.deptno and t1.ename like :b2;

     EMPNO ENAME      JOB              MGR HIREDATE         SAL       COMM     DEPTNO     DEPTNO DNAME          LOC
---------- ---------- --------- ---------- --------- ---------- ---------- ---------- ---------- -------------- -------------
    582720 AHIOABCDYT YXAQBMMYZ     874855 07-DEC-10    8436.11    5663.23      39434      39434 JSQOATEEMKCWZS RFPBWFMIAUUPN
    448911 CZDLGBABCD VALZNFZDN     638948 07-NOV-13     7589.9    3307.46      69381      69381 ZJEAOYUCOEDUFF UOFSOHXHTSXVH
    515098 DPOABCDIAB ATXDVQJXP     260849 13-JAN-10    4036.32    6729.36       3548       3548 JOTVEVFBTESCBZ UDODRZQVVMWQT
...

10 rows selected.

Elapsed: 00:00:01.74


3.解析


 はじめに思いつくのは実行計画による違いである。dbms_xplanで実行計画を取得する(ヒントにgather_plan_statisticsを付与し、実行統計も取得する)と、いずれの結果も実行計画はほぼ同じであるが、よく見るとId4がINDEX FULL SCANに対し、遅い方はINDEX RANGE SCANとなっている。いずれの索引アクセス方法にしても、あいまい検索(%が先頭)では全てのリーフブロックをスキャン(シングルブロックリード)しなければならないため、本質的なIO量は変わらないはずである。ではこの性能差はどこから来ているのだろうか。
◆リテラルの場合
SQL_ID  0qygthva6jcgv, child number 3
-------------------------------------
select /*+ leading(t2 t1) use_hash(t1) index(t1 IDX_EMP_ENAME)
gather_plan_statistics */ * from emp t1, dept t2 where
t1.deptno=t2.deptno and t1.ename like '%ABCD%'

Plan hash value: 1197820828

-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                            | Name          | Starts | E-Rows |E-Bytes|E-Temp | Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers |  OMem |  1Mem | Used-Mem |
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                     |               |      1 |        |       |       | 54605 (100)|          |     10 |00:00:00.02 |    4621 |       |       |        |
|*  1 |  HASH JOIN                           |               |      1 |  50000 |  4296K|  4496K| 54605   (1)| 00:00:03 |     10 |00:00:00.02 |    4621 |  9465K|  3157K| 9991K (0)|
|   2 |   TABLE ACCESS FULL                  | DEPT          |      1 |    100K|  3320K|       |   171   (1)| 00:00:01 |    100K|00:00:00.02 |     568 |       |       |        |
|   3 |   TABLE ACCESS BY INDEX ROWID BATCHED| EMP           |      1 |  50000 |  2636K|       | 54060   (1)| 00:00:03 |     10 |00:00:00.01 |    4053 |       |       |        |
|*  4 |    INDEX FULL SCAN                   | IDX_EMP_ENAME |      1 |  50000 |       |       |  4053   (1)| 00:00:01 |     10 |00:00:00.19 |    4043 |       |       |        |
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

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

   1 - access("T1"."DEPTNO"="T2"."DEPTNO")
   4 - filter(("T1"."ENAME" LIKE '%ABCD%' AND "T1"."ENAME" IS NOT NULL))

◆バインド変数の場合
SQL_ID  18640n98c4ncx, child number 3
-------------------------------------
select /*+ leading(t2 t1) use_hash(t1) index(t1 IDX_EMP_ENAME)
gather_plan_statistics */ * from emp t1, dept t2 where
t1.deptno=t2.deptno and t1.ename like :b2

Plan hash value: 300188277

-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                            | Name          | Starts | E-Rows |E-Bytes|E-Temp | Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers |  OMem |  1Mem | Used-Mem |
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                     |               |      1 |        |       |       | 50757 (100)|          |     10 |00:00:00.04 |    1004K|       |       |        |
|*  1 |  HASH JOIN                           |               |      1 |  50000 |  4296K|  4496K| 50757   (1)| 00:00:02 |     10 |00:00:00.04 |    1004K|  9465K|  3157K| 9976K (0)|
|   2 |   TABLE ACCESS FULL                  | DEPT          |      1 |    100K|  3320K|       |   171   (1)| 00:00:01 |    100K|00:00:00.01 |     568 |       |       |        |
|*  3 |   TABLE ACCESS BY INDEX ROWID BATCHED| EMP           |      1 |  50000 |  2636K|       | 50211   (1)| 00:00:02 |     10 |00:00:00.02 |    1003K|       |       |        |
|*  4 |    INDEX RANGE SCAN                  | IDX_EMP_ENAME |      1 |  50000 |       |       |   204   (0)| 00:00:01 |   1000K|00:00:00.30 |    4043 |       |       |        |
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
...
Predicate Information (identified by operation id):
---------------------------------------------------

   1 - access("T1"."DEPTNO"="T2"."DEPTNO")
   3 - filter("T1"."ENAME" LIKE :B2)
   4 - access("T1"."ENAME" LIKE :B2)

 ここで、上記結果のA-Rowsの値に注目したい。A-Rowsは実際の返却された行数を表す。INDEX FULL SCANのA-Rowsは1000K(100万件)であるのに対し、INDEX RANGE SCANのは10件である。つまり、INDEX FULL SCANはこの処理の中でLIKE '%ABCD%'で10件に絞り込みを行っているのに対し、INDEX RANGE SCANは全く絞り込みを行わず100万件を返却し、その結果、Id3のTABLE ACESS BY INDEX ROWIDでemp表にアクセスしLIKE '%ABCD%'の絞り込みを行い、10件の結果を得ていることがわかる。このことから、遅延の原因はこのId4のINDEX RANGE SCANにおいてLIKEの絞り込みができないことに起因していることがわかる。

4.原因


 この事象は12.2で導入された、バインド変数におけるワイルドカードで開始されるLIKE検索をチェック機能(QKSFM_ACCESS_PATH_20289688)による影響であることが判明した。
SQL> select * from v$system_fix_control where description like '%LIKE%'

     BUGNO VALUE SQL_FEATURE                    DESCRIPTION                                   OPTIMIZER_  EVENT IS_DEFAULT CON_ID
...
   20289688     1 QKSFM_ACCESS_PATH_20289688     check for leading wildcard in LIKE with bind  12.2.0.1        0          1      3

 実際に、この_fix_controlを無効化して同じSQLを実行すると、あるべき性能が得られ、id4におけるINDEX RANGE SCANの中でLIKE '%ABCD%'の絞り込みが行われることがわかる。
SQL> select /*+ opt_param('_fix_control' '20289688:0') leading(t2 t1) use_hash(t1) index(t1 IDX_EMP_ENAME) gather_plan_statistics */ * from emp t1, dept t2 where t1.deptno=t2.deptno and t1.ename like :b2;

     EMPNO ENAME      JOB              MGR HIREDATE         SAL       COMM     DEPTNO     DEPTNO DNAME          LOC
---------- ---------- --------- ---------- --------- ---------- ---------- ---------- ---------- -------------- -------------
    582720 AHIOABCDYT YXAQBMMYZ     874855 07-DEC-10    8436.11    5663.23      39434      39434 JSQOATEEMKCWZS RFPBWFMIAUUPN
    448911 CZDLGBABCD VALZNFZDN     638948 07-NOV-13     7589.9    3307.46      69381      69381 ZJEAOYUCOEDUFF UOFSOHXHTSXVH
    515098 DPOABCDIAB ATXDVQJXP     260849 13-JAN-10    4036.32    6729.36       3548       3548 JOTVEVFBTESCBZ UDODRZQVVMWQT
...
10 rows selected.

Elapsed: 00:00:00.19

SQL_ID  25wd59chvjmwd, child number 0
-------------------------------------
select /*+ opt_param('_fix_control' '20289688:0') leading(t2 t1)
use_hash(t1) index(t1 IDX_EMP_ENAME) gather_plan_statistics */ * from
emp t1, dept t2 where t1.deptno=t2.deptno and t1.ename like :b2

Plan hash value: 300188277

-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                            | Name          | Starts | E-Rows |E-Bytes|E-Temp | Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers |  OMem |  1Mem | Used-Mem |
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                     |               |      1 |        |       |       | 50757 (100)|          |     10 |00:00:00.02 |    4621 |       |       |        |
|*  1 |  HASH JOIN                           |               |      1 |  50000 |  4296K|  4496K| 50757   (1)| 00:00:02 |     10 |00:00:00.02 |    4621 |  9465K|  3157K| 9988K (0)|
|   2 |   TABLE ACCESS FULL                  | DEPT          |      1 |    100K|  3320K|       |   171   (1)| 00:00:01 |    100K|00:00:00.01 |     568 |       |       |        |
|   3 |   TABLE ACCESS BY INDEX ROWID BATCHED| EMP           |      1 |  50000 |  2636K|       | 50211   (1)| 00:00:02 |     10 |00:00:00.01 |    4053 |       |       |        |
|*  4 |    INDEX RANGE SCAN                  | IDX_EMP_ENAME |      1 |  50000 |       |       |   204   (0)| 00:00:01 |     10 |00:00:00.18 |    4043 |       |       |        |
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
...
Predicate Information (identified by operation id):
---------------------------------------------------

   1 - access("T1"."DEPTNO"="T2"."DEPTNO")
   4 - access("T1"."ENAME" LIKE :B2)
       filter("T1"."ENAME" LIKE :B2)

 なお、この事象はバインドピークを無効化している場合("_optim_peek_user_binds"=false)は発生しない。これは、バインドピークの機能の中で、バインド値の先頭にワイルドカードが入っているかチェックしているためと思われる。したがって、本事象は12.2以上で、バインドピークを有効化しており、LIKE検索によるあいまい検索を行い、かつ検索にB-tree索引を利用している環境で発生し得る問題と考えられる。ハッシュ結合はこの事象の発生条件に関係ない。1つの表に対する検索でも発生し得る。

5.対処方法


 考え得る対処方法は以下の通り。
     
  • (1)セッション(またはシステム)レベルの_fix_controlで20289688を無効化する(例: ALTER SESSION SET "_fix_control"='20289688:0';)  
  • (2)セッション(またはシステム)レベルでバインドピークを無効化する(ALTER SESSION SET "_optim_peek_user_binds"=false;)  
  • (3)対象となるSQLに_fix_controlのヒントを入れる(例:/*+ opt_param('_fix_control' '20289688:0') */ )  
  • (4)対象となるSQLにバインドピークのヒントを入れる(例:/*+ opt_param('_optim_peek_user_binds' 'false') */ )

 運用開始しており、バインドピークを有効化しているシステムにおいては、システムレベルで(1)(2)を変更することは難しいだろう。性能問題が発生するAPに限りセッションレベルで設定するようAPを改修するか、(3)(4)のヒントを入れるのが現実的だろう。なお、(3)(4)については、SPMやSQLパッチを使えば、APに手を入れずに実行計画を変更することも可能だろう。特にSQLがパッケージから発行されている場合は有効な対処方法となり得る。

4.おわりに


 QKSFM_ACCESS_PATH_20289688が12.2で導入されてから今まで、なぜこの問題が放置されたままなのか不思議に感じる。この性能問題があったとしても、この機能を残すべき積極的な理由があったのかもしれない。もし、そうでないとすれば、バインドピークを使う場合は、_fix_controlで無効化しておく方が良いのではないか、とさえ思う。
 なお、本事象をMOSCのスレッドで解析を進めている中、根本原因を指摘いただいたのはJonathan Lewis氏であった。自分だけでは、よもやオプティマイザの細かな改修の結果によりこの事象が発生しているとは思いもよらなかっただろう。Oracle CoreやCost based optimizerの著者である同氏と直接スレッドでやり取りできたことは、個人的にはこの上ない喜びであった。このようなことを可能としているOracleコミュニティ(MOSC)にも感謝したい。

2022/7/21 追記


 Jonathan Lewis氏とのその後のやりとりで判明したことを備忘まで以下に追記しておく。v$system_fix_controlを確認すると、10.2.0.1において以下の修正が行われていることがわかる。

 3628118 10.2.0.1 QKSFM_ACCESS_PATH_3628118 Do not consider LIKE with leading wildcard as index key

 これは%で始まるLIKE検索の場合は、索引を使わないようにするための修正と思われる。そして、今回問題となっている20289688は、これをリテラルでなくバインド変数でも動作するようにキャッチアップしたものと思われる。あくまで想像の域を出ないが、考えられる経緯としては、バインド変数であいまい検索をした際にindex full/range scanになってしまい性能問題が出る事象があり、それについてSRが起票され、開発者がバインド変数でも同じ挙動をさせようと12.2でこの修正を入れたが、その修正の際、HINTで索引を強制的に使う場合の考慮が不足しており、今回のfilterが効かない挙動の違いが生まれてしまったのかもしれない。あくまでも推測ではあるが、なるほどありえそうなシナリオではあると感じる。

 さらに、この事象に該当すると思われるバグを指摘頂いた。バグの説明文がまさに本事象と合致している。まだ修正されていないそうだ。

 BUG 33500777 - FILTER FOR PREDICATE WITH LIKE AND BIND WITH LEADING WILDCARD IS NOT ALLOCATED ON INDEX SCAN AFTER FIX 20289688

 あいまい検索においては一般的に索引を使わない実行計画が多く、絞り込みが効くとあらかじめわかっているケースは少ないだろう。その意味では今回のようにヒントで索引に誘導しなければならない状況自体がレアケースで、本事象に遭遇することは少ないのかもしれない。ワークアラウンドはあるので、優先度は上がらないかもしれないが、今後の修正を期待したい。

以上
nice!(0)  コメント(0)