お世話になります。hiroと申します。初めて書き込みさせて頂きます。
現在Oracle11gにてSQLの性能計測をしています。
しかし同じ環境、SQL(データ件数は変わりません。)で秒数5秒~80秒と差異が出てしまい、
バッファや実行計画を消しているにもかかわらず測定結果が一定にならず、困ってしまっています。
特徴として、2回目以降が早くなります。
原因が分からずほとほと困り果ててしまいました。分かるプロフェッショナルな方、
どうか教えて下さい。
※事情があり、Oracleは再起動出来ません。。。
行なっている事は、以下です、
1.キャッシュ・実行計画の削除
以下コマンドで、削除を行なっています。
alter system flush buffer_cache;
alter system flush shared_pool;
※これでOracle側はクリアされているという理解です。x$bhテーブルの
stateが0になっています。
2.SQL/PLUS (ObjectBrowser)からSQLを実行
(その間にバッファに乗ってくるブロック数を確認する。)
※x$kcbwbpd,x$bhのテーブルを見てます。
3.トレースログを取得してTKPROFコマンドで整形しています。
※OSはLINUXで、sarコマンドで1秒づつ負荷を確認していますがIO負荷は
何も実行していない時は10%程度をずっと続けています。SQLを投げると6%程度
上がります。
上記を行なって凄い不思議な事があるのですが、
1)I/Oの読み込み速度が初回と次が違う。
2回目以降はバッファに乗ってくるブロックの数は同じなのですが、
速度が全然違うということです。1秒に200ブロック乗ってくるのが1回目だとすると
2回目は1秒に800ブロック乗ってきたりします。
しばらくほおっておくと速度が戻ったりします。
2)トレースログ(TKPROF)を見てみると、私の理解不足かと思うのですがキャッシュを
削除しているにもかかわらず、query(バッファアクセスブロック)の数が0に
なっていない。
※queryの説明を読むと、バッファアクセスブロックのアクセス数と記載があり、
バッファをクリアしているのであれば、0になるのかなっと思ってたりします。
(SQLを実行中にバッファに乗せてそのSQL自身がバッファを見てるみたいな
事なのでしょうか?・・??)
またrowsが同じSQLなのに数値がずれたりします。
(rowsは処理件数だと思っています。SQLPLUS上は15件検索されてきます。)
call count cpu elapsed disk query current rows
-----
Parse 2 0.11 0.12 0 0 0 0
Execute 2 0.00 0.00 0 0 0 0
Fetch 2 2.93 5.85 19279 507706 0 30
-----
total 6 3.04 5.98 19279 507706 0 30
ぼんやり、OSのファイルキャッシュとか削除しないといけない?
・・とか
起こっている事象に頭がついていかず湯気が出てます。
ちなみに1回目(遅いアクセスの場合は以下です。(同じSQLです。))
call count cpu elapsed disk query current rows
-----
Parse 1 0.12 0.18 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 2.24 78.03 19108 253168 0 10
-----
total 3 2.36 78.21 19108 253168 0 10
実行計画を見るのは初めてなので理解が間違っているかも知れませんが
ここの理解の仕方は全然違うよなどのアドバイスを頂けたら嬉しいです。
宜しくお願い致します。
Edited by: 915244 on 2012/02/17 5:04