Wednesday, December 30, 2009

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はオラクルからの大切なプレゼントです。たとえその値段は高いかも知れませんが、よく利用すればするほど支払いの甲斐があります。

Thursday, December 24, 2009

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

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


例えば、


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

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

Saturday, December 19, 2009

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がランタイムーエンジンまで適用されるはずだとはまったく期待しませんでした。でも結局そうなってしまいました。たぶん多くのシステムで熱いイシューになるはずです。

Wednesday, December 16, 2009

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

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



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



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

Monday, December 14, 2009

書き出し一貫性 - 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値を1づつ増加します。

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に掛ける特殊な影響だと言っても良いでしょう。

Saturday, December 12, 2009

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

少数の視覚を持て


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


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

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

Wednesday, December 9, 2009

バインドピーキングと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に”1”を代入したらバインドピーキングによって全表走査を選択するようになります。

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文章が複数の実行計画を見せる時必ずこのビューを検索しなければならないんでしょうね。

Saturday, December 5, 2009

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

DaaSの時代が来る?


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


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


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


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


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


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

Wednesday, December 2, 2009

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

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

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

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


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


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

Sunday, November 29, 2009

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

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


例えば、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の強力さが分かる良い例と言えます。

Thursday, November 26, 2009

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

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


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


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


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

Wednesday, November 25, 2009

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にまたどんな隠れた改善点が見つかるか楽しみですね。

Sunday, November 22, 2009

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

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


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


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


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




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

Saturday, November 21, 2009

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

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

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

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

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


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


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ではなくて)が作った実行計画が以外に立派なのでびっくりする場合があります。生半な統計情報よりは統計情報が初めからないほうが良い場合がたくさんあります。

Tuesday, November 17, 2009

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

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


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


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


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


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

Monday, November 16, 2009

並列実行と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.

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

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を参照してください。

Sunday, November 15, 2009

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

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


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


HTMLバージョンのMy Oracle Support


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

Saturday, November 14, 2009

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

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


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


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


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


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

Thursday, November 12, 2009

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を参照してください。

Tuesday, November 10, 2009

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

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


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


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


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

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

Monday, November 9, 2009

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 FunctionDBMS_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

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

Sunday, November 8, 2009

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

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


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


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


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


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

Saturday, November 7, 2009

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の結果を解析する時はやっぱりいろいろなところに気にしなければならないと言う良い例の一つです。

Tuesday, November 3, 2009

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

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


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


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


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

Monday, November 2, 2009

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類のヒントやモードはなくなるべきだと思いますが、なお必要がありますね。:)


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