日本オラクル株式会社 コンサルティング統括本部テクノロジーコ
ンサルティング本部
小田 圭二(おだ けいじ)
皆さんがご存知のとおり、現実のシステムは刻々とその状態を変えます。そのような現実のシステムの運用において本当に大事なのは、遅延している瞬間の状態を確認することです。例えば、30分間ずっと同じ状態(均一)のままというトラブルであれば、瞬間を確認する必要はないでしょう。しかし、現実のトラブルは「あるタイミングで」「たまに」「ある処理が」といった具合に不均一なケースが多いはずです。つまり、トラブルが起こったその瞬間の情報を押さえる必要があるのです。
私たちOracleコンサルタントは、多くの場合、瞬間の情報をV$SESSIONビュー 注1 やV$SESSION_WAITビュー 注2から確認します。これらビューの概要は表1、表2を参照してください。
表1 V$SESSIONの定義(抜粋)
表2 V$SESSION_WAITの定義(抜粋)
注1:セッションに関する情報が載っている動的パフォーマンスビュー。
注2:セッションごとの現在の待機イベントが載っている動的パフォーマンスビュー。
しかし、Oracleは遅延しているタイミングで自動的に情報をとってくれませんので、管理者が適切な間隔でこれらのビューを繰り返し検索し、ログに残しておく必要があります。そのためのスクリプトは、LIST1、LIST2のようになります(環境や目的に合わせて適宜変更してください)。
LIST1 V$SESSIONを定期的に実行するスクリプト
LIST2 V$SESSION_WAITを定期的に実行するスクリプト
なお、V$SESSION_WAITやV$SESSIONはメモリ中の情報にアクセスするものであり、アイドルの情報さえ表示させなければ、参照しても負荷はほとんどありません(詳しくは後述)。V$SESSION_WAITとV$SESSIONを結合して一緒に情報を採ることも可能です。
注意すべき点は、あくまで瞬間の情報を定期的に採っているため、瞬間と瞬間の間については分からないことです。連続する情報を取得するためには、後述するSTATSPACKかSQLトレースを使います。
ログの取得方法にはいくつかコツがあります。それらを簡単に紹介します。
なお、筆者はdbms_job(Oracleのジョブスケジューリング機能)によるログの取得は使いません。理由は、使用することにより余計にプロセスが立ち上がってしまうことと、パフォーマンス情報が見にくくなってしまうことです。
次に、瞬間の情報がどう役立つのかを説明します。DBエンジニアの悩みの1つに、パフォーマンストラブルの発生場所がDBなのかDB以外なのか、その切り分けが難しいことがあると思います。システムのパフォーマンスが悪く、まず「DBが遅いのではないか」と言われた経験もあるのではないでしょうか。
しかし、実際にはDBより手前で詰まっていることも多いものです。そうした切り分けを行なう際にも瞬間の情報が使えます。
V$SESSIONビューには「STATUS」という列があり、その列は主に「ACTIVE」と「INACTIVE」という2つの値をとります。「ACTIVE」は“SQL文を実行中”という意味で、SQL文は受け取っていますが、まだ処理結果を返していない状態です。逆に言うと「INACTIVE」などのアイドル状態では、「DBにはSQL文が届いていない」と言えます(図1)。
図1 セッションの「状態」
例えば、図2の状況において、エンドユーザーから見た時刻0:00:05から0:00:10までの間にシステムが遅延しているとします。しかし、V$SESSIONビューのデータからはDBはSQL文を受け取っていないわけですから、DBが遅延している可能性は低いと言えます 注3。
図2 セッションの「状態」とV$SESSIONの関係
注3:1つの処理が複数のSQL文で構成されていることも多いため、断定まではできません。しかし、情報をある程度繰り返し取得しても同じであれば、断言して構わないと思います。
LIST1のスクリプトを実行した結果の例(LIST3)を見てください。SQL文が実行されていれば「ACTIVE」と表示されます。LIST3のように、定期的に検索してもずっと表示されているセッションとSQL文は、DBでの処理に時間がかかっている可能性が高いと言えます。
なお、分析の際にはV$SESSIONビューを検索しているセッション自身も表示されることに気を付けてください。
LIST3 LIST1のスクリプトの実行結果
処理に時間がかかっているSQL文があることが分かれば、それがどれか知りたくなると思います。それには、LIST4のスクリプトを用います。
LIST4 ハッシュ値とアドレスからSQL文を表示するスクリプト
さらに、そのSQL文がどのくらいリソースやI/Oや時間を使用したのかは、LIST5のスクリプトで分かります。
ただし、Oracleの内部構造の関係で、長い時間実行されなかったSQL文の情報は消えてしまいます。そのため、気付いたときには早めに情報をとってください 注4。
LIST5 ハッシュ値とアドレスから該当SQL文の実行時間、CPU時間、読み込みブロック数を表示するスクリプト
注意:V$SQLやV$SQLAREAは頻繁に検索してはいけません。理由は処理が重いからです。V$SESSIONなどと結合させて頻繁に検索をしているケースがありますが、負荷をかけ過ぎて、ミイラ取りがミイラになってしまうことがあります。
注4:OracleはSQL文をshared poolと呼ばれるメモリにキャッシュします。このキャッシュは一定のサイズのため、SQL文が長く使われずにいたり、頻繁にいろいろなSQL文が実行されるとSQL文がキャッシュ落ちしてしまいます。キャッシュ落ちしたSQL文の情報はV$SQLやV$SQLAREAに表示されません。
ここまでの説明で、SQL文がDBに届いていないのか、届いていて処理に長く時間がかかっているかをおおまかに確認する方法まで分かりました。DBにSQL文が届いていることが分かれば、次は遅延している瞬間のDBの状態を知りたくなります。そのときに有効なのが、V$SESSION_WAITビューです。
LIST6は、V$SESSION_WAITビューを参照するLIST2のスクリプトを実行した結果の例です。enqueue待ちになっていて、長く待たされていることが分かります。また、「SECONDS_IN_WAIT」列でおおよその待ち時間が分かります 注5。
LIST6 LIST2のスクリプトの実行結果
注5:SECONDS_IN_WAIT列の単位は秒です。ただし、トランザクションが少ないシステムでは、まれに情報の反映が最大3秒遅れることがあります。また、9.2.0.3までのOracle9i R2では待機イベントが終了していないのに、数秒経つとSECONDS_IN_WAIT列の値が0に戻るという動作をするため、同じ待機イベントで待っているか(引数も同じか)で判定してください。
分析方法ですが、同じ待機イベントで長時間待っている、もしくはずっと同じ待機イベントが繰り返し出ているセッションがあれば、それに着目します。V$SESSION_WAITビューの意味を図示すると、図3および図4のようになります。
図3 待機イベントとセッションの関係
図4 待機イベントとV$SESSION_WAITビューの関係
例えば、「6:59:30から6:59:40まで遅延した」とエンドユーザーから言われた場合、V$SESSION_WAITビューの情報から、サーバープロセス1の「enqueue」が原因の可能性があると言えます。待機イベントにはいろいろありますが、それらの意味はOracleのリファレンスマニュアルで確認できます。そこで待機イベントの引数を見ると、イベントの詳細情報がある程度分かります。
注意事項として、STATE列が「WAITING」である行だけが現在の待機イベントを表わしていることに気を付けてください。WAITING以外の行は過去の待機イベントなので、無視します。見方を変えると、STATE列がWAITING以外の場合、Oracleとしてはサーバープロセスが処理中だと言えます。イベント名が表示されているから待たされていると考えずに、必ずSTATE列を確認するようにしてください。 LIST2のスクリプトでは、WHERE句に「STATE='WAITING'」を指定して、実際に待機しているイベントだけを表示させています。
なお、セッション数が多いとV$SESSION_WAITビューの参照も負荷(特に端末への表示やファイルへの書き出し)が高くなるので、WHERE句を使って表示する情報を適宜絞ってください。通常、「SQL*Netmessage」で始まる行さえ外せば問題ないはずです 注6。事実、マルチCPU環境ではありますが、筆者が1000セッション以上で1秒ごとに参照したときでも、大きな負荷はかかりませんでした(負荷は1%未満)。
この点は、V$SESSIONも同様です。
注6:LIST2のスクリプトでは「SQL*Net message」に加え、バックグラウンドプロセスのアイドルイベントも表示対象から外しています。
ミイラ取りがミイラになってはいけません。そのため、本特集ではできる限り注意事項や指標となる負荷情報を書きました。
Oracleの全バージョンで確認したわけではありませんが、V$SQLやV$SQLAREAは適切にWHERE句を指定していても、入っている行数(SQL文の数)に比例して重くなることがあります。そのため、SQL文が少ない(数百SQL文程度の)システムか、業務が流れていない時間帯もしくは事前にパフォーマンスを確かめた上で、これらのビューにアクセスすることをお勧めします。
これらのビューにアクセスするSQL文を定期的に実行するように促している書籍や記事もありますが、利用のしかたには十分注意してください。
待ち行列の確認も、このV$SESSION_WAITビューからできます。Oracleがリクエストを受け付けて以降のどこかの処理で詰まっているのであれば、図5のように待ち行列になっているセッションが、待機状態としてV$SESSION_WAITビューに表示されます。
図5 待ち行列の確認方法
また、Oracle内のボトルネックだけではなく、Oracleより先に原因がある待ち行列についても、一部読みとれることに注目してください。例えば、ディスクがボトルネックになっているとします。そこでV$SESSION_WAITビューを参照すると、ディスクからの読み込み待ちを意味する「db file sequential read」が表示されますが、これも待ち行列に入っているサーバープロセスの分だけ表示されます 注7。ただし、「CPUリソース不足」の待ち行列とCPUリソース不足時を除きます 注8。
以上のように、遅延している瞬間の情報を見ることによって、そもそもDBサーバーで問題が起きているのかどうかが分かりますし、問題が起きているときのOracleの各サーバープロセスの状態を知ったり、Oracleがリクエストを受け付けて以降の処理で発生している待ち行列を把握したりできます。前述の「合計と平均のマジック」や「瞬間的な待ち行列のマジック」は、この瞬間の情報を採る方法で見破ることができます。
注7:実際には、ディスクで待ち行列になっていても同期しているため、Oracle上から判別できるということです。
注8:詳しくは後述しますが、CPUリソース不足時には、Oracleの待機イベントの数値が大きくなるという現象が起きます。またOracleは、CPUリソース不足を直接確認するための情報は持っていません。/p>
enqueue待ち以外の待機イベントも紹介しましょう。LIST7では「db filesequential read」が表示されています。このようにディスクからの読み込み遅延も数秒以上のものであれば分かります。
LIST7 enqueue待ち以外の待機イベント
Oracleには、以前からDB全体(正確にはインスタンス)のパフォーマンスを見るためのツール「Bstat/Estat」が付属していました。バージョン8.1.6からは、Bstat/Estatの後継であるSTATSPACKが使えるようになりました。
さて、これらはDB全体のパフォーマンス情報を見ることができるのですが、“全体”とは、いったい何を指しているのでしょうか? 答えは、図6が示すように、ある期間のセッションすべての合計やディスクのアクティビティ、キャッシュヒット率などの情報です。
図6 STATSPACKが教えてくれる情報
LIST8は、図6に対応する形でSTATSPACKで作成したレポート(抜粋)です。STATSPACKでレポートを作成する際には、いくつかの注意事項を頭に入れておく必要があります。
LIST8 STATSPACKレポートの抜粋
まず、レポートに示される数値は“合計”だということです。V$SESSION_WAITビューのように、遅延している瞬間の状況を見ることはできません。
また、短い間隔でレポートをとるのは避けなければなりません。STATSPACKはスナップショットと呼ばれる、あるタイミングごとの統計情報を保存します。そのタイミングはユーザーが指定する(もしくはコマンドを実行する)のですが、その統計情報を保存するのに、ある程度の時間とCPUコストがかかります。特に、レベル5 注9以上ではSQL文の情報をメモリから検索するので、SQL文が多いシステムでは時間がかかります。そのため、スナップショットは1分以上間隔を空けてとるべきです。
なお、間隔を短くしたい場合には、事前にスナップショットの取得にかかる負荷を測っておきます。つまり、何も実行していない状態でスナップショットをとり、レポートを見てみるのです。これにより、スナップショット取得時のCPU使用量が分かるので、本番のレポートでは、このCPU使用量を考慮した(減らした)上で分析ができます。
ここまで聞くと、STATSPACKは不便なように思えますが、そんなことはありません。不便を補って余りある便利な機能を持っています。まず、STATSPACKはレベル5以上であれば、自動的に目立つSQL文の情報を表示します。全SQL文はもちろん表示できませんが、問題ありそうなSQL文をいくつかの観点でチェックして、上位を表示してくれるのです。
しかも、Oracle9iからは「Elapsed time 注10」を表示できるようになったため、timed_statisticsパラメータ 注11をtrueにする、もしくはstatistics_levelパラメータ 注12をデフォルトの「typical」以上にしておけば、そのSQL文の実行にかかった時間とCPU時間が分かります。多くの場合で問題をSQL文レベルで特定できるため、これはとても便利です。
注9:このレベルは、情報の細かさを表わす。スナップショットの際に指定できます。
注10:SQL文経過(処理)時間。
注11:時間情報を取得するかを決定するパラメータ。
注12:Oracle9i R2から導入されたパラメータで、取得情報の細かさを決定します。
ときどき、「負荷がかかるからパフォーマンス情報をとらないポリシーです」とか、パフォーマンス情報をとっている方でも 「timed_statisticsはfalse (時間情報はとらない)です」とか、「ダウンが怖いので、ピーク時はパフォーマンス情報をとりたくない」と言う方がいます。
これは大変危険で、自動車の運転に例えるなら、少し速くなるからと車のフロントガラスを外し、代わりに頭を伏せて前を見ずにアクセル全開で走っているようなものです。パフォーマンスは多少良いかもしれませんが、トラブルに気が付いたときには手遅れで、大事故を起こしてしまうかもしれません。障害時に原因が分からないこともあるでしょう。
企業システムを預かるエンジニアであれば、多少遅くなってもできるだけ情報を集め、避けられる事故は避け、事故が起きても二度と起こさない努力をする姿勢が大切だと思います。
では、プロのSTATSPACKのデータの見方を紹介しましょう。まず、TOP5 注13を見ます。LIST8の3つ目の白抜きの箇所です。ここで、「CPU time」以外のイベント(もちろんアイドルではないもの)の合計時間を足しておきます 注14。
次に、「cpu used by this session」を見てCPU時間を調べます。TOP5に「CPU time」が表示されていれば、同じものなのでそれを使います。最後に、TOP5で合計したアイドルではない待機イベントの時間とCPU時間とを足します。これが、DBがシステム遅延の原因かどうかを判定するための資料になります。
前述したとおり、「CPU時間+アイドルではない待機イベント」が、ほぼDBでの処理時間です。この「CPU時間+アイドルではない待機イベント」がアプリケーションの遅延時間より明らかに小さければ、V$SESSIONやV$SESSION_WAITの情報がなくても「DBは白だ(DBで遅延が起きていない)」と言えます。逆に、アプリケーションの遅延時間(この場合クライアントのレスポンスタイム)とほぼ同じであり、ほかのサーバープロセスで処理を行なっていないのであれば、「DBは黒だ(DBで遅延が起きている)と言えます。それ以外のケースは灰色です。特に複数のサーバープロセスが処理を行なっていた場合、判定は難しくなります(図7)。
図7 複数のサーバープロセスで処理を行なっていた場合は判定が難しい
注13:このTOP5は、バージョンによって呼び方が異なります。Oracle9i R2では「Top 5 Timed Events」、Oracle8iとOracle9i R1では「Top 5 Wait Events」です。
注14:TOP5にはアイドルイベントは表示されません。
では、判定が灰色のときはどうしたら良いのでしょうか。Oracle9i以降で、遅延しているアプリケーションとSQL文を特定できているのであれば、そのSQL文情報の「Elapsed time」を見ます。このElapsed timeはSQL文ごとの「アイドルではない待機イベント+CPU処理時間」ですから、これがそのアプリケーションのレスポンスタイムとほぼ同じであれば、DBで時間がかかっていると言えます。
SQL文を特定できていなくても、SQL文情報は見る価値はあります。また、遅延していなかったときのデータ(過去のデータ)と比較するという手もあります(LIST9参照)。
LIST9 STATSPACKの差分から原因を探る方法
しかし、過去のデータと違いがあったからといって、本当にそこから原因が分かるとは限りません。知らないところで、アプリ ケーションの何かが変わっているのかもしれませんし、アプリケーション開発者の「まったく変更はない」という発言が間違っているかもしれません。トラブルシューティングの現場では、性善説は通用しません。そのため、「手がかり」もしくは「第一容疑者」程度に扱うのが妥当だと考えます。可能であれば、ほかのアプリケーションが動いていない状態でSTATSPACKでレポ ートをとるか、V$SESSIONビューやV$SESSION_WAITビューを見て遅延の証拠を押さえてください。
原因が分かったら、次はチューニングです。チューニングは本特集では説明範囲外ですが、この分析で得られた情報が役に立つので、簡単に紹介します。
まず、DBのチューニングでは、SQL文の処理時間である「CPU時間+アイドルではない待機イベント」を減らすという発想をします。CPU時間が占める割合が大きい場合は、実行計画を変えて処理を軽くしない限り、小手先のチューニングでは対処できないでしょう。設計レベルの問題かもしれません。
次に、待機イベントが大きい場合には、その待機イベントが起きる仕組みを調べた上で、待機イベントを減らす方法を考えてみてください。こちらのほうが小手先のチューニングが効く可能性はありますが、最悪のケースでは、やはり設計レベルの問題という結論もあり得ます。
チューニングの話はこれくらいにして、このような特徴を持つSTATSPACKレポートは、どのようなケースで使えるのでしょうか。ここまでに半分答えを書いてきてしまいましたが、「定常監視と、ほかの業務処理が入ってこない環境下でのSQL文の調査/分析」です。複数の処理が実行されている環境下においても、パフォーマンス調査に使えることはありますが、V$SESSIONビューやV$SESSION_WAITビューも必要となるかもしれません。
SQLトレースにより、SQL文の実行計画、SQL文ごとに処理にかかった時間、処理にかかったCPU時間が分かります 注15。このSQLトレースの結果は、Oracleの動作モデル図では何に相当するのでしょうか。図8のように、セッション上で実行されたSQL文の処理にかかった時間(CPU時間+アイドルではない待機イベント)と、CPU時間が分かります。さらに、図にはないSQL文の実行計画(どのようにデータにアクセスして、どのようにデータを処理したのか)も分かります。
なお、「どの待機イベントにどれくらいかかったか」は分かりません。
図8 SQLトレースが教えてくれる情報
注15:SQLトレースにおいては、その記述が一字一句同じ場合に同一SQL文とみなされます。したがって、バインド変数の値が違う場合でも同一SQL文とカウントされ、情報はサマリーされます。
LIST10を見てください。SQLトレースの結果(抜粋)です。
LIST10 SQLトレースの結果(抜粋)
SQLトレースは、DB全体(正確にはインスタンス)のSQL文について調査することもできますが、負荷が大きい(処理が遅くなる)ため、本番サーバーではできる限り使用を避けるべきです。また、DB全体のSQL文を調査対象としてしまうと、結果を見るのが面倒で非効率でもあります。セッション単位でも設定可能なものの、これも処理が遅くなるので、できる限り使わないようにすべきです。
>では、どのようなケースにSQLトレースは適しているのでしょうか。制限事項を考えると、SQL文が問題であることが分かり、SQL文を特定した後に、開発環境(もしくは商用環境の1セッション)で取得するのが効果的です。少なくとも、問題のあるSQL文かセッションが判明するまでは、SQLトレースの使用はお勧めできません。
また、SQLトレースの代替手段もあります。実行計画を見るだけであれば、Oracle9iから加わったV$SQL_PLANビューが使えます。Oracle9iからV$SQLAREAビューでもCPU時間や実行にかかった時間は分かるようになりました 注16。
注16:V$SQLAREAはWHERE句でアクセスする行を絞っても、入っている行数に比例して検索に時間がかかるケースがあります。
「Oracle Netのトレース(SQL*Netのトレースとも呼ばれます)」を一言で言うと、Oracle版パケットキャプチャツールです。このツールは一般にネットワークの障害の際に使用するものと思われていますが、パフォーマンス情報の取得にも使える場合があります。
Oracle Netのトレースでは、図9に示すように、SQL文が到着したタイミングおよびSQL文の結果を返すタイミング(正確にはOracleレベルでのパケット送受信のタイミング)で、Oracleのクライアントとサーバー間でやり取りされたパケットが記録されます。さらに、記録には時間とSQL文(パケットダンプですが)を含めることができますし、DBサーバー側だけでなく、Oracleクライアント側でも記録できます。
図9 Oracle Netのトレースが表示する情報
LIST11は、Oracle Netのトレースの結果(抜粋)です。Oracle Netのトレースの注意点は処理が遅くなることと、取得できるのはあくまでOracleレベルのパケットダンプであることです。TCPヘッダーなどは見ることができません。
LIST11 SQLトレースの結果(抜粋)
処理が遅くなることに関しては、筆者の経験では、最低のレベルであっても30%程度レスポンスが遅くなったことがあります。そのため、障害時には仕方がないものの、本番サーバーのパフォーマンス情報をとる目的で使用するべきではありません。
そのため、パフォーマンス分析におけるOracle Netのトレースの使い方は、テスト環境において、実際にOracleにSQL文が届いたタイミングと結果を返したタイミングの確認や、データ量が多く(=パケット数が多い)時間がかかっていることの確認程度に限られるでしょう。
以上、パート2では、Oracleのパフォーマンスを測定するための各種ツールを紹介しました。それぞれ一長一短ありますので、目的に適したツールを選んで使えるようにしましょう。チューニングも状況の把握から始まります。そのための道具をよく知り、またそれを使いこなせる腕を磨くことが大切です。
Copyright © 2008, Oracle Corporation Japan. All rights reserved.
無断転載を禁ず
この文書はあくまでも参考資料であり、掲載されている情報は予告なしに変更されることがあります。日本オラクル社は本書の内容に関していかなる保証もいたしません。また、本書の内容に関連したいかなる損害についても責任を負いかねます。
Oracleは米国Oracle Corporationの登録商標です。文中に参照されている各製品名及びサービス名は米国Oracle Corporationの商標または登録商標です。その他の製品名及びサービス名はそれぞれの所有者の商標または登録商標の可能性があります。
小田 圭二(おだ けいじ)
1996年日本オラクル入社。人事教育本部にて、新卒や中途採用社員に対し、データベースやOS、ネットワークの講師を5年ほど経験した後、2000年にテクノロジーコンサルティング本部に異動。 テクノロジーのコンサルタントとして、主に大規模ミッションクリティカルシステムを担当。
ポリシーは、「OracleもOS上で動くアプリケーションにすぎない。だから、OS、ストレージ、ネットワークを学ぶべき」。 スキル面の興味は、アーキテクチャ、DBA、インフラ技術、教育、コンサル手法など。