AWRレポートを手軽に利用しよう。

AWR(Automatic Workload Reposistory)はオラクルからのプレゼントです。もちろん、ただではないけどど…

私は特定な作業の性能特徴を分析する時、次のように手軽にAWRレポートを利用しています。

@snap_begin

alter session enable parallel dml;

insert /*+ append parallel(t1 4) trace */ into t1
select /*+ parallel(t2 4) */ * from t2;
commit;

@snap_end

@snap_report

-- AWR Report
WORKLOAD REPOSITORY report for

DB Name         DB Id    Instance     Inst Num Release     RAC Host
------------ ----------- ------------ -------- ----------- --- ------------
UKJA1021       738915393 ukja1021            1 10.2.0.1.0  NO  UKJAX

              Snap Id      Snap Time      Sessions Curs/Sess
            --------- ------------------- -------- ---------
Begin Snap:      1284 29-Dec-09 15:04:38        19       3.5
  End Snap:      1285 29-Dec-09 15:04:42        19       3.5
   Elapsed:                0.08 (mins)
   DB Time:                0.15 (mins)

Cache Sizes
~~~~~~~~~~~                       Begin        End
                             ---------- ----------
               Buffer Cache:       452M       452M  Std Block Size:         8K
           Shared Pool Size:       116M       116M      Log Buffer:     6,968K

Load Profile
~~~~~~~~~~~~                            Per Second       Per Transaction
                                   ---------------       ---------------
                  Redo size:          1,201,392.36          5,725,836.00
              Logical reads:              2,178.56             10,383.00
              Block changes:                298.99              1,425.00
             Physical reads:                 97.36                464.00
            Physical writes:                142.89                681.00
                 User calls:                 12.80                 61.00
                     Parses:                 26.44                126.00
                Hard parses:                  0.42                  2.00
                      Sorts:                  8.60                 41.00
                     Logons:                  1.68                  8.00
                   Executes:                 27.07                129.00
               Transactions:                  0.21
...


Event                                 Waits  -outs    Time (s)    (ms)      /txn
---------------------------- -------------- ------ ----------- ------- ---------
db file scattered read                   42     .0           2      55      42.0
log file parallel write                  27     .0           1      32      27.0
rdbms ipc reply                           8     .0           0      50       8.0
control file sequential read            674     .0           0       1     674.0
db file sequential read                  11     .0           0      27      11.0
...

snap_begin、snap_end、snap_reportスクリプトは下記のとおりです。簡単なSQL*Plusだけで手軽にAWRレポートを作れます。
1. snap_begin.sql

col begin_snap new_value begin_snap;
col db_id new_value db_id;
col inst_num new_value inst_num;

select dbid as db_id from v$database;
select instance_number as inst_num from v$instance;

select dbms_workload_repository.create_snapshot as begin_snap from dual;

2. snap_end.sql

col end_snap new_value end_snap;

select dbms_workload_repository.create_snapshot as end_snap from dual;

3. snap_report.sql

select * from table(
  dbms_workload_repository.awr_report_text(
          &db_id,
          &inst_num,
          &begin_snap,
          &end_snap)
  );

もう一度言いますが、AWRはオラクルからの大切なプレゼントです。たとえその値段は高いかも知れませんが、よく利用すればするほど支払いの甲斐があります。

オラクル性能に対する短い考え＃19

オラクルの機能は長期間にかかって完成される。

例えば、

• プランスタビリティーはOracle 8iのStored Outlineから始まったが、実際に使えるほどの水準はOracle 11gR2で達成された。
  
• CBOはOracle 7で紹介されたが、公式的にRBOを完全に代替したのはOracle 10gからだ。
  
• バインドピークはOracle 9iから提供されつつあるが、現実的に使用可能にたったのはOracle 11gからだ。
  

オラクルを理解するのには結構長い時間の観察が必要だと言えますね。

Oracle 11gR2のオプティマイザのCardinaliy Feedback

Oracle 11gR2のランタイムーオプティマイザにCardinality Feedback機能が追加されたことを知るようになりました。

1. Hidden and Undocumented "Cardinality Feedback"
   
2. Adaptive Optimisation ?
   
3. Trivial Research on the Cardinality Feedback on 11gR2
   

オラクルは10gから自動クエリチューニング(Automatic Query Tuning)という名前でCardinality Feedback機能を紹介しました。予想の行数(Estimated Cardinality)と実際の行数(Actual Cardinality)を比べてその差を減らす方式がCardinality Feedback機能の動作原理です。このためにOPT_ESTIMATEヒントが追加されました。しかし、これはあくまでもチューニングオプティマイザエンジンにすみました。

11gR2でこの機能はチューニングエンジンにやまずにランタイムーエンジンまで適用されました。詳しい内容は上のリンクこ参照すればいいでしょう。簡単に整理すると次のとおりです。

1. クエリを行ったあと予想行数件数と実際行数件数の違いが大きすぎると判断されると該当実行計画は共有物不可の状態になって実際の行数件数をカーソルに書き込みます。しかし予想行数件数と実際行数件数の違いだけが唯一なファクターなのかは確実ではなんです。
   
2. あとで同一なクエリがまた実行されると最初の実行で書き込んでおいた行数をOPT_ESTIMATEヒントを通じてクエリに挿入します。すなわちCardinality Feedbackが行われます。
   
3. この過程はたった一度のみ行われます。すなわち最初のクエリだけがフィードバックの対象となります。
   
4. _OPTIMIZER_USE_FEEDBACKパラメーターを利用して制御できます。すなわちこのパラメーターの値をFALSEに変更したらCardinality Feedbackは行われません。
   

私の個人的な意見を申し上げるとCardinality Feedbackがランタイムーエンジンまで適用されるはずだとはまったく期待しませんでした。でも結局そうなってしまいました。たぶん多くのシステムで熱いイシューになるはずです。

私のブログに雪が降っています。

少しだけ(数秒ぐらい)待ってください。しんしんと雪が降っているんですよ。



次のようにJava Scriptをエンベッドしました。

この雪は一月上旬までだけ降ります。

書き出し一貫性 - Restartメカニズム

先日、特定のDMLが多すぎるロジカルリードを持つ問題に対する問い合わせがありました。たとえその問題に対する原因ではありませんでしたけど、おかげで書き出し一貫性(Write Consistency)問題を一度話し合う必要性を感じました。

簡単なテストを通じて話し合ってみます。まず次のようにテーブルを一つ作ります。

UKJA@ukja1021> select * from v$version where rownum = 1;

BANNER
----------------------------------------------------------------
Oracle Database 10g Enterprise Edition Release 10.2.0.1.0 - Prod

UKJA@ukja1021> create table t1
  2  as
  3  select level as c1, rpad('x',1000) as c2
  4  from dual
  5  connect by level <= 10000
  6  ;

Table created.

テーブルT1に対してトリガーを作って行一件が変更されるたびにpkg_temp.g_update_cnt値を１づつ増加します。

UKJA@ukja1021> create or replace package pkg_temp
  2  is
  3   g_update_cnt number;
  4  end;
  5  /

Package created.

UKJA@ukja1021> -- create trigger
UKJA@ukja1021> create or replace trigger trg1
  2  after update on t1
  3  for each row
  4  begin
  5   pkg_temp.g_update_cnt := pkg_temp.g_update_cnt + 1;
  6  end;
  7  /

次のように10,000件を変更するとpkg_temp.g_update_cnt値は10,000になります。

UKJA@ukja1021> exec pkg_temp.g_update_cnt := 0;

PL/SQL procedure successfully completed.

UKJA@ukja1021> 
UKJA@ukja1021> update t1 set c2 = rpad('y',1000)
  2  where c1 = c1
  3  ;

10000 rows updated.

UKJA@ukja1021> commit;

Commit complete.

UKJA@ukja1021> 
UKJA@ukja1021> exec dbms_output.put_line('update cnt = ' || pkg_temp.g_update_cnt);
update cnt = 10000

PL/SQL procedure successfully completed.

今、次のようにテストを変更します。

1. セッションAで10,000件を変更します。
   
2. セッションAがまだ最後の行を変更する前にセッションBが最後の行の値を変えてコミットを行います。
   
3. セッションAが変更を終えたあとpkg_temp.g_update_cnt値を確認します。
   

セッションAが10,000件を変更始めます。

UKJA@ukja1021> exec pkg_temp.g_update_cnt := 0;

PL/SQL procedure successfully completed.

UKJA@ukja1021> 
UKJA@ukja1021> update t1 set c2 = rpad('y',1000)
  2  where c1 = c1
  3  ;
....

セッションAがまだ最後の行を変更する前にセッションBが最後の行の値を変えてコミットを行います。

UKJA@ukja1021> update t1 set c1 = c1+1 where c1 = 10000;

1 row updated.

UKJA@ukja1021> commit;

Commit complete.

セッションAが変更を終えた後pkg_temp.g_update_cnt値を確認します。驚いたことにpgk_temp.g_update_cntの値は19,999件です!

...
10000 rows updated.

UKJA@ukja1021> commit;

Commit complete.

UKJA@ukja1021> exec dbms_output.put_line('update cnt = ' || pkg_temp.g_update_cnt);
update cnt = 19999

PL/SQL procedure successfully completed.

これは10,000件ではなくてその二倍に該当する20,000件ぐらいが変更されたということを意味します。これをよくRestartメカニズムと呼びます。

1. セッションAが最後の行を変更するため一応Consistent Readモードで該当ブロックを読み込みます。
   
2. セッションAはクエリが始まった後該当行がセッションBに変更されてコミットされたのを確認します。
   
3. UPDATE文のwhere c1 = c1 条件で一貫性確認(Consistency Check)がなされます。セッションAは最後の行はUPDATEが始まった後で変更されたので該当条件を満足するかしないかを確認するのが不可能だと判断します。
   
4. こんな場合セッションAは今までの変更をロールバックし、UPDATE文を行い直します。これをRestartメカニズムと言います。したがって9,999＋10,000＝19,999件の行が変更されたことです。
   

Restartの副作用はSQL*Traceの結果でもよく現れます。Restartが発生した場合同じに10,000個の行を変更しますが、ずっと多い仕事をします。ロールバックをして行い直さなければならないからです。

-- Restartがなされない場合
update t1 set c2 = rpad('y',1000)
where c1 = c1

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.01       0.00          0          7          0           0
Execute      1      0.34       0.52          0       1443      12992       10000
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.35       0.53          0       1450      12992       10000

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 61  

Rows     Row Source Operation
-------  ---------------------------------------------------
      0  UPDATE  T1 (cr=1487 pr=0 pw=0 time=530716 us)
  10000   TABLE ACCESS FULL T1 (cr=1432 pr=0 pw=0 time=74012 us)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  log buffer space                                5        0.01          0.05
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        0.00          0.00
********************************************************************************

-- Restartがなされる場合
update t1 set c2 = rpad('y',1000)
where c1 = c1

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      1.25       6.29          0       4323      67568       10000
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      1.25       6.29          0       4323      67568       10000

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 61  

Rows     Row Source Operation
-------  ---------------------------------------------------
      1  UPDATE  T1 (cr=4411 pr=0 pw=0 time=5643605 us)
  30000   TABLE ACCESS FULL T1 (cr=4297 pr=0 pw=0 time=180259 us)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  log file switch completion                      4        0.99          2.28
  log file switch (checkpoint incomplete)         2        0.38          0.44
  log buffer space                               18        0.68          1.98
  enq: TX - row lock contention                   1        0.07          0.07
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        0.00          0.00
********************************************************************************

このようなRestartメカニズムはよくオラクルは読み取り一貫性(Read Consistency)のみならず書き出し一貫性(Write Consistency)を持っているとも言います。もっと正確に言えばオラクルの読み取り一貫性(Read Consistency)のメカニズムがDMLに掛ける特殊な影響だと言っても良いでしょう。

