待ちイベントに関する検証 その３
＜待ちイベントに関する検証 その３＞
ペンネーム： ダーリン
【latch: shared pool/library cache】
シシです。イノシシです。猪突猛進の年が始まりました。
もう進むしかありません。前だけを見つめて心惑わすことなく Oracle の世界
に浸りましょう。今年は 11g もやってきそうだし。
さて、ちょっと長めのお休みをいただきましたので前回までを軽く振り返りま
しょう。
今回のシリーズでは、待ちイベントにフォーカスして SQL の処理の流れを追
いかけてみることをテーマにしています。
1回目と、2回目は、DBへの入り口になるネットワーク関連の待ちイベントを探
ってみました。
通常 Idle イベントに分類されるものに関しては、監視しなくてもよいといわ
れることがありますが、FETCH SIZE (SQL*Plus では ARRAY SIZE)をちょっと
変更すると、この待ちイベントが減少することがわかりましたね。また、ネッ
トワークのトラフィックが混んでいると当然この待ちが長くなることも改めて
確認してみました。
では、今回からは DB サーバに到達した SQL を待ち受けている待ちイベント
達を探っていきましょう。
ところで、前回確認した待ちイベントはどんな感じでしたでしょうか。
もう一度見てみます。
SQL> select SID,EVENT,TOTAL_WAITS,TIME_WAITED 2 , TIME_WAITED_MICRO ,WAIT_CLASS 3 from v$session_event where sid = 142 4 order by TIME_WAITED_MICRO; SID EVENT TOTAL_WAITS TIME_WAITED ----- ------------------------------ ----------- ----------- 142 SQL*Net break/reset to client 1 0 142 SQL*Net message to client 180335 101 142 SQL*Net message from client 180334 495941 TIME_WAITED_MICRO WAIT_CLASS ----------------- ------------- 37 Application 1010033 Network 4959408972 Idle
うーんと、、そういえば、NetService 関連の待ちイベントしか現れていませ
んでした。いやいや、よく考えて見ましょう。待ちイベントはそのセッション
のみで発生するとは限りません。インスタンス全体ではどうなっているか一度
見てみましょう。
インスタンス全体で確認するには、V$SYSTEM_EVENT ビューのほうが都合がよ
いのでこれを使います。また、V$SESSION_EVENT ビューと同様に累積値で表示
されるため、今回は見やすくなるよう差分を取得するように工夫してみます。
（後述のスクリプト参照）
では、このスクリプトを実行してから、前回と同じSQLを実行します。
SQL> select * from test_tbl; C1 C2 C3 ----- ----- ----- 1 1 1 2 2 2 3 3 3 4 4 4 ... ... ... 99995 99995 99995 99996 99996 99996 99997 99997 99997 99998 99998 99998 99999 99999 99999 99999行が選択されました。 経過: 00:00:18.32
さて待ちイベントはっと、、、
event=[control file parallel write] wait_class=[System I/O] total_waits=[10] time_waited =[3] time_waited_micro=[24900]
注釈：”control file parallel write” はご存知のとおり制御ファイルに対
する書き込みの待ちイベントです。上記の SQL は検索処理のみなので
すが、今回差分取得のために一時的にテーブルに書き込むなどしている
ため制御ファイルに対してやや多めに書き込みが発生している可能性が
あります。
特に目立って何か待ちイベントが発生しているわけではないようです。（*1）
でもここであっさり引き下がっては、Oracle コンサルタントの名が廃ります。
ちょちょいっと”待ち”を発生させて待ちイベントを取得しましょう。
そりゃ！！
ちょっと見づらいので整理すると、、、
event wait_class total_wait time_waited ---------------------------- ------------ ---------- ------------ latch: shared pool Concurrency 15 4259 latch: library cache Concurrency 4 2953 latch free Other 13 1222 log file parallel write System I/O 62 16 control file parallel write System I/O 10 7 LGWR wait for redo copy Other 8 5
、、と、まぁこんな感じです。(*2)
どこか見覚えのある待ちイベントも出てきました。
待ちイベントはその処理単独で発生するようなケースと（I/O 待ちなど）、他
の処理と重なることで発生する待ちがあります。上記の待ちイベントは後者の
“競合”により発生した待ちイベントです。
この仕掛けは簡単で、実は同じ SQL を 20 セッションで同時実行してみました。
すると、してやったりです。wait_class に “Concurrency” が現れてきました。
ここでは library cache の競合が発生しています。
library cache の競合について簡単に説明しておきましょう。このメルマガ読
者の皆さんには”耳たこ”かも知れませんが。
Oracle の SGA には、いくつかのメモリ領域が存在しています。その中の共有
プールと呼ばれる領域で library cache の競合は発生します。共有プールには、
SQL の実行計画などを含めた解析情報や、テーブルなどのオブジェクトの情報
などが存在します。
あるセッションで SQL を実行しようとするとき、Oracle のプロセスは同じ SQL
の実行計画がすでに共有プールに存在するかどうかをまず最初に確認します。
SQL がすでに解析されているかどうかは、重要なポイントです。同じ SQL の
実行計画がすでに存在するのならわざわざ CPU 負荷を掛けて SQL を解析する
なんて無駄ですからね。それが何十、何百というセッションから頻繁に呼び出
されるSQLとなればなおさらです。
というわけで、同じ SQL の解析結果が共有プールに存在する場合はこれを再
利用します。この SQL を利用している間は、その他の要因で SQL の情報(実
行計画など)を変更されては困るのでしばらくの間ロックします。これがラッ
チ(latch: library cache)の取得です。
このとき、ラッチは取得しますが別にこれが待ちイベントになるわけではあり
ません。別に誰も待っていませんから。この状態が (*1) です。
そこで、待ちわびる人を増やした状態が (*2) というわけです。
ラッチを取得できなかった人たちは、ラッチほしさに順番待ちをするというわ
けですね。そうすると待ちイベントの回数や、時間が加算されていきます。
ちょっと補足しておきます。
SQL の実行計画など解析情報を変えてほしくないからラッチを取得するといい
ました。では、解析情報を変えない人同士ならお互い同時に利用しあってもい
いはずです。
というわけで、このような処理（SELECT 処理など）で取得するラッチは共有モ
ードのラッチです。共有モードで取得するラッチはお互い同時に取得可能なの
で実はここで待ちは発生しないのです。
え”っ、でも待ちが発生してるじゃないか。って？
そのからくりは次週のお楽しみ。
V$SYSTEM_EVENT から情報を取得するスクリプト
# 実行前に "set serveroutput on" を忘れずに。
# テーブル作成は初回のみ実施してください。
～～～～～～～～～～～～～～～～～～～～～～～～～～～～～～
create table sys_event ( event
, wait_class
, total_waits_1st
, total_waits_2nd
, time_waited_1st
, time_waited_2nd
, time_waited_micro_1st
, time_waited_micro_2nd )
as select event
, wait_class
, total_waits
, total_waits
, time_waited
, time_waited
, time_waited_micro
, time_waited_micro
from v$system_event
where 1=0;
declare
v_event varchar2(100) := null;
v_wait_class varchar2(64) := null;
v_total_waits number(38,0) := 0;
v_time_waited number(38,0) := 0;
v_time_waited_micro number(38,0) := 0;
cursor cur is
select event
, wait_class
, total_waits_2nd - total_waits_1st v_total_waits
, time_waited_2nd - time_waited_1st v_time_waited
, time_waited_micro_2nd - time_waited_micro_1st v_time_waited_micro
from sys_event
where time_waited_micro_2nd - time_waited_micro_1st > 0
and wait_class not in ('Idle','Network')
order by time_waited_micro_2nd - time_waited_micro_1st desc ;
begin
insert into sys_event (
event
, wait_class
, total_waits_1st
, time_waited_1st
, time_waited_micro_1st )
select event
, wait_class
, total_waits
, time_waited
, time_waited_micro
from v$system_event;
dbms_lock.sleep(30);
update sys_event a
set ( event
, wait_class
, total_waits_2nd
, time_waited_2nd
, time_waited_micro_2nd )
= (select event
, wait_class
, total_waits
, time_waited
, time_waited_micro
from v$system_event b
where a.event = b.event );
for rec in cur loop
dbms_output.put_line(
'event=[' || rec.event ||
'] wait_class=[' || rec.wait_class ||
'] total_waits=[' || rec.v_total_waits ||
'] time_waited =[' || rec.v_time_waited ||
'] time_waited_micro=[' || rec.v_time_waited_micro ||
']');
end loop;
rollback;
end;
/
～～～～～～～～～～～～～～～～～～～～～～～～～～～～～～
みなさま、本年もよろしくお願いいたします。
三日月が不気味に赤い 茅ヶ崎にて