パフォーマンスがころころ変化するSQLの調査
これもよくありますよね。
速かったり、遅かったりするけど、原因がなぜかわからない・・・。
こういう場合、実行計画がころころ変化してるケースが非常に多いです。
ということで、それの調べ方を。
あ、10gの話になるので、9i以前の方はすみません。
ここでは、例として下記のSQLのパフォーマンスがころころ変わっているとします。
このSQLはOracle内部で発行されているSQLなのですが、
ユーザが発行してるものだと思ってください。
select procedure#,procedurename,properties,itypeobj# from procedureinfo$ where obj#=:1 order by procedurename desc, overload# desc
9iまでは、こういったSQLレベルでの実行計画の変化を確認する場合、
Statspack の Snapshot を Level 6 以上で取得しておく必要がありましたが、
10g では、デフォルトで Automatic Workload Repository（以下AWR）という機能が動いており、
なにもしなくても、こういった情報を蓄積してくれています。
ただし！
この機能に付随するテーブルやビューへのアクセス、
パッケージの使用に関しては、Diagnostics Pack のライセンスが必要となるようです。
以下のSQLもライセンスが無いと実行してはいけないと思われます。
詳しくはこちら。
http://www.oracle.co.jp/products/price/oem10g_function.html
もしくは、OracleDirectまで。
はい、気を取り直して調査開始しましょう。
まずは、このSQLのSQL_IDを確認する必要があります。
V$SQLあたりを引っ掛ければOKですね。
SQL> SELECT SQL_ID FROM V$SQL WHERE SQL_TEXT LIKE 'select procedure#,procedurename,properties,itypeobj# from procedureinfo$ where obj#=:1 order by procedurename desc, overload# desc%'; SQL_ID -------------------- dcstr36r0vz0d dcstr36r0vz0d
２行出てますが、おそらく複数回パースがされているのでしょう・・・。
気にせず次いきます。
ここで、取得したSQL_IDを元に、AWRで持っている情報を引っ掛けにいきます。
たびたび出てきている DBMS_XPLAN というパッケージのDISPLAY_AWR というプロシージャで
AWR内部で持っている該当のSQLの実行計画を確認することが可能なんです。
SQL> select * from table(DBMS_XPLAN.DISPLAY_AWR('dcstr36r0vz0d',null,null,'ALL'));
PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------
SQL_ID dcstr36r0vz0d
--------------------
select procedure#,procedurename,properties,itypeobj# from
procedureinfo$ where obj#=:1 order by procedurename desc, overload# desc
Plan hash value: 17720163
----------------------------------------------------------------------
| Id | Operation | Name | Cost (%CPU)|
----------------------------------------------------------------------
| 0 | SELECT STATEMENT | | |
| 1 | SORT ORDER BY | | 0 (0)|
| 2 | TABLE ACCESS BY INDEX ROWID| PROCEDUREINFO$ | |
| 3 | INDEX RANGE SCAN | I_PROCEDUREINFO1 | |
----------------------------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
1 - SEL$1
2 - SEL$1 / PROCEDUREINFO$@SEL$1
3 - SEL$1 / PROCEDUREINFO$@SEL$1
SQL_ID dcstr36r0vz0d
--------------------
select procedure#,procedurename,properties,itypeobj# from
procedureinfo$ where obj#=:1
order by procedurename desc, overload# desc
Plan hash value: 3798950322
-------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
-------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | | | 5 (100)| |
| 1 | TABLE ACCESS BY INDEX ROWID | PROCEDUREINFO$ | 28 | 868 | 5 (0)| 00:00:01 |
| 2 | INDEX RANGE SCAN DESCENDING| I_PROCEDUREINFO1 | 28 | | 2 (0)| 00:00:01 |
-------------------------------------------------------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
1 - SEL$1 / PROCEDUREINFO$@SEL$1
2 - SEL$1 / PROCEDUREINFO$@SEL$1
44行が選択されました。
２種類出てきました。
でも、これだけだと、どっちが速くてどっちが遅いかは判断がつきにくい場合があります。
そこで、どの時間帯にどちらの実行計画が使用されていたかを確認し、
実際の使用感から、どっちの実行計画が優れているのかを判断します。
下記のSQLを実行することによって、時間帯ごとの実行計画の変化が確認できます。
SQL> set linesize 120
SQL> set pagesize 1000
SQL> col BEGIN_INTERVAL_TIME for a30
SQL> col SQL_ID for a20
SQL> SELECT DISTINCT
2 SQL.SNAP_ID ,SNAP.BEGIN_INTERVAL_TIME
3 ,SQL.SQL_ID ,SQL.PLAN_HASH_VALUE
4 FROM SYS.WRH$_SQLSTAT SQL
5 ,SYS.WRM$_SNAPSHOT SNAP
6 WHERE SQL.SNAP_ID = SNAP.SNAP_ID
7 AND SQL.SQL_ID='dcstr36r0vz0d'
8 ORDER BY SQL.SNAP_ID;
SNAP_ID BEGIN_INTERVAL_TIME SQL_ID PLAN_HASH_VALUE
---------- ------------------------------ -------------------- ---------------
37 08-05-20 18:55:53.000 dcstr36r0vz0d 3798950322
38 08-05-22 13:42:05.000 dcstr36r0vz0d 3798950322
40 08-05-22 15:00:18.037 dcstr36r0vz0d 3798950322
41 08-05-22 16:00:21.243 dcstr36r0vz0d 3798950322
42 08-05-25 14:42:14.000 dcstr36r0vz0d 3798950322
43 08-05-25 14:53:20.252 dcstr36r0vz0d 17720163
44 08-05-27 13:24:05.000 dcstr36r0vz0d 17720163
「PLAN_HASH_VALUE」列が実行計画の表示の「Plan hash value:」と対応しています。
上記の結果が返ってきていて、「08-05-25 14:42:14 ごろまでは速かった」という
証言が取れていれば、PLAN_HASH_VALUE:3798950322 のほうが速いということに
なりますので、ヒント句などを使用して、SQLの実行計画をそのように固めてあげればよいのです。
なお、今回の実験ですが、
一部説明しにくい結果が返ってきていたところがありましたので、
わかりやすいように改変しています。ご了承ください。
次回は、Diagnostics Pack のライセンス買ってねーよ！
って人のために、Statspackで同じような情報が
簡単に取り出せないか、実験してみたいと思います。
では。