オラクル性能に対する短い考え＃18

少数の視覚を持て

例えばこのようなものであります。

• 皆がSQLトレースに満足している時オラクル内部的な知識を活用して体系的な性能分析技法を研究したSteve Adamsさん。
  
• 皆がクエリをチューニングする方法について話をしている時オプティマィザの動作原理を元にした問題解決を話したJonathan Lewisさん。
  
• 皆がSQLトレースで満足している時ダイレクトメモリーアクセス方式でアクティブセッションをすべて収集して性能分析の新しい次元を提示したExemとMaxgauge。
  

私はこのごろすこしづつ自身が少数の視覚を備えて行っていると感じます。少数の視覚が成功的に大衆化すれば、すぐ多数の視覚になり、誰かがまた新しい少数の視覚を提示するはずです。こうだから知識の世界は面白いものです。

バインドピーキングとSQLトレースの出会い

バインドピーキング(Bind Peeking)が起こす一番大きい混乱の一つはバインド変数を使用する同一なSQL文章の実行計画が変わるということです。その中面白い事例一つを簡単なテストを通じて紹介します。

次のようにオブジェクトを作ります。

UKJA@ukja1106> create table t1(c1 int, c2 varchar2(10));

Table created.

UKJA@ukja1106> insert into t1
  2  select 1, level from dual connect by level <= 10000;

10000 rows created.

UKJA@ukja1106> 
UKJA@ukja1106> insert into t1
  2  select level, level from dual connect by level <= 10000;

10000 rows created.

UKJA@ukja1106> 
UKJA@ukja1106> create index t1_n1 on t1(c1);

Index created.

UKJA@ukja1106> 
UKJA@ukja1106> exec dbms_stats.gather_table_stats(user, 't1', -
>   method_opt=>'for columns c1 size skewonly');

PL/SQL procedure successfully completed.

コラムC1はばらつきがあってヒストグラムが存在します。統計情報はつぎのようです。Height-Balancedヒストグラムが生成されているのが分かります。

UKJA@ukja1106> @tab_stat t1
UKJA@ukja1106> set echo off
01. table stats
old   9:  table_name = upper(''&T_NAME'')
new   9:  table_name = upper(''t1'')
TABLE_NAME                    : T1
PARTITION_NAME                :
NUM_ROWS                      : 20000
BLOCKS                        : 42
SAMPLE_SIZE                   : 20000
LAST_ANAL                     : 2009/12/07 13:41:08
-----------------

PL/SQL procedure successfully completed.

02. column stats
old   9:  s.table_name = upper(''&T_NAME'')
new   9:  s.table_name = upper(''t1'')
TABLE_NAME                    : T1
COLUMN_NAME                   : C1
NUM_DISTINCT                  : 10000
NUM_NULLS                     : 0
DENSITY                       : .00005
LOW_VALUE                     : C102
HIGH_VALUE                    : C302
HISTOGRAM                     : HEIGHT BALANCED
-----------------
TABLE_NAME                    : T1
COLUMN_NAME                   : C2
NUM_DISTINCT                  :
NUM_NULLS                     :
DENSITY                       :
LOW_VALUE                     :
HIGH_VALUE                    :
HISTOGRAM                     : NONE
-----------------

PL/SQL procedure successfully completed.

03. histogram stats
old   7:  table_name = upper('&T_NAME')
new   7:  table_name = upper('t1')

TABLE_NAME           COLUMN_NAME          ENDPOINT_NUMBER ENDPOINT_VALUE
-------------------- -------------------- --------------- --------------------
T1                   C1                               126 1()
T1                   C1                               127 33()
T1                   C1                               128 112()
...
T1                   C1                               254 10000()

129 rows selected.

コラムC1に”１”を代入したらバインドピーキングによって全表走査を選択するようになります。

UKJA@ukja1106> var b1 number;
UKJA@ukja1106> exec :b1 := 1;
UKJA@ukja1106> var b2 varchar2(10);
UKJA@ukja1106> exec :b2 := '1';

UKJA@ukja1106> 
UKJA@ukja1106> select /*+ gather_plan_statistics */
  2   count(*) from t1
  3  where c1 = :b1 and c2 = :b2;

  COUNT(*)
----------
         2

--------------------------------------------------------------
| Id  | Operation          | Name | Starts | E-Rows | A-Rows |
--------------------------------------------------------------
|   1 |  SORT AGGREGATE    |      |      1 |      1 |      1 |
|*  2 |   TABLE ACCESS FULL| T1   |      1 |     99 |      2 |
--------------------------------------------------------------

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

   2 - filter("C2"=:B2)
   3 - access("C1"=:B1)

今度はSQL*Traceを活性化します。そしてコラムC1に1ではなくて2を代入します。

UKJA@ukja1106> alter session set sql_trace = true;

Session altered.

UKJA@ukja1106> var b1 number;
UKJA@ukja1106> exec :b1 := 2;

PL/SQL procedure successfully completed.

UKJA@ukja1106> var b2 varchar2(10);
UKJA@ukja1106> exec :b2 := '1';

PL/SQL procedure successfully completed.

UKJA@ukja1106> 
UKJA@ukja1106> select /*+ gather_plan_statistics */
  2   count(*) from t1
  3  where c1 = :b1 and c2 = :b2;

  COUNT(*)
----------
         0

-------------------------------------------------------------------------
| Id  | Operation                    | Name  | Starts | E-Rows | A-Rows |
-------------------------------------------------------------------------
|   1 |  SORT AGGREGATE              |       |      1 |      1 |      1 |
|*  2 |   TABLE ACCESS BY INDEX ROWID| T1    |      1 |      1 |      0 |
|*  3 |    INDEX RANGE SCAN          | T1_N1 |      1 |      1 |      1 |
------------------------------------------------------------------------- 

実行計画が変わりました。何かおかしいではありませんか。最初の実行でバインドピーキングがもうなされたので次の同一なテキストのクエリは同一な実行計画を見せなければなりません。

もっと詳細な分析をしてみましょう。まず現在登録されている息子LCOたちとその実行計画を見ます。

UKJA@ukja1106> select * from table(dbms_xplan.display_cursor('&sql_id', null, 'typical'));
old   1: select * from table(dbms_xplan.display_cursor('&sql_id', null, 'typical'))
new   1: select * from table(dbms_xplan.display_cursor('98721ruagfx5c', null, 'typical'))

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------
SQL_ID  98721ruagfx5c, child number 0
-------------------------------------
select /*+ gather_plan_statistics */  count(*) from t1 where c1 = :b1
and c2 = :b2

Plan hash value: 3724264953

---------------------------------------------------------------------------
| Id  | Operation          | Name | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |      |       |       |    18 (100)|          |
|   1 |  SORT AGGREGATE    |      |     1 |     8 |            |          |
|*  2 |   TABLE ACCESS FULL| T1   |    99 |   792 |    18   (0)| 00:00:01 |
---------------------------------------------------------------------------

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

   2 - filter(("C2"=:B2 AND "C1"=:B1))

SQL_ID  98721ruagfx5c, child number 1
-------------------------------------
select /*+ gather_plan_statistics */  count(*) from t1 where c1 = :b1
and c2 = :b2

Plan hash value: 359681750

--------------------------------------------------------------------------------------
| Id  | Operation                    | Name  | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |       |       |       |     2 (100)|          |
|   1 |  SORT AGGREGATE              |       |     1 |     8 |            |          |
|*  2 |   TABLE ACCESS BY INDEX ROWID| T1    |     1 |     8 |     2   (0)| 00:00:01 |
|*  3 |    INDEX RANGE SCAN          | T1_N1 |     1 |       |     1   (0)| 00:00:01 |
--------------------------------------------------------------------------------------

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

   2 - filter("C2"=:B2)
   3 - access("C1"=:B1)

確かに二つの実行計画が存在します。これが意味するのはSQLトレースが活性化されるとオラクルは同一なSQL文章だといっても他のSQL文で認識するということを意味します。その理由をV$SQL_SHARED_CURSORビューを通じて見つけられます。私が作成した簡単なスクリプトでV$SQL_SHARED_CURSORビューを検索します。

UKJA@ukja1106> @shared_cursor2 &sql_id
UKJA@ukja1106> set echo off
old  14:           and s.sql_id = ''&1''',
new  14:           and s.sql_id = ''98721ruagfx5c''',
SQL_TEXT                       = select /*+ gather_plan_statistics */  count(*) from t1 where c1 = :b1 and c2 = :b2
SQL_ID                         = 98721ruagfx5c
ADDRESS                        = 29D81B30
CHILD_ADDRESS                  = 2879E2BC
CHILD_NUMBER                   = 0
--------------------------------------------------
SQL_TEXT                       = select /*+ gather_plan_statistics */  count(*) from t1 where c1 = :b1 and c2 = :b2
SQL_ID                         = 98721ruagfx5c
ADDRESS                        = 29D81B30
CHILD_ADDRESS                  = 2F5E79DC
CHILD_NUMBER                   = 1
STATS_ROW_MISMATCH             = Y
--------------------------------------------------

すなわち、SQLトレースが活性化されるとSTATS_ROW_MISMATCHによってSQL文章を共有できずに新しいチャイルドカーソルを作るようになります。その過程で再びバインドピーキングがなされます。

SQLトレースの結果だけを見てせっかちにチューニングをするのはあぶないという恐れが生じませんか。

Oracle 11gの基準で同一なSQL文章が共有されないにはなんと60余種類の理由があります。

UKJA@ukja1106> desc v$sql_shared_cursor                       
           Name                                               
           ---------------------------------------------------
    1      SQL_ID                                             
    2      ADDRESS                                            
    3      CHILD_ADDRESS                                      
    4      CHILD_NUMBER                                       
    5      UNBOUND_CURSOR                                     
    6      SQL_TYPE_MISMATCH                                  
    7      OPTIMIZER_MISMATCH                                 
    8      OUTLINE_MISMATCH                                   
    9      STATS_ROW_MISMATCH                                 
   10      LITERAL_MISMATCH                                   
   11      FORCE_HARD_PARSE                                   
   12      EXPLAIN_PLAN_CURSOR                                
   13      BUFFERED_DML_MISMATCH                              
   14      PDML_ENV_MISMATCH                                  
   15      INST_DRTLD_MISMATCH                                
   16      SLAVE_QC_MISMATCH                                  
   17      TYPECHECK_MISMATCH                                 
   18      AUTH_CHECK_MISMATCH                                
   19      BIND_MISMATCH                                      
   20      DESCRIBE_MISMATCH                                  
   21      LANGUAGE_MISMATCH                                  
   22      TRANSLATION_MISMATCH                               
   23      ROW_LEVEL_SEC_MISMATCH                             
   24      INSUFF_PRIVS                                       
   25      INSUFF_PRIVS_REM                                   
   26      REMOTE_TRANS_MISMATCH                              
   27      LOGMINER_SESSION_MISMATCH                          
   28      INCOMP_LTRL_MISMATCH                               
   29      OVERLAP_TIME_MISMATCH                              
   30      EDITION_MISMATCH                                   
   31      MV_QUERY_GEN_MISMATCH                              
   32      USER_BIND_PEEK_MISMATCH                            
   33      TYPCHK_DEP_MISMATCH                                
   34      NO_TRIGGER_MISMATCH                                
   35      FLASHBACK_CURSOR                                   
   36      ANYDATA_TRANSFORMATION                             
   37      INCOMPLETE_CURSOR                                  
   38      TOP_LEVEL_RPI_CURSOR                               
   39      DIFFERENT_LONG_LENGTH                              
   40      LOGICAL_STANDBY_APPLY                              
   41      DIFF_CALL_DURN                                     
   42      BIND_UACS_DIFF                                     
   43      PLSQL_CMP_SWITCHS_DIFF                             
   44      CURSOR_PARTS_MISMATCH                              
   45      STB_OBJECT_MISMATCH                                
   46      CROSSEDITION_TRIGGER_MISMATCH                      
   47      PQ_SLAVE_MISMATCH                                  
   48      TOP_LEVEL_DDL_MISMATCH                             
   49      MULTI_PX_MISMATCH                                  
   50      BIND_PEEKED_PQ_MISMATCH                            
   51      MV_REWRITE_MISMATCH                                
   52      ROLL_INVALID_MISMATCH                              
   53      OPTIMIZER_MODE_MISMATCH                            
   54      PX_MISMATCH                                        
   55      MV_STALEOBJ_MISMATCH                               
   56      FLASHBACK_TABLE_MISMATCH                           
   57      LITREP_COMP_MISMATCH                               
   58      PLSQL_DEBUG                                        
   59      LOAD_OPTIMIZER_STATS                               
   60      ACL_MISMATCH                                       
   61      FLASHBACK_ARCHIVE_MISMATCH                         
   62      LOCK_USER_SCHEMA_FAILED                            
   63      REMOTE_MAPPING_MISMATCH                            
   64      LOAD_RUNTIME_HEAP_FAILED                           

こんなに多い理由が存在するので同一なSQL文章が複数の実行計画を見せる時必ずこのビューを検索しなければならないんでしょうね。

オラクル性能に対する短い考え＃17

DaaSの時代が来る？

クラウドコンピューティング(Cloud Computing)という新しい流れとともにデータベースをサービスで提供する試しが本格化されています。

私はこれをDaas(Database As A Service. ダース)と呼びます。自分の勝手に作った言葉せす。

これはオラクルのような商用ライセンスでもないし、PostgreSQLのような無料ライセンスでもない第三のライセンスです。データをどのくらい使うかによってお金を支払うとても合理的なライセンス政策が現れるようになります。

DaaSが成功的に普遍化すると企業はメインテナンスの費用を大きく減らすことができるでしょう。中小規模の企業には魅力的に見えます。もちろん大型企業たちは保安と性能、安全性の問題でいぜんとして既存の方式を選り好みする可能性が高いです。

エンジニアの立場から見ると大変な危機で思われるかも知れません。その間データベースのインストール、パッチ、チューニングに必要だった人力が大きく減りかねません。

しかしデータベースへの接近費用が大きく減るによってデータベース使用の爆発的な増加を呼び起こすはずです。そこから新しい機会が開かれるかもしれません。

バグ5364143 - バインドピーク問題

バインドピークが活性化されているにも関わらずバインドピークが実行されないバグ5364143があります。

1. クエリが最初にハードパースされる時はバインドピークが成功的に発生します。
   
2. 以降該当クエリがフラッシュ、メモリPressure、DDLなどの理由でInvalidationされます。
   
3. 次回に同一なクエリがまたハードパースされる時はバインドピークを修行しません。
   

ここで核心はクエリの情報全体が消えるのではなくて実行計画情報のみ消える場合です。SQL文章に当たるLCO(Library Cache Object)はヒープ0にメタ情報を、ヒープ6に実行計画情報を持っています。万一ヒープ6が消えて再びハードパースされる時はバインドピークが起こらない場合が時々発生すると言うのがこのバグが現れる方式です。

反面バインドピークを非活性化してもバインドピークが起こるバグもあります。

バインド変数を使用する同じSQL文章がたまに違う実行計画を作って困らせる場合が時々あったが、とてもその理由が分からない場合があります。こんなバグたちのためか疑われますね。

バージョン互換性を備えたスクリプト作り

オラクルバージョンが多様になり、バージョンごと支援するオブジェクトが変わるによりバージョン互換性を持つスクリプトを作るのが少しづつ難しくなっていきます。(幸いに基本となるオブジェクトたちは大きな変化がないので問題が深刻ではないけれどね)

例えば、9i以下だったらV$SESSION_WAITビューから、10g以上だったらV$SESSIONビューから待機イベント情報を抽出するスクリプトが作りたいんです。PL/SQLを利用せずSQL*Plusで実行可能な一つのスクリプトファイルで作りたければどうしたらいいでしょうか。多い方法があるはずですが次のような簡単なトリックが使えます。

col is_10g new_value __is_10g
col is_9i new_value __is_9i

with v as (
 select 
  to_number(substr(banner, 
     instr(banner, 'Release ')+8,
     instr(banner, '.') - instr(banner, 'Release ')-8)) as version
 from v$version where rownum = 1
)
select
 case when version >= 10 then '' else '--' end as is_10g,
 case when version <= 9 then '' else '--' end as is_9i
from v
;

__is_19g、__is_9i置換変数を利用して次のように手軽に解決します。

select * from (
&__is_10g select event, p1, p2, p3 from v$session
&__is_9i select event, p1, p2, p3 from v$session_wait
)
;

応用したら次のようにバージョン別にコラムまで操作できます。

select 
 sid
 ,serial#
&__is_10g ,event
&__is_10g ,p1
from
 v$session
;

SQL*Plusの強力さが分かる良い例と言えます。

オラクルに対する短い考え #16

オラクルは長い間ほとんど変わらなかった

オラクル性能トラブルシューチングが難しいながらも易しい理由があります。オラクルがエンタープライズの姿を備えたのがバージョン6(1988年)からと言われます。Undoに基づいた細かい行レベルロックとPL/SQLを支援し始めたのがこの時からです。

なんと20年の間オラクルの核心エンジンはほとんど変化なしに維持されて来ています。Redo、Undo、行レベルロック、Enqueue、Latch、Shared Pool、Cache Bufferなど性能を支配するすべての要素が大きい変化なしに(しかし少しづつ改善されながら)その様子をそのまま持っています。

そのおかげで核心概念に対する理解が優れたら少ない努力だけで専門家的な水準を維持できます。しかし逆さまに言うと核心的な概念に対する理解が十分ではなければ何か勉強し続けてもいつも2%不足な状態になります。

Oracle 11gR2의 Zero-Size Unusable Indexとテーブル拡張(Table Expansion)

Christian AntogniniがここからOracle 11gR2の新機能の一つのZero-size Unusable Indexに対する簡単な紹介とオプティマィザに及ぶ影響について説明しています。

Zero-Sized Unusable Indexというのは使用不可インデックスまたはインデックスパーティションのセグメント空間を物理的に解除することを意味しています。次に簡単な例があります。

バージョンはOracle 11gR2です。

UKJA@UKJA1120> select * from v$version where rownum <= 1;
BANNER
----------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - Production

パーティションテーブルを作ってからローカルインデックスを作ります。

UKJA@UKJA1120> create table t1(c1 int, c2 int)
  2  partition by range(c1) (
  3        partition p1 values less than (10000),
  4        partition p2 values less than (20000),
  5        partition p3 values less than (30000),
  6        partition p4 values less than (maxvalue)
  7  );

Table created.

UKJA@UKJA1120> insert into t1 select level, level from dual connect by level <= 30000;

30000 rows created.

Elapsed: 00:00:00.14
UKJA@UKJA1120> 
UKJA@UKJA1120> create index t1_n1 on t1(c1) local;

Index created.

Elapsed: 00:00:00.17
UKJA@UKJA1120> 
UKJA@UKJA1120> @gather t1
UKJA@UKJA1120> exec dbms_stats.gather_table_stats(user, '&1', no_invalidate=>false);

最後のパーティションP4を除いて残りの三つのパーティションを使用不可の状態に変えます。

UKJA@UKJA1120> 
UKJA@UKJA1120> alter index t1_n1 modify partition p1 unusable;

UKJA@UKJA1120> alter index t1_n1 modify partition p2 unusable;

UKJA@UKJA1120> alter index t1_n1 modify partition p3 unusable;

USER_SEGMENTSビューを問い合わせてみると使用不可状態のインデックスパーティション自体が存在しないのが分かります。空間節約次元で望ましい動作方式と言えます。

UKJA@UKJA1120> select partition_name, bytes
  2  from user_segments where segment_name = 'T1_N1';

PARTITION_NAME            BYTES
-------------------- ----------
P4                     10485760

ここからもう一つの魔法のようなものが発生します。つぎのようにパーティションP3とP4をかかる条件節を持ったクエリを実行します。万一Oracle 10gだったら全表走査を選択するしかないでしょう。でもOracle 11gR2では次のようにUNION ALLに変化された完璧な実行計画が生成されます。

UKJA@UKJA1120> explain plan for
  2  select count(*) from t1
  3  where c1 between 29999 and 30001;

-------------------------------------------------------------
| Id  | Operation                 | Name    | Pstart| Pstop |
-------------------------------------------------------------
|   0 | SELECT STATEMENT          |         |       |       |
|   1 |  SORT AGGREGATE           |         |       |       |
|   2 |   VIEW                    | VW_TE_2 |       |       |
|   3 |    UNION-ALL              |         |       |       |
|   4 |     PARTITION RANGE SINGLE|         |     4 |     4 |
|   5 |      INDEX RANGE SCAN     | T1_N1   |     4 |     4 |
|   6 |     PARTITION RANGE SINGLE|         |     3 |     3 |
|   7 |      TABLE ACCESS FULL    | T1      |     3 |     3 |
-------------------------------------------------------------

インデックスが正常的に存在するパーティションP4に対しては索引走査を、インデックスが存在しないパーティションP3に対しては全表走査を修行します。こんな動作方式はパーティション数に関わらず良く修行されます。

UKJA@UKJA1120> alter index t1_n1 rebuild partition p2;

UKJA@UKJA1120> explain plan for
  2  select count(*) from t1
  3  where c1 between 19999 and 30001;

--------------------------------------------------------------
| Id  | Operation                  | Name    | Pstart| Pstop |
--------------------------------------------------------------
|   0 | SELECT STATEMENT           |         |       |       |
|   1 |  SORT AGGREGATE            |         |       |       |
|   2 |   VIEW                     | VW_TE_2 |       |       |
|   3 |    UNION-ALL               |         |       |       |
|   4 |     CONCATENATION          |         |       |       |
|   5 |      PARTITION RANGE SINGLE|         |     4 |     4 |
|   6 |       INDEX RANGE SCAN     | T1_N1   |     4 |     4 |
|   7 |      PARTITION RANGE SINGLE|         |     2 |     2 |
|   8 |       INDEX RANGE SCAN     | T1_N1   |     2 |     2 |
|   9 |     PARTITION RANGE SINGLE |         |     3 |     3 |
|  10 |      TABLE ACCESS FULL     | T1      |     3 |     3 |
--------------------------------------------------------------

この動作方式を見てこの一語を浮かべたらオプティマィザの動作方式についてある程度理解していると言えます。"Transformation!"

これを確認するため10053トレースを修行してみます。その結果です。

TE: Checking validity of table expansion for query block SEL$1 (#0)

***********************************
Cost-Based Table Expansion
***********************************
TE: Checking validity of TE for query block SEL$1 (#1)
TE: Checking validity of table expansion for query block SEL$1 (#1)

TE: after table expansion:******* UNPARSED QUERY IS *******
SELECT COUNT(*) "COUNT(*)" FROM  
(
 (SELECT 0 FROM "UKJA"."T1" "T1" 
  WHERE TBL$OR$IDX$PART$NUM("UKJA"."T1",0,0,65535,"T1".ROWID)>=4 AND 
  TBL$OR$IDX$PART$NUM("UKJA"."T1",0,0,65535,"T1".ROWID)<=4 
  AND "T1"."C1"<= 30001 AND NULL IS NULL 
  AND ("T1"."C1">=30000 OR NULL IS NOT NULL)) 
 UNION ALL  
 (SELECT 0 FROM "UKJA"."T1" "T1" 
  WHERE TBL$OR$IDX$PART$NUM("UKJA"."T1",0,0,65535,"T1".ROWID)>=3 
  AND TBL$OR$IDX$PART$NUM("UKJA"."T1",0,0,65535,"T1".ROWID)<=3 
  AND "T1"."C1">= 29999 AND "T1"."C1"<30000)) 
"VW_TE_1"

テーブル拡張(Table Expansion)という技法を通じて数個のパーティションをかかる条件節がUNION ALLに変形されたのが分かります。Oracle 11gR2で新しく追加されたこの技法は_OPTIMIZER_TABLE_EXPANSIONパラメターで制御されます。

UKJA@UKJA1120> alter session set "_optimizer_table_expansion" = false;

UKJA@UKJA1120> explain plan for
  2  select count(*) from t1
  3  where c1 between 19999 and 30001;

----------------------------------------------------------
| Id  | Operation                 | Name | Pstart| Pstop |
----------------------------------------------------------
|   0 | SELECT STATEMENT          |      |       |       |
|   1 |  SORT AGGREGATE           |      |       |       |
|   2 |   PARTITION RANGE ITERATOR|      |     2 |     4 |
|   3 |    TABLE ACCESS FULL      | T1   |     2 |     4 |
----------------------------------------------------------

もう一つの注意するところはテーブル拡張(Table Expansion)もコストベースで定義されていることです。万一費用計算で不利な値が出たら上の例でも全表走査を選択されたかも知れません。

Oracle 11gR2にまたどんな隠れた改善点が見つかるか楽しみですね。

オラクル性能に対する短い考え＃15

tahiti.oracle.comを使用しましょう。

オラクルが提供する命令文やPL/SQLパッケージの情報を探すとき一番先に行ってみるべき所は？

答えはGoogleではなくてTahitiです。Tahitiの存在を数人に聞いてみましたが知らない人が意外に多いんでした。習慣的にGoogleを検索する前に必ずしもここを尋ねてみましょう。マニュアルも読んでみなかったと怒られたくなければ。

なおSQL Referenceを読む方法も身につけましょう。SQL Referenceは次のような形式で文脈(Syntax)を説明しています。

上の形式がまだ慣れていなかったら練習がもっと必要です。最小限オラクルマニュアルほどはどんな問題もなしに読めるべきです。

統計情報がない時CBOは何をするだろうか。

この前統計情報がない場合オプティマィザが費用(Cost)をどのように計算するかに対する問い合わせがありました。基本的な方法は次のようです。

1. 動的サンプリング(Dynamic Sampling)が利用できればサンプリングにより統計情報を作った後で費用を計算する。
   
2. 動的サンプリングが利用できなければ内部的に決められている基本値を使用する。
   

ここで内部的に決められている基本値ということの意味が気になります。幸いにオラクルマニュアルとWolfgang Breitlingが作成した有名な白書によく説明してあります。

• オラクルマニュアル
  
• Look Under the Hood of CBO - the 10053 Event
  

簡単なテストを通じて整理してみます。

まず次のようにテーブルを作ります。

UKJA@ukja1021> -- case1
UKJA@ukja1021> create table t1
  2  as
  3  select level as c1, 'x' as c2
  4  from dual
  5  connect by level <= 10000;

Table created.

Elapsed: 00:00:00.04
UKJA@ukja1021> 
UKJA@ukja1021> create index t1_n1 on t1(c1);

Index created.

Elapsed: 00:00:00.03

動的サンプリングを動作しないようにする上、OPTIMIZER_MODE値をALL_ROWSにするによってオプティマィザが内部的な基本値を使用するようにします。

UKJA@ukja1021> alter session set optimizer_dynamic_sampling = 1;

Session altered.

Elapsed: 00:00:00.00
UKJA@ukja1021> alter session set optimizer_mode = all_rows;

Session altered.

実行計画を見ましょうか。たとえ統計情報はないんですけど、予測行件数が31で結構もっともらしく予測しました。

UKJA@ukja1021> explain plan for
  2  select * from t1
  3  where c1 = 1;

Explained.

-------------------------------------------------------------------------------------
| Id  | Operation                   | Name  | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |       |    31 |   496 |     2   (0)| 00:00:01 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T1    |    31 |   496 |     2   (0)| 00:00:01 |
|*  2 |   INDEX RANGE SCAN          | T1_N1 |    12 |       |     1   (0)| 00:00:01 |
-------------------------------------------------------------------------------------

31の予測行件数がどこから来たのかは10053トレースファイルによく書き込んであります。

***************************************
BASE STATISTICAL INFORMATION
***********************
Table Stats::
  Table: T1  Alias: T1  (NOT ANALYZED)
    #Rows: 3104  #Blks:  38  AvgRowLen:  100.00
Index Stats::
  Index: T1_N1  Col#: 1
    LVLS: 1  #LB: 21  #DK: 10000  LB/K: 1.00  DB/K: 1.00  CLUF: 16.00
***************************************
SINGLE TABLE ACCESS PATH
  Column (#1): C1(NUMBER)  NO STATISTICS (using defaults)
    AvgLen: 22.00 NDV: 97 Nulls: 0 Density: 0.010309
  Table: T1  Alias: T1     
    Card: Original: 3104  Rounded: 31  Computed: 31.04  Non Adjusted: 31.04
  Access Path: TableScan
    Cost:  10.15  Resp: 10.15  Degree: 0
      Cost_io: 10.00  Cost_cpu: 892035
      Resp_io: 10.00  Resp_cpu: 892035
  Access Path: index (AllEqGuess)
    Index: T1_N1
    resc_io: 2.00  resc_cpu: 29893
    ix_sel: 0.004  ix_sel_with_filters: 0.004
    Cost: 2.01  Resp: 2.01  Degree: 1
  Best:: AccessPath: IndexRange  Index: T1_N1
         Cost: 2.01  Degree: 1  Resp: 2.01  Card: 31.04  Bytes: 0

上の内容を分析してみると次のようです。

1. テーブルのブロック数は33である。
   
2. したがってテーブルの基本Cardinality = 38*(8192 - 24)/100 = 3103.84 = 3104になった。
   
3. したがって列C1のDensityは1 / ( 3103.84 / 32 ) = 0.01030981 = 0.010309である。
   
4. したがってWHERE C1 = 1に該当する予測行件数は3104 * 0.010309 = 31になる。
   

すなわち、テーブルブロック数だけ手に入ればその後は上で言った二つの文書で説明された内部的な公式によって自然に計算されます。ここで問題はテーブルのブロック数をどう手に入れるのです。オラクルマニュアルによると次のように得られます。

• セグメントに存在するExtent Mapからブロック数を手に入れる。
  
• 万一上の方法が不可能だったら(たとえばTable Functionを使ったりExternal Tableを使用したばあい)100だと仮定する。
  

上の説明が正しいかExtent Mapを実際に確認してみます。セグメントヘッダーブロックを見ると次のようにExtent Mapが存在します。

UKJA@ukja1021> col header_file new_value header_file
UKJA@ukja1021> col header_block new_value header_block
UKJA@ukja1021> select header_file, header_block
  2  from dba_segments where owner = user and segment_name = 'T1';

HEADER_FILE HEADER_BLOCK
----------- ------------
          7        40990

Elapsed: 00:00:00.03

UKJA@ukja1021> alter system dump datafile &header_file block &header_block;

...
  Extent Map
  -----------------------------------------------------------------
   0x01c0a009  length: 1280  

UKJA@ukja1021> select to_dec('01c0a009') from dual;

TO_DEC('01C0A009')
------------------
          29401097

Extent Mapによると一つのExtentが存在するし現在0番から37番、すなわち38個のブロックが実際に使用されているのが分かります。したがってオプティマィザは38個のブロックが存在すると認識しているのです。

-- dump_dba.sql : http://sites.google.com/site/ukja/sql-scripts-1/c/dump-dba
UKJA@ukja1021> @dump_dba 29401097
...
Dump of First Level Bitmap Block

  --------------------------------------------------------
  DBA Ranges :
  --------------------------------------------------------
   0x01c0a009  Length: 64     Offset: 0      
  
   0:Metadata   1:Metadata   2:Metadata   3:Metadata
   4:Metadata   5:Metadata   6:Metadata   7:Metadata
   8:Metadata   9:Metadata   10:Metadata   11:Metadata
   12:Metadata   13:Metadata   14:Metadata   15:Metadata
   16:Metadata   17:Metadata   18:Metadata   19:Metadata
   20:Metadata   21:Metadata   22:FULL   23:FULL
   24:FULL   25:FULL   26:FULL   27:FULL
   28:FULL   29:FULL   30:FULL   31:FULL
   32:FULL   33:FULL   34:FULL   35:FULL
   36:FULL   37:FULL   38:unformatted   39:unformatted
   40:unformatted   41:unformatted   42:unformatted   43:unformatted
   44:unformatted   45:unformatted   46:unformatted   47:unformatted
   48:unformatted   49:unformatted   50:unformatted   51:unformatted
   52:unformatted   53:unformatted   54:unformatted   55:unformatted
   56:unformatted   57:unformatted   58:unformatted   59:unformatted
   60:unformatted   61:unformatted   62:unformatted   63:unformatted
  --------------------------------------------------------

この情報はdbms_space.unused_spaceプロシージャを通じて手に入れた値を一致します。したがってExtent Mapを通じてテーブルのブロック数を手に入れるというマニュアルの内容が事実であることが分かります。

UKJA@ukja1021> exec show_space('T1');
Free Blocks.............................
Total Blocks............................1280
Total Bytes.............................10485760
Total MBytes............................10
Unused Blocks...........................1242
Unused Bytes............................10174464
Last Used Ext FileId....................9
Last Used Ext BlockId...................52489
Last Used Block.........................38

一つ面白いことはテーブルのブロック数を物理的に得るのでとても正確だということです。このために統計情報が全然無い状態で(そして動的サンプリングが動作しないことにもかかわらず)CBO(RBOではなくて)が作った実行計画が以外に立派なのでびっくりする場合があります。生半な統計情報よりは統計情報が初めからないほうが良い場合がたくさんあります。

オラクル性能に対する短い考え＃14

初期化パラメータのデフォルト値一つ一つには哲学が入っている。

オラクルほど初期化パラメータ(Initialization Parameter)を利用して多様な制御が可能なスフトも少ないんです。特に隠しパラメータと呼ばれるものたちは本当に細かいものまで制御できるようになっています。初めてはこんな多きパラメータたちが不慣れで面倒くさく感じられるかも知れませんが、オラクルを使用する時間が増えるほどありがたく感じるようになります。それだけ自由を許すと言う意味だからです。

ここのパラメータは固有の目的を持っています。多くのパラメータがデフォルト値(Default Value)を持っています。デフォルト値は当然にそのパラメータの固有の目的を一番よく果たすように設定されます。あるパラメータはデフォルト値が間違い設定されて私たちを困らせるようにします。オラクル開発チームが現実を誤解したはずです。デフォルト値が意味することを正確に理解したらそれだけオラクルの性能に対する理解が深まります。

例をあげてみましょうか。

• なぜOPTIMIZER_MODEのデフォルト値はALL_ROWSなのか。
  
• なぜ_OPTIM_PEEK_USER_BINDSのデフォルト値はTRUEなのか。
  
• なぜOPTIMIZER_DYNAMIC_SAMPLINGのデフォルト値は2なのか。
  
• なぜDB_BLOCK_SIZEは8KBなのか。
  

並列実行とV$PQ_TQSTATビュー

並列実行(Parallel Execution)をきちんと解析するには必ずといっても良いだけV$PQ_TQSTATビューを確認すべき場合があります。一度もこのビューを使用したことがなかったら次の例を見てびっくりするはずです。

オラクルバージョンは次のようです。

UKJA@ukja1021> select * from v$version where rownum = 1
  2  ;

BANNER
----------------------------------------------------------------
Oracle Database 10g Enterprise Edition Release 10.2.0.1.0 - Prod

テーブルを作ります。C1列について自然に整列になっている形態です。

UKJA@ukja1021> create table t1
  2  as select level as c1
  3  from dual
  4  connect by level <= 100000
  5  -- order by dbms_random.random
  6  -- how the table is ordered may affect the result
  7  ;

Table created.

テーブルの全ての行をフェッチするもっとも単純な形態の並列実行です。

UKJA@ukja1021> begin
  2    for c in ( select /*+ parallel(t1,4)*/ * from t1) loop
  3      null;
  4    end loop;
  5  end;
  6  /

PL/SQL procedure successfully completed.

その結果をV$PQ_TQSTATビューを通じて観察してみます。

ed pq_stat.sql

col process format a10
col server_type format a10
select dfo_number, tq_id, server_type,  process, 
  num_rows, bytes, avg_latency, waits, timeouts
from v$pq_tqstat
order by 1, 2, 3, 4, 5
;

その結果は次のようです。

UKJA@ukja1021> @pq_stat

DFO_NUMBER      TQ_ID SERVER_TYP PROCESS      NUM_ROWS      BYTES AVG_LATENCY
---------- ---------- ---------- ---------- ---------- ---------- -----------
     WAITS   TIMEOUTS
---------- ----------
         1          0 Consumer   QC             100000     595112           0
       223         64

         1          0 Producer   P000             5913      33710           0
         3          0

         1          0 Producer   P001            40870     243406           0
        21          0

         1          0 Producer   P002             7884      45733           0
         4          0

         1          0 Producer   P003            45333     272263           0
        23          0


Elapsed: 00:00:00.01

四つのスレーブプロセスがテーブルからデータを読み込む生産者(Producer)で動作しました。驚いたことにP001、P003二つのプロセスが大部分のデータを読み込み、残りの二つは一部のデータだけを読み込みました。スレーブプロセスの間にデータを公平に読み込んでいないと言えます。こんな現状ができたら並列実行の性能が考えより高くない結果になってしまいます。

ORDER BY句を利用して整列を修行したらもっと深刻な結果が出ます。

UKJA@ukja1021> begin
  2    for c in ( select /*+ parallel(t1,4)*/ * from t1 order by c1) loop
  3      exit;
  4    end loop;
  5  end;
  6  /

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.07
UKJA@ukja1021> 
UKJA@ukja1021> @pq_stat

DFO_NUMBER      TQ_ID SERVER_TYP PROCESS      NUM_ROWS      BYTES AVG_LATENCY
---------- ---------- ---------- ---------- ---------- ---------- -----------
     WAITS   TIMEOUTS
---------- ----------
         1          0 Consumer   P000             1972       9925           0
         9          2

         1          0 Consumer   P001             1971      10018           0
         9          3

         1          0 Consumer   P002             1971      10018           0
         8          2

         1          0 Consumer   P003            94086     565403           0
       116         47

         1          0 Producer   P004            31015     183753           0
        24          3

         1          0 Producer   P005            21681     129330           0
        17          4

         1          0 Producer   P006            27594     165130           0
        22          5

         1          0 Producer   P007            19710     117279           0
        14          2

         1          0 Ranger     QC                372       3789           0
         3          1

         1          1 Consumer   QC                100       1927           0
        67         23

         1          1 Producer   P000             1166       5782           0
        14          3

         1          1 Producer   P001             1146       5780           0
        14          3

         1          1 Producer   P002             1146       5781           0
        13          2

         1          1 Producer   P003             1146       5781           0
       122         48

14 rows selected.

四つのプロセス(P004 ~ P007)が生産者(Producer)でテーブルからデータを読み込むし四つのプロセス(P000 ~ P003)が消費者(Consumer)で整列を行いますが、その分布がたいへん良くないです。四つ目のプロセスであるP003が大部分の作業(94%、10,000件中94,086件)を行うのが分かります。このままなら並列実行のメリットはほとんどないと言えます。

こんな現状は索引を生成する時も同じです。索引の生成は内部的に整列作業を行います。次にその結果があります。

UKJA@ukja1021> create index t1_n1 on t1(c1) parallel 4;

Index created.

UKJA@ukja1021> @pq_stat

DFO_NUMBER      TQ_ID SERVER_TYP PROCESS      NUM_ROWS      BYTES AVG_LATENCY
---------- ---------- ---------- ---------- ---------- ---------- -----------
     WAITS   TIMEOUTS
---------- ----------
         1          0 Consumer   P000           100000    1807692           0
         4          1

         1          0 Consumer   P001                0         80           0
         4          1

         1          0 Consumer   P002                0         80           0
         4          1

         1          0 Consumer   P003                0         80           0
         4          1

         1          0 Producer   P004            11826     212999           0
         8          1

         1          0 Producer   P005            38899     705092           0
        26          4

         1          0 Producer   P006            11826     213097           0
         7          0

         1          0 Producer   P007            37449     676904           0
        29          6

         1          0 Ranger     QC                  0        160           0
         5          1

         1          1 Consumer   QC                  4       1272           0
         4          1

         1          1 Producer   P000                1        318           0
         0          0

         1          1 Producer   P001                1        318           0
         0          0

         1          1 Producer   P002                1        318           0
         0          0

         1          1 Producer   P003                1        318           0
         0          0


14 rows selected.

今度はP000プロセスが全ての整列作業を行いました。並列作業のメリットはないと言えます。

こんな現状はデータの整列程度とも関連があるようです。次のようにテーブルにランダムでデータが入るように変えてみます。

UKJA@ukja1021> create table t1
  2  as select level as c1
  3  from dual
  4  connect by level <= 100000
  5  order by dbms_random.random  -- !!
  6  -- how the table is ordered may affect the result
  7  ;

Table created.

この場合には四つのスレーブプロセスがほとんど公平に４等分して整列作業を行います。最高の理想的な場合だと言えます。

UKJA@ukja1021> begin
  2    for c in ( select /*+ parallel(t1,4)*/ * from t1 order by c1) loop
  3      exit;
  4    end loop;
  5  end;
  6  /

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.06
UKJA@ukja1021> 
UKJA@ukja1021> @pq_stat

DFO_NUMBER      TQ_ID SERVER_TYP PROCESS      NUM_ROWS      BYTES AVG_LATENCY
---------- ---------- ---------- ---------- ---------- ---------- -----------
     WAITS   TIMEOUTS
---------- ----------
         1          0 Consumer   P000            23570     132528           0
        39         13

         1          0 Consumer   P001            27176     164544           0
        65         16

         1          0 Consumer   P002            27655     167454           0
        50         18

         1          0 Consumer   P003            21599     130778           0
        60         14

         1          0 Producer   P004            17739     105608           0
        15          4

         1          0 Producer   P005            29044     173021           0
        30         10

         1          0 Producer   P006            21681     129097           0
        20          4

         1          0 Producer   P007            31536     187718           0
        23          5

         1          0 Ranger     QC                372       4546           0
         1          0

         1          1 Consumer   QC                100       1927           0
        67         24

         1          1 Producer   P000             1166       5782           0
        44         14

         1          1 Producer   P001              955       5782           0
        70         17

         1          1 Producer   P002              955       5780           0
        56         20

         1          1 Producer   P003              954       5777           0
        66         16


14 rows selected.

하지만 인덱스를 생성할 경우에는 여전히 같은 문제가 발생합니다.

UKJA@ukja1021> create index t1_n1 on t1(c1) parallel 4;

Index created.

Elapsed: 00:00:00.54
UKJA@ukja1021> 
UKJA@ukja1021> @pq_stat

DFO_NUMBER      TQ_ID SERVER_TYP PROCESS      NUM_ROWS      BYTES AVG_LATENCY
---------- ---------- ---------- ---------- ---------- ---------- -----------
     WAITS   TIMEOUTS
---------- ----------
         1          0 Consumer   P000           100000    1807712           0
         4          1

         1          0 Consumer   P001                0         80           0
         4          1

         1          0 Consumer   P002                0         80           0
         4          1

         1          0 Consumer   P003                0         80           0
         4          1

         1          0 Producer   P004            15768     285122           0
        10          0

         1          0 Producer   P005            32986     596372           0
        25          0

         1          0 Producer   P006            17739     320856           0
        12          1

         1          0 Producer   P007            33507     605762           0
        22          1

         1          0 Ranger     QC                  0        160           0
         1          0

         1          1 Consumer   QC                  4       1272           0
         3          1

         1          1 Producer   P000                1        318           0
         0          0

         1          1 Producer   P001                1        318           0
         0          0

         1          1 Producer   P002                1        318           0
         0          0

         1          1 Producer   P003                1        318           0
         0          0

14 rows selected.

上記の現状を見ると整列作業を並列に修行するコードの一部分にロジックの誤りがあると考えられます。V$PQ_TQSTATビューではなければこんな現状を観察するのは易しくないです。機会がある時ぜひ活用してみるのをお勧めします。

この現状に対するもっとも詳しい説明は次のURLを参照してください。

• Oracle Parallel Query Sorting and Index Creation Performance Problems
  

My Oracle Support(MOS. 旧Metalink)はなおHTMLを支援します。

何時ぞやメタリンクの次世代バージョンのMy Oracle Support(MOS)がオープンされました。その過程でログイン失敗、性能劣化などの問題かできましたが、その中でもフラッシュに対する不満が高いでした。

幸いにフラッシュではなくてHTMLで組み合わされたMy Oracle Supportがなお支援されています。次のURLを利用してみてください。

HTMLバージョンのMy Oracle Support

私もここを主に利用するつもりです。

オラクル性能に対する短い考え＃13

プログラミング実力はオラクル性能専門家になるのに一番大きい役にたつ

性能問題に対してある程度知識を積んでいってみると必ずしも大きい壁に会うようになります。その壁の名前は経験です。自分の経験が一番大きい限界になります。多くのエンジニアたちが一定水準を外れられない決定的な理由中の一つです。

自分の経験だけでは解決できない問題に会ったら創造的な方式で状況を解き明かすべきです。優れたプログラミング能力はこんな時に大きい役に立ちます。万一プログラミングが苦手だとしたら問題を解決する速度は遅くなるし正確度も低くなるものです。

すなわち、初対面の問題を速い速度で解決する最高の道具はプログラミング能力です。単純にプログラミング言語が分かるのかを言うわけではなくてそれを通じて問題を解き明かす能力を言っているのです。

いつかあなたが今解き明かしたこの問題が全世界で自分が最初に解決した問題となる瞬間が来るはずです。オラクル性能専門家の世界へいらっしゃったのを歓迎いたします!

Physical Reads、Logical Readsを追い掛けよう。

安そうに見えるが、難しい問題が多いです。次の例もその代表的な場合です。

まず次のように空いたテーブルを一つ作ります。動的サンプリングとハードパースによるI/O発生をなくすために統計情報と収集しクエリもあらかじめ一回づつ実行しておきます。

drop table t1 purge;

create table t1(c1 char(1));

exec dbms_stats.gather_table_stats(user, 't1');

select /* no_rows */ * from t1;
select /* 1 rows */ * from t1;

次の結果を見てください。

alter system flush buffer_cache;

select /* no_rows */ * 
from
 t1

Rows     Row Source Operation
-------  ---------------------------------------------------
      0  TABLE ACCESS FULL T1 (cr=3 pr=1 pw=0 time=828 us)
      

insert into t1 values('1');
commit;

alter system flush buffer_cache;

select /* 1 rows */ * 
from
 t1

Rows     Row Source Operation
-------  ---------------------------------------------------
      1  TABLE ACCESS FULL T1 (cr=21 pr=19 pw=0 time=3303 us)

空いたテーブルに対して全表走査をする場合にはPhysical Reads=1、Logical Reads=3であります。この値はどこから来るでしょうか。行(Row)が一つのテーブルの場合は全表走査に対してPhysical Reads=19、Logical Reads=21であります。この値はまたどこから来ますか。

この質問に答えてみたらオラクルでI/Oを追いかける簡単な技法を習うようになります。まずバージョンは次のようです。

UKJA@ukja1021> @version

BANNER
----------------------------------------------------------------
Oracle Database 10g Enterprise Edition Release 10.2.0.1.0 - Prod

TablespaceはASSM(Automatic Segment Space Management)で管理されていてExtentのサイズはUniform Size 10Mであります。テーブルにデータが一件もない場合のSQL*Traceに対するTkprofの結果です。

select /* no_rows */ * 
from
 t1


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        1      0.00       0.00          1          3          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      0.00       0.00          1          3          0           0

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 61  

Rows     Row Source Operation
-------  ---------------------------------------------------
      0  TABLE ACCESS FULL T1 (cr=3 pr=1 pw=0 time=828 us)

まずPhysical Reads(1)はどこから出た値かを確認してみます。トレース原本ファイルは次のようです。

PARSING IN CURSOR #10 len=30 dep=0 uid=61 oct=3 lid=61 tim=3012155435237 hv=1069717740 ad='2836fe0c'
select /* no_rows */ * from t1
END OF STMT
PARSE #10:c=0,e=877,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,tim=3012155435230
EXEC #10:c=0,e=46,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=3012155436544
WAIT #10: nam='SQL*Net message to client' ela= 4 driver id=1413697536 #bytes=1 p3=0 obj#=18 tim=3012155436775
WAIT #10: nam='db file sequential read' ela= 282 file#=7 block#=25630 blocks=1 obj#=55933 tim=3012155437320 
FETCH #10:c=0,e=833,p=1,cr=3,cu=0,mis=0,r=0,dep=0,og=1,tim=3012155437829
WAIT #10: nam='SQL*Net message from client' ela= 1197 driver id=1413697536 #bytes=1 p3=0 obj#=55933 tim=3012155439358
STAT #10 id=1 cnt=0 pid=0 pos=1 obj=55933 op='TABLE ACCESS FULL T1 (cr=3 pr=1 pw=0 time=828 us)'

Db file sequential readイベントを見たらFile#=7、Block#=25630であります。ブロックダンプを通じて確認して見るとSegment Headerであるのが分かります。

UKJA@ukja1021> @which_obj2 7 25630
old   1: alter system dump datafile &__FILE block &__BLOCK
new   1: alter system dump datafile 7 block 25630

System altered.

Elapsed: 00:00:00.04
------------------------------------------------
dba =               7/25630
type =              PAGETABLE SEGMENT HEADER
------------------------------------------------

すなわち、Segment Headerを読み込むために一回のPhysical Readsが発生します。データが一件もないのでこれ以上のI/Oは不必要です。Physical Readsが一回しかないと言うのがその証拠です。それにもかかわらずLogical Reads(cr)が3であるのはSegment Headerをもう二度(したがって総三回)読むのを意味します。その理由は文書化されていません。たぶん空間情報を得るために内部的に確認作業をするのではないかと考えています。

そんな理由で全表走査による最小のLogical Readsは三回と認識されています。ここで一つ確認したいことは10200イベントです。10200イベントはLogical Readsを追いかける時使用されます。

10200
 "consistent read buffer status"
// *Cause:
// *Action:

でもこのイベントはデータを読み込む時のみ動作します。すなわち上の例のようにSegment Headerのようなメタブロックを読み込む時には記録されないようです。惜しい制約です。

一件のデータをInsertした後を観察してみます。

insert into t1 values ('1');
commit;

SQL*TraceによるTkprofの結果は次のようです。

select /* 1 rows */ * 
from
 t1


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2      0.00       0.00         19         21          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.00       0.00         19         21          0           1

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 61  

Rows     Row Source Operation
-------  ---------------------------------------------------
      1  TABLE ACCESS FULL T1 (cr=21 pr=19 pw=0 time=3303 us)

私がテストしたシステムの場合にはPhysical Reads=19、Logical Reads=21であります。この値はバージョンやSegment Space Management方式、Extentのサイズによって違えます。

Physical Readsの19の値がどこから来たのかをトレース原本ファイルから確認してみます。

PARSING IN CURSOR #24 len=29 dep=0 uid=61 oct=3 lid=61 tim=3012155797727 hv=2697749229 ad='2825d88c'
select /* 1 rows */ * from t1
END OF STMT
PARSE #24:c=0,e=713,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,tim=3012155797723
EXEC #24:c=0,e=49,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=3012155799033
WAIT #24: nam='SQL*Net message to client' ela= 6 driver id=1413697536 #bytes=1 p3=0 obj#=0 tim=3012155799433
WAIT #24: nam='db file sequential read' ela= 254 file#=7 block#=25630 blocks=1 obj#=55933 tim=3012155800000
WAIT #24: nam='db file sequential read' ela= 243 file#=7 block#=25609 blocks=1 obj#=55933 tim=3012155800562
WAIT #24: nam='db file sequential read' ela= 228 file#=7 block#=25629 blocks=1 obj#=55933 tim=3012155801014
WAIT #24: nam='db file scattered read' ela= 1315 file#=7 block#=25641 blocks=16 obj#=55933 tim=3012155802707
FETCH #24:c=0,e=3316,p=19,cr=13,cu=0,mis=0,r=1,dep=0,og=1,tim=3012155803019
WAIT #24: nam='SQL*Net message from client' ela= 298 driver id=1413697536 #bytes=1 p3=0 obj#=55933 tim=3012155803696
FETCH #24:c=0,e=34,p=0,cr=8,cu=0,mis=0,r=0,dep=0,og=1,tim=3012155803938
WAIT #24: nam='SQL*Net message to client' ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=55933 tim=3012155803998
WAIT #24: nam='SQL*Net message from client' ela= 2449 driver id=1413697536 #bytes=1 p3=0 obj#=55933 tim=3012155806478
STAT #24 id=1 cnt=1 pid=0 pos=1 obj=55933 op='TABLE ACCESS FULL T1 (cr=21 pr=19 pw=0 time=3303 us)'

三回のSingle Block I/O(Db file sequential read)と一回のMulti Block I/O(Db file scatteread read、Blocks=16)を通じて総19ブロックをPhysical I/Oで読み込みました。Single Block I/Oがどんなブロックを読み込んだのを確認してみたら次のようです。

UKJA@ukja1021> @which_obj2 7 25630
UKJA@ukja1021> @which_obj2 7 25609
UKJA@ukja1021> @which_obj2 7 25629

------------------------------------------------
dba =               7/25630
type =              PAGETABLE SEGMENT HEADER
------------------------------------------------
dba =               7/25609
type =              FIRST LEVEL BITMAP BLOCK
object_id =         55933
object_name =       T1
------------------------------------------------
dba =               7/25629
type =              SECOND LEVEL BITMAP BLOCK
object_id =         55933
object_name =       T1
------------------------------------------------

Segment HeaderとともにASSM(Automatic Segment Space Management)で使用されるFirst Level BMB、Second Level BMBを読み込んだのが分かります。（Third Level BMBはまだ生成されなかったので読み込まなかったんです）

それでは16個のPhysical Readsはどこから来たのでしょうか。スペース情報を見ると次のようです。

UKJA@ukja1021> exec show_space('T1');
Free Blocks.............................
Total Blocks............................1280
Total Bytes.............................10485760
Total MBytes............................10
Unused Blocks...........................1216
Unused Bytes............................9961472
Last Used Ext FileId....................7
Last Used Ext BlockId...................25609
Last Used Block.........................64

PL/SQL procedure successfully completed.

High Water Markが64番目のブロックまでを指差しています。したがってPhysical Readsは16ではなくて61(64－3)になるべきです。全表走査と言うのはデータブロックの初めてからHigh Water MarkまでをSequentialに読み込むのではありませんか。しかしオラクルはただ16個のブロックだけをPhysical Readsで読み込みました。これを説明しようとすればブロックの分布を管理するFirst Level BMBブロックの内容を見る必要があります。First Level BMB(file#=7, block#=25609)の内容は次のようです。

  --------------------------------------------------------
  DBA Ranges :
  --------------------------------------------------------
   0x01c06409  Length: 64     Offset: 0      
  
   0:Metadata   1:Metadata   2:Metadata   3:Metadata
   4:Metadata   5:Metadata   6:Metadata   7:Metadata
   8:Metadata   9:Metadata   10:Metadata   11:Metadata
   12:Metadata   13:Metadata   14:Metadata   15:Metadata
   16:Metadata   17:Metadata   18:Metadata   19:Metadata
   20:Metadata   21:Metadata   22:unformatted   23:unformatted
   24:unformatted   25:unformatted   26:unformatted   27:unformatted
   28:unformatted   29:unformatted   30:unformatted   31:unformatted
   32:75-100% free   33:75-100% free   34:75-100% free   35:75-100% free
   36:75-100% free   37:75-100% free   38:75-100% free   39:75-100% free
   40:75-100% free   41:75-100% free   42:75-100% free   43:75-100% free
   44:75-100% free   45:75-100% free   46:75-100% free   47:75-100% free
   48:unformatted   49:unformatted   50:unformatted   51:unformatted
   52:unformatted   53:unformatted   54:unformatted   55:unformatted
   56:unformatted   57:unformatted   58:unformatted   59:unformatted
   60:unformatted   61:unformatted   62:unformatted   63:unformatted

上の情報をみると総16個のブロック(32－47)のみが実際に使われていて残りのブロックは使わないUnformattedと言うのが分かります。オラクルはこの情報を利用して16個のブロックのみを一回のMulti Block I/Oで読み込んだのであります。

Physical Readsが19でここで上で見たように追加的なLogical Readsが二回発生するのでLogical Readsは21だと報告されているのです。

今頃ならなぜ安いながらも難しい質問だと言ったのか分かるんでしょう。意味のないテストのようですが(Just for Fun?)、その過程で得られる経験と知識は相当なものです。

テストで使われたスクリプトは次のURLを参照してください。

• show_space
  
• which_obj2
  

オラクル性能に対する短い考え＃11

性能問題に対する正確な理解は用語に対する正確な理解から来る。

人間の考える能力が言語を作ったが、逆に言語が言語が人間の考えを支配するようになるでしょう。

オラクル性能世界でも同じです。用語に対する正確な理解がなければ問題を100％理解できないばかりでなく間違った知識を信じるようになってしまいます。例を挙げてみましょうか。

• Explain PlanとExecution Planの違いが説明できますか。
  
• ScanとLookupの差異は何ですか。
  
• Histogramの意味は何ですか。
  
• LockとEnqueueの意味が分けられますか。
  
• SQLとCursorの違いが説明できますか。
  
• Eventと言う用語はいつ使われるのか説明できますか。
  

用語が100％正確に説明できたらその自体で性能問題に対する相当な洞察力を持っていると言えます。

PL/SQLでのLoggingの使用

Programming Langaugeと言うのが開発された以降発明された最高のデバッグツールはなんでしょうか。精巧で強力なデバッグツールがたくさんありますがなお一番強力で一番よく使われるデバッグツールは開発者が自分で記録するログ(Log)であります。

しかしPL/SQLは相対的にログを残す機能がとても弱いです。この問題を話し合ってみみます。

一番よく使用されるのがDBMS_OUTPUTパッケージでしょう。でも、PL/SQLブロックの実行が終わった後で記録されるので実行時間が長いPL/SQLブロックをデバッグする場合は相当不便です。

set serveroutput on

begin
 for idx in 1 .. 10 loop
  dbms_output.put_line(sysdate || ', ' || idx || 'th insertion');
  dbms_lock.sleep(1);
 end loop;
end;
/

2009/11/10 13:33:18, 1th insertion
2009/11/10 13:33:19, 2th insertion
2009/11/10 13:33:20, 3th insertion
2009/11/10 13:33:21, 4th insertion
2009/11/10 13:33:22, 5th insertion
2009/11/10 13:33:23, 6th insertion
2009/11/10 13:33:24, 7th insertion
2009/11/10 13:33:25, 8th insertion
2009/11/10 13:33:26, 9th insertion
2009/11/10 13:33:27, 10th insertion

PL/SQL procedure successfully completed.

Elapsed: 00:00:10.00

他のトリックは次のようにDBMS_SYSTEMパッケージを用いてトレースファイル(1)やAlert Logファイル(2)、または両方(3)に記録することです。TAILとかテキストエディターでファイルを開けてみればいいでしょう。UTL_FILEパッケージを利用して別途のファイルに記録して確認することもできます。この方法の一つデメリットはログファイルがサーバーにあると言うことです。ネットワーク接続や保安の問題によって使用しにくい場合が多いです。

begin
 for idx in 1 .. 10 loop
  sys.dbms_system.ksdwrt(1, sysdate || ', ' || idx || 'th insertion');
  dbms_lock.sleep(1);
 end loop;
end;
/

-- C:\ORACLE\ADMIN\UKJA1021\UDUMP\ukja1021_ora_1448.trc
*** 2009-11-10 13:37:15.015
*** ACTION NAME:() 2009-11-10 13:37:15.000
*** MODULE NAME:(SQL*Plus) 2009-11-10 13:37:15.000
*** SERVICE NAME:(UKJA1021) 2009-11-10 13:37:15.000
*** SESSION ID:(140.1169) 2009-11-10 13:37:15.000
2009/11/10 13:37:15, 1th insertion
2009/11/10 13:37:16, 2th insertion
2009/11/10 13:37:17, 3th insertion
2009/11/10 13:37:18, 4th insertion
2009/11/10 13:37:19, 5th insertion
2009/11/10 13:37:20, 6th insertion
2009/11/10 13:37:21, 7th insertion
2009/11/10 13:37:22, 8th insertion
2009/11/10 13:37:23, 9th insertion
2009/11/10 13:37:24, 10th insertion

プログラミングに興味があったらもっと良い方法が作れます。次の例を見てください。Pipelined Table FunctionとDBMS_PIPEパッケージを利用しています。特定セッションでログを記録すれば他のセッションではSELECT文を利用してログの内容を確認できます。上で見た二つの方法をみんな乗り越えています。

create or replace package pkg_log
as 
  type log_array is table of varchar2(4000);
 procedure log(message in varchar2);
 procedure flush;
 function get_log return log_array pipelined;
end;
/

show err

create or replace package body pkg_log
as
 procedure log(message in varchar2) is
  v_status number;
 begin
  dbms_pipe.pack_message(sysdate || ', ' || message);
    v_status := dbms_pipe.send_message('log');
 end log;
 
 procedure flush is
  v_status number;
 begin
  dbms_pipe.pack_message('$$END$$');
  v_status := dbms_pipe.send_message('log');
 end;
 
 function get_log return log_array pipelined is
  v_status  number;
  v_message varchar2(4000);
 begin
  while true loop
   v_status := dbms_pipe.receive_message('log');
     if v_status = 0 then
       dbms_pipe.unpack_message(v_message);
       if v_message = '$$END$$' then
        return;
       end if;
       pipe row(v_message);
       pipe row('');
     end if;
  end loop;
  return;
 end get_log;
end;
/

show err

使用例は次のようです。

-- session #1
begin
 for idx in 1 .. 10 loop
  pkg_log.log(idx || 'th insertion');
  dbms_lock.sleep(1);
 end loop;
 pkg_log.flush;
end;
/


-- session #2
set array 2
set pages 100
select * from table(pkg_log.get_log);

COLUMN_VALUE
---------------------------------------

2009/11/10 13:30:12, 1th insertion

2009/11/10 13:30:13, 2th insertion

2009/11/10 13:30:14, 3th insertion

2009/11/10 13:30:15, 4th insertion

2009/11/10 13:30:16, 5th insertion

2009/11/10 13:30:17, 6th insertion

2009/11/10 13:30:18, 7th insertion

2009/11/10 13:30:19, 8th insertion

2009/11/10 13:30:20, 9th insertion

2009/11/10 13:30:21, 10th insertion

考え方に沿って無数な方法でログを管理することができます。重要なものは自分が必要なツールはたまに自分で作ることができれば良いと言うことです。

オラクル性能に対する短い考え＃11

人間は失敗から習うようにオラクル性能問題はバーグから習う

オラクル性能に対して最高のエンジニアはオラクル出身のエンジニアである場合がたくさんあります。なぜそうでしょうか。

オラクル内で他の人は得られない高級な情報をたくさん接したことでしょうか。

そうかも知れませんが、一番大きい理由はオラクルの障害およびバーグを接してそれを解決した経験が多いからです。

人間は失敗から習って、オラクルエンジニアは障害やバーグからオラクルを習うことです。障害に会ったら喜んで解決しようとすべき理由です。

SELECT文－Parse, Execute, Fetchどの段階？

大部分のSELECT文はFetch段階で多くの時間とI/Oを使うようになります。例として、次のTkprof結果を見てください。

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.01       0.03          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2      0.15       0.26        172        161          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.17       0.29        172        161          0           1

とても一般的な結果でしょう。SQL文は次のようです。

select max(t1.c1), max(t2.c2) from t1, t2
where rownum <= 100000
order by t2.c2, t1.c1

今度は次の結果を見てください。いかがですか。なぜFetch段階じゃなくてParse段階で大部分の時間を使っていますか。

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1    300.10     353.29         90       7060          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2      0.00       0.00          0          0          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4    300.10     353.29         90       7060          0           1

正答はハードパースです。ハードパースのために発生するOptimization過程はParse段階に属するのでTkprof結果でもParse段階に記録されます。SQL文は次のようです(500個のテーブルをジョインするように動的に生成されたSQL文です）。

select count(*) from T_HEAP_DUMP, T_ALERT_ANALYZE, T_MON_TEMP, T_MON_TIME_TEMP,
T_MON_LATCH_TEMP, T_MON_EVENT_TEMP, T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP,
CHAINED_ROWS, TT1, TT2, T1, T_SMALL, EXT_ORAUS, T_SMALL_WITH_SMALL_ROW,
T_TARGET2, T_ORAUS, T_TARGET1, T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG,
T_SMALL_LOB, T_BIG_LOB, T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP,
T_ALERT_ANALYZE, T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP,
T_MON_EVENT_TEMP, T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2,
T1, T_SMALL, EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP,  dual where 1 = 0

次はどうですか。なぜ今回はParse段階でもFetch段階でもなくてExecute段階で大部分の時間を使っていますか。

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1    322.45     368.33          3       6725          0           0
Fetch        2      0.00       0.01          0          0          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4    322.45     368.34          3       6725          0           1

正答はBind Peekingです。Bind Peekingが使われるとParse段階ではなくてExecute段階でOptimizationが行われます。従ってTkprof結果でもExecute段階に記録されます。

select count(*) from T_HEAP_DUMP, T_ALERT_ANALYZE, T_MON_TEMP, T_MON_TIME_TEMP,
T_MON_LATCH_TEMP, T_MON_EVENT_TEMP, T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP,
CHAINED_ROWS, TT1, TT2, T1, T_SMALL, EXT_ORAUS, T_SMALL_WITH_SMALL_ROW,
T_TARGET2, T_ORAUS, T_TARGET1, T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG,
T_SMALL_LOB, T_BIG_LOB, T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP,
T_ALERT_ANALYZE, T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP,
T_MON_EVENT_TEMP, T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2,
T1, T_SMALL, EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP, T_MON_MUTEX_TEMP, CHAINED_ROWS, TT1, TT2, T1, T_SMALL,
EXT_ORAUS, T_SMALL_WITH_SMALL_ROW, T_TARGET2, T_ORAUS, T_TARGET1,
T_SMALL_WITH_BIG_ROW, T_SMALL_WITH_LOB, T_NO_LOG, T_SMALL_LOB, T_BIG_LOB,
T_NOLOB, T3, T_LOB, T_NO_LOB, T_TARGET, T2, T_HEAP_DUMP, T_ALERT_ANALYZE,
T_MON_TEMP, T_MON_TIME_TEMP, T_MON_LATCH_TEMP, T_MON_EVENT_TEMP,
T_MON_ROWCACHE_TEMP,  dual where rownum = :b1

Tkprofの結果を解析する時はやっぱりいろいろなところに気にしなければならないと言う良い例の一つです。

オラクル性能に対する短い考え＃10

パーティションはOLTPとはあまり関係ない

パーティションは大容量のデータを扱うDWシステムのため設計されました。OLTPシステムでのメリットはほとんどないと思います。

単純に行数が多いという理由でパーティションの使用を考慮していたら考え直すほうが良いです。目的に会わないパーティションの使用はかえって管理の難しさと以外の性能問題を起こす可能性があります。

もちろんOLTPとDWの中間どこかにあるハイブリッドシステムが多いので現実はこんなに単純ではありませんけど…

Native Full Outer Hash JoinとROWNUM

オラクル11gはNative Full Outer Hash Joinを支援しています。ここによく説明されています。

ここで一つの疑問が生じます。Full Outer Joinを使いながらPagination QueryのためにROWNUM条件を使用すればオラクルはどんな実行計画を作るでしょうか。Native Full Outer JoinはHash Joinでだけ支援されるがPagination QueryはNested Loops Joinともっと似合います。次に簡単なテスト結果があります。

まず次のように二つのテーブルを作ります。

create table t1 as 
select level as c1, rpad('x',100) as c2
from dual
connect by level <= 100000
;

create table t2 as 
select level as c1, rpad('x',100) as c2
from dual
connect by level <= 100000
;

alter table t1 modify c1 not null;
alter table t2 modify c2 not null;

create index t1_n1 on t1(c1);
create index t2_n1 on t2(c1);

exec dbms_stats.gather_table_stats(user, 't1', no_invalidate=>false);
exec dbms_stats.gather_table_stats(user, 't2', no_invalidate=>false);

Full Outer Joinではない一般Outer Joinの場合はNested Loops Joinが選択されPaginationの目的によく合います。性能も優れるはずです。

explain plan for
select * from (
 select rownum as r, x.* from (
  select *
  from t1 left join t2 on t1.c1 = t2.c1
  ) x where rownum <= 10
) where r >= 1
;

-----------------------------------------------------------------------------
| Id  | Operation                      | Name  | Rows  | Bytes | Cost (%CPU)|
-----------------------------------------------------------------------------
|   0 | SELECT STATEMENT               |       |    10 |  1430 |    24   (0)|
|*  1 |  VIEW                          |       |    10 |  1430 |    24   (0)|
|*  2 |   COUNT STOPKEY                |       |       |       |            |
|   3 |    NESTED LOOPS OUTER          |       |    11 |  2310 |    24   (0)|
|   4 |     TABLE ACCESS FULL          | T1    |    11 |  1155 |     2   (0)|
|   5 |     TABLE ACCESS BY INDEX ROWID| T2    |     1 |   105 |     2   (0)|
|*  6 |      INDEX RANGE SCAN          | T2_N1 |     1 |       |     1   (0)|
-----------------------------------------------------------------------------

でもFull Outer Joinを使えばNative Full Outer Hash Joinが使用されます。Paginationの目的にはぜんぜん合いません。

explain plan for
select * from (
 select rownum as r, x.* from (
  select *
  from t1 full join t2 on t1.c1 = t2.c1
  ) x where rownum <= 10
) where r >= 1
;

--------------------------------------------------------------------------------
| Id  | Operation               | Name     | Rows  | Bytes |TempSpc| Cost (%CPU)
--------------------------------------------------------------------------------
|   0 | SELECT STATEMENT        |          |    10 |  1430 |       |  2302   (1)
|*  1 |  VIEW                   |          |    10 |  1430 |       |  2302   (1)
|*  2 |   COUNT STOPKEY         |          |       |       |       |            
|   3 |    VIEW                 | VW_FOJ_0 |   100K|    12M|       |  2302   (1)
|*  4 |     HASH JOIN FULL OUTER|          |   100K|    20M|    11M|  2302   (1)
|   5 |      TABLE ACCESS FULL  | T1       |   100K|    10M|       |   596   (1)
|   6 |      TABLE ACCESS FULL  | T2       |   100K|    10M|       |   596   (1)
--------------------------------------------------------------------------------

Native Full Outer Joinは次のパラメータで制御されます。

UKJA@ukja1106> @para outer_join
NAME                           VALUE                IS_DEFAUL SES_MODIFI
------------------------------ -------------------- --------- ----------
SYS_MODIFI
----------
DESCRIPTION
------------------------------------------------------------------------

_optimizer_native_full_outer_j FORCE                TRUE      true
oin
immediate
execute full outer join using native implementaion

このパラメータをオフさせたらNative Full Outer JoinではなくてUNION ALLを利用したFull Outer Join(すなわち10gの方式)に変わるだけ、Paginationに適当なNested Loops Joinに変わることではないんです。

explain plan for
select * from (
 select rownum as r, x.* from (
  select /*+ opt_param('_optimizer_native_full_outer_join', 'off') */ *
  from t1 full join t2 on t1.c1 = t2.c1
 ) x where rownum <= 10
) where r >= 1
;

--------------------------------------------------------------------------------
| Id  | Operation                 | Name  | Rows  | Bytes |TempSpc| Cost (%CPU)|
--------------------------------------------------------------------------------
|   0 | SELECT STATEMENT          |       |    10 |  1430 |       |  3620   (1)|
|*  1 |  VIEW                     |       |    10 |  1430 |       |  3620   (1)|
|*  2 |   COUNT STOPKEY           |       |       |       |       |            |
|   3 |    VIEW                   |       |   199K|    24M|       |  3620   (1)|
|   4 |     UNION-ALL             |       |       |       |       |            |
|*  5 |      HASH JOIN OUTER      |       |   100K|    20M|    11M|  2302   (1)|
|   6 |       TABLE ACCESS FULL   | T1    |   100K|    10M|       |   596   (1)|
|   7 |       TABLE ACCESS FULL   | T2    |   100K|    10M|       |   596   (1)|
|*  8 |      HASH JOIN RIGHT ANTI |       | 99999 |    10M|  1664K|  1318   (1)|
|   9 |       INDEX FAST FULL SCAN| T1_N1 |   100K|   488K|       |    86   (2)|
|  10 |       TABLE ACCESS FULL   | T2    |   100K|    10M|       |   596   (1)|
--------------------------------------------------------------------------------

無理にFIRST_ROWS(10)ヒントを与えるとようやく欲した形態の実行計画が現れます。

explain plan for
select * from (
 select rownum as r, x.* from (
  select /*+ first_rows(10) 
         opt_param('_optimizer_native_full_outer_join', 'off') */ *
  from t1 full join t2 on t1.c1 = t2.c1
 ) x where rownum <= 10
) where r >= 1
;

-------------------------------------------------------------------------------
| Id  | Operation                        | Name  | Rows  | Bytes | Cost (%CPU)|
-------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                 |       |    10 |  1430 |    37   (0)|
|*  1 |  VIEW                            |       |    10 |  1430 |    37   (0)|
|*  2 |   COUNT STOPKEY                  |       |       |       |            |
|   3 |    VIEW                          |       |    22 |  2860 |    37   (0)|
|   4 |     UNION-ALL                    |       |       |       |            |
|   5 |      NESTED LOOPS OUTER          |       |    11 |  2310 |    24   (0)|
|   6 |       TABLE ACCESS FULL          | T1    |    11 |  1155 |     2   (0)|
|   7 |       TABLE ACCESS BY INDEX ROWID| T2    |     1 |   105 |     2   (0)|
|*  8 |        INDEX RANGE SCAN          | T2_N1 |     1 |       |     1   (0)|
|   9 |      NESTED LOOPS ANTI           |       |    11 |  1210 |    13   (0)|
|  10 |       TABLE ACCESS FULL          | T2    |    11 |  1155 |     2   (0)|
|* 11 |       INDEX RANGE SCAN           | T1_N1 |     1 |     5 |     1   (0)|
-------------------------------------------------------------------------------

これはちょっと失望名結果です。なぜならROWNUM条件を使えばオラクルは内部的にFIRST ROWS技法を真似するオプションを持っているからです。でも願っただけきちんと動作しませんでした。

UKJA@ukja1106> @para rownum_pred
NAME                           VALUE                IS_DEFAUL SES_MODIFI
------------------------------ -------------------- --------- ----------
SYS_MODIFI
----------
DESCRIPTION
------------------------------------------------------------------------

_optimizer_rownum_pred_based_f TRUE                 TRUE      true
kr
immediate
enable the use of first K rows due to rownum predicate

次のようにヒントを使用してNative Full Outer Hash Joinを制御できます。

UKJA@ukja1106> @hint native

NAME                           INVERSE                        VERSION
------------------------------ ------------------------------ ----------
NATIVE_FULL_OUTER_JOIN         NO_NATIVE_FULL_OUTER_JOIN      10.2.0.3
NO_NATIVE_FULL_OUTER_JOIN      NATIVE_FULL_OUTER_JOIN         10.2.0.3

次のように使用します。

explain plan for
select * from (
 select rownum as r, x.* from (
  select /*+ first_rows(10) no_native_full_outer_join */ *
  from t1 full join t2 on t1.c1 = t2.c1
  ) x where rownum <= 10
) where r >= 1
;

-------------------------------------------------------------------------------
| Id  | Operation                        | Name  | Rows  | Bytes | Cost (%CPU)|
-------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                 |       |    10 |  1430 |    37   (0)|
|*  1 |  VIEW                            |       |    10 |  1430 |    37   (0)|
|*  2 |   COUNT STOPKEY                  |       |       |       |            |
|   3 |    VIEW                          |       |    22 |  2860 |    37   (0)|
|   4 |     UNION-ALL                    |       |       |       |            |
|   5 |      NESTED LOOPS OUTER          |       |    11 |  2310 |    24   (0)|
|   6 |       TABLE ACCESS FULL          | T1    |    11 |  1155 |     2   (0)|
|   7 |       TABLE ACCESS BY INDEX ROWID| T2    |     1 |   105 |     2   (0)|
|*  8 |        INDEX RANGE SCAN          | T2_N1 |     1 |       |     1   (0)|
|   9 |      NESTED LOOPS ANTI           |       |    11 |  1210 |    13   (0)|
|  10 |       TABLE ACCESS FULL          | T2    |    11 |  1155 |     2   (0)|
|* 11 |       INDEX RANGE SCAN           | T1_N1 |     1 |     5 |     1   (0)|
-------------------------------------------------------------------------------

伝統的なUSE_NLヒントも当然動作します。

explain plan for
select * from (
 select rownum as r, x.* from (
  select /*+ use_nl(t1) use_nl(t2) */ *
  from t1 full join t2 on t1.c1 = t2.c1
  ) x where rownum <= 10
) where r >= 1
;

--------------------------------------------------------------------------
| Id  | Operation                        | Name  | Rows  | Bytes |TempSpc|
--------------------------------------------------------------------------
|   0 | SELECT STATEMENT                 |       |    10 |  1430 |       |
|*  1 |  VIEW                            |       |    10 |  1430 |       |
|*  2 |   COUNT STOPKEY                  |       |       |       |       |
|   3 |    VIEW                          |       |   199K|    24M|       |
|   4 |     UNION-ALL                    |       |       |       |       |
|   5 |      NESTED LOOPS OUTER          |       |   100K|    20M|       |
|   6 |       TABLE ACCESS FULL          | T1    |   100K|    10M|       |
|   7 |       TABLE ACCESS BY INDEX ROWID| T2    |     1 |   105 |       |
|*  8 |        INDEX RANGE SCAN          | T2_N1 |     1 |       |       |
|*  9 |      HASH JOIN RIGHT ANTI        |       | 99999 |    10M|  1664K|
|  10 |       INDEX FAST FULL SCAN       | T1_N1 |   100K|   488K|       |
|  11 |       TABLE ACCESS FULL          | T2    |   100K|    10M|       |
--------------------------------------------------------------------------

Nested Loops Joinが選択された場合とそうではない場合はPagination Queryで相当な性能の違いが存在します。

select /*+ gather_plan_statistics */ * from (
 select rownum as r, x.* from (
  select *
  from t1 full join t2 on t1.c1 = t2.c1
  ) x where rownum <= 10
) where r >= 1
;

--------------------------------------------------------------------------------
| Id  | Operation               | Name     | Starts | A-Rows | Buffers | Reads |
--------------------------------------------------------------------------------
|*  1 |  VIEW                   |          |      1 |     10 |    1547 |    682|
|*  2 |   COUNT STOPKEY         |          |      1 |     10 |    1547 |    682|
|   3 |    VIEW                 | VW_FOJ_0 |      1 |     10 |    1547 |    682|
|*  4 |     HASH JOIN FULL OUTER|          |      1 |     10 |    1547 |    682|
|   5 |      TABLE ACCESS FULL  | T1       |      1 |    100K|    1542 |      0|
|   6 |      TABLE ACCESS FULL  | T2       |      1 |     16 |       5 |      0|
--------------------------------------------------------------------------------


select /*+ gather_plan_statistics */ * from (
 select rownum as r, x.* from (
  select /*+ first_rows(10) 
       opt_param('_optimizer_native_full_outer_join', 'off') */ *
  from t1 full join t2 on t1.c1 = t2.c1
 ) x where rownum <= 10
) where r >= 1
;

------------------------------------------------------------------------------
| Id  | Operation                        | Name  | Starts | A-Rows | Buffers |
------------------------------------------------------------------------------
|*  1 |  VIEW                            |       |      1 |     10 |      16 |
|*  2 |   COUNT STOPKEY                  |       |      1 |     10 |      16 |
|   3 |    VIEW                          |       |      1 |     10 |      16 |
|   4 |     UNION-ALL                    |       |      1 |     10 |      16 |
|   5 |      NESTED LOOPS OUTER          |       |      1 |     10 |      16 |
|   6 |       TABLE ACCESS FULL          | T1    |      1 |     10 |       5 |
|   7 |       TABLE ACCESS BY INDEX ROWID| T2    |     10 |     10 |      11 |
|*  8 |        INDEX RANGE SCAN          | T2_N1 |     10 |     10 |       9 |
|   9 |      NESTED LOOPS ANTI           |       |      0 |      0 |       0 |
|  10 |       TABLE ACCESS FULL          | T2    |      0 |      0 |       0 |
|* 11 |       INDEX RANGE SCAN           | T1_N1 |      0 |      0 |       0 |
------------------------------------------------------------------------------

ここでもう一つの疑問が持てます。多くのPagination QueryがORDER BY句を使用します。万一このORDER BYをインデックスで処理できないとしたらNested Loops Joinのメリットは消えてしまいます。こんな場合はNative Full Outer Hash Joinが本然のメリットを発揮することができるはずです。

私は個人的にFIRST_ROWS類のヒントやモードはなくなるべきだと思いますが、なお必要がありますね。:)

オプティマイザがだんだん賢くなっていますがたまにはとても簡単なクエリでも手動制御が必要な場合があります。われらが相変わらずヒントを身に付けなければならない理由となります。