はじめに

「おめでとう」

「おめでとう」

「おめでとう」

「めでたいなぁ」

「占い師CO。4人目、黒です」

「?!」

本記事は「STATSPACK解説 第弐話」の続きです。
今回は第3話です。
====================================

第1話

  • STATSPACKとは?
  • STATSPACKの概要
  • STATSPACKによる情報取得
  • STATSPACKのインストール方法

第弐話

  • STATSPACKの取得レベル変更
  • STATSPACKレポートからアイドルの待機イベントの除外
  • STATSPACKの手動でのスナップショット取得方法
  • STATSPACKのスナップショット自動取得ジョブ作成
  • STATSPACKレポートの取得方法

第3話

====================================

「なぜ某最終回から突然人狼ゲームに?」

「真実は人の数だけ存在するって言ってた」

「つまり、あなたにとってあの最終回は人狼ゲーム中ということ?」

「そう」

「そう・・・おめでとう」

今回もとてもユニークな課長の連載、第3弾です!
とても人気なので是非楽しんで下さいね。中身は役立つ情報ばかりです。

STATSPACKレポートを見る

スナップショットも定期的に取るようにした!
レポートの取得方法も分かりいつでもレポートが見れるようになった!

であれば、折角なので多少レポートの中身も見れるようになりたいですよね。

STATSPACKレポートの内容は膨大であり、その全ての項目を解説することは出来ませんが、調査・分析をするにあたって抑えておくべき重要なポイントがいくつかありますので
今回はそういったいくつかの項目の説明と見方、また調査・分析手法について解説していきます。
少々難しい単語が多くなり苦しいかもしれませんが、頑張ってください!

また、調査・分析の際の大事な点として、正常時のレポートと問題発生時のレポートを比較するという点があります。例えば問題が5/14 12:00~13:00の間に発生していた場合、
その前日の5/13 12:00~13:00のレポートと比較したり、その1週間前の5/7 12:00~13:00と
比較したり、問題が発生していない時間帯で且つ問題発生時とトランザクションの傾向が近しい時間帯を選定して比較対象とするのが理想です

比較無しの単独のレポートだけでもある程度の調査・分析が出来ることもありますが、正常時と比較して何が問題なのかを明らかにする方がより調査・分析の速度や精度は上がるでしょう。

では改めて抑えておくべき重要な項目について解説していきます。

トップ5 イベント(Top 5 Timed Events)

STATSPACKレポートといえばまずこれを見る!といっても過言ではありません。
こちらの項目にはDB内で多くの発生時間を占めていた上位5つのイベントが出力されます。

レポートには以下のように出力されます。

Top 5 Timed Events                                                    Avg  %Total
~~~~~~~~~~~~~~~~~~                                                   wait   Call
Event                                           Waits     Time (s)   (ms)   Time
----------------------------------------- ------------ ----------- ------ ------
CPU time                                                      1000          88.8
db file sequential read                           1000         100    100    8.8
buffer busy waits                                 5000          25      5    2.2
control file sequential read                       278           0      0     .4
PGA memory operation                                99           0      0     .2

項目の見方を記載します。
Event・・・イベント、及び待機イベント名
Waits・・・イベントの発生回数
Time(s)・・・発生合計時間(s)
Avg wait(ms)・・・イベント1回あたりの平均待機時間(ms)
%Total Call Time・・・該当イベントの時間÷(DBで発生した処理時間+待機時間)

簡単な書き方になりますが、DBのイベントというのは例えば以下のようなものがあります。

①CPUを使ってました・・・イベント名:CPU time

②ディスクのI/O待ちで待ってました・・・イベント名:db file sequential read

③他のセッションがブロックをキャッシュに読み込もうとしてたので
読み込みが終わるのを待ってました・・・イベント名:buffer busy waits

DB内では常に何かしらの処理であったり「待機」という待ち時間が発生しており
それらが様々な名称で記録されたものが「イベントといいます。

そしてそのイベントの中でも
DB内で待ち時間が発生していることを示すイベントを
待機イベントといいます。

本項目に多くの発生時間を占める待機イベントが出力されているのであればそれが何かしらの性能のネックになっている可能性が高いという事です。

折角なので上記の①~③で記載しているよく見かけるイベントについて解説します。

CPU time

こちらのイベントは「DBでCPUを使っている=処理を実行している」という状況を示しており、待機を示すイベントではありません。
上記のレポート出力で CPU Time については wait に関する出力がありませんが、それはこのイベントが待機イベントではないからです。

上記より、こちらのイベントがトップであり、多くの時間を占めている状況であれば基本的には健全な状態と言えます

ただし、こちらの項目がトップでもそれに負けじと別の待機イベントも多くの時間を占めている場合は詳細な分析を行うのが良いでしょう。

db file sequential read

SQLからのシングルブロックリードによるデータ要求に対してディスクへのアクセスが行われ、ディスクI/O待ちが発生していることを示しています。
バッファキャッシュ上に対象データが存在しないので、ディスクアクセスが発生している状況です。

こちらのイベントが多く発生して問題となっている場合、SGA(Buffer Cache)のサイズを拡張して
より多くのデータをキャッシュ出来るようにしたり、必要以上に多くのデータ読み込みをしてしまっている非効率なSQLを特定しチューニングを実施したりすることで改善が見込める可能性があります。

ただこちらのイベント、完全に防ぐことは基本的に難しいですので多少発生していても問題視しなくて良いケースが多いです。他の待機イベントについても言える事ですが、
重要なのは待機イベントが発生している時間帯にシステムとしての性能問題が発生していたかどうかという点になります。

ここで鍵となるのが、正常時のレポートと問題発生時のレポートの比較です。
もしこういった待機イベントが
正常時にも問題発生時にもある程度出力されている状況であれば、それは原因ではない可能性が高い
素早く判断が出来ますが、問題発生時のレポートだけを確認して「待機イベントが多く発生しているから改善しないと!」という判断をしてしまうとそれはミスリードになる可能性が高く、問題の解決まで長引いてしまうかもしれません。

buffer busy waits

ざっくり言ってしまうとブロック競合です。自分が使いたいブロックを他のセッションが使っている場合によく発生します。
ケースとして多いのは、多数のプロセスが特定のテーブルに対して集中的にアクセスを繰り返している場合ですね。

こちらの待機イベントも完全に防ぐことは難しい場合がありますし、問題視しなくて良いケースも多いですが、問題になっているようであれば、必要以上に多くのデータ読み込みをしてしまっている非効率なSQLをチューニングしたり、
バッチ処理とOLTP系の処理で競合しているようであればバッチ処理用のテーブルとOLTP用のテーブルでテーブルを分けてアクセス競合を防ぐといった方法があるかと思います。

ただ後者のテーブル分割は稼働中のシステムに対して実施するのは敷居が高く現実的ではありませんので、考え方の一つとして頭の片隅に置いておいてもらえればと思います。

このように、どういったイベントが上位を占めているかを確認し、そのイベントに対してアプローチをしていくのが性能問題改善への近道となります!

インスタンス効率(Instance Efficiency Indicators)

インスタンスにおける稼働効率がパーセンテージで表示されています。
基本的には100%に近ければ近いほど健全な状態です。システムの特性上どうしても低くなってしまう場合もありますが、トップ5イベントの項目でお伝えしている通り性能問題となっていなければ問題ありません。
また、繰り返しとなりますが正常時と問題発生時の値を比較して分析していきましょう。

該当項目は以下のようにレポートに出力されます。
いくつか項目がありますが、代表的なものは以下の赤字部分です。

Instance Efficiency Indicators
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
            Buffer Nowait %: 100.00        Redo NoWait %: 100.00
              Buffer Hit  %: 100.00   Optimal W/A Exec %: 100.00
             Library Hit  %: 99.97          Soft Parse %: 100.00
         Execute to Parse %: 50.58           Latch Hit %: 99.69
Parse CPU to Parse Elapsd %: 50.00       % Non-Parse CPU: 98.85

この赤字の2項目について解説します。

Buffer Hit

全体のデータアクセスの内、バッファキャッシュ(メモリ)上に必要なデータが見つかり
ディスクI/Oが発生しなかった割合
を示す項目です。

こちらの割合が高いほどディスクアクセスの発生を抑えられていたということになり健全な状態であると言えます。

ディスクI/O待ちに関する待機イベントが多く発生している場合、合わせてこちらの値も確認すると良いでしょう。

Library Hit

ライブラリキャッシュに必要なSQL情報が存在していた割合を示す項目です。

こちらの割合が高いほどSQL情報の再利用が出来ており、ハードパースの発生をある程度抑えられており健全な状態である
と言えます。

ハードパースはそもそもの所要時間が長くなるケースも多く、多発するとCPU負荷に影響を及ぼす場合もありますので可能な限り発生を抑止するのが理想です。

こちらの割合が低く、改善をしたいという場合はSQLのリテラル部分をバインド変数に置き換えたりしてSQLを共有可能な状態にチューニングするのがよいでしょう。
尚、共有プールのサイズを拡張しても効果がある場合がありますが、多くのケースではあまり効果が無い場合が多いですのでその点は注意しましょう。

長時間SQL(SQL ordered by Elapsed time)

文字通り、実行時間の長いSQLが表示されている項目です。
実行時間の長いSQLが絶対悪、という訳ではありません問題解決の何かしらのきっかけになるケースは多いです。
問題発生時にはこちらもチェックするのが良いでしょう。

レポートには以下のように出力されます。

SQL ordered by Elapsed time for DB: TEST Instance: test Snaps: 60 -61
-> Total DB Time (s): 6
-> Captured SQL accounts for 135.4% of Total DB Time
-> SQL reported below exceeded 1.0% of Total DB Time

  Elapsed                Elap per           CPU                          Old
  Time (s)   Executions  Exec (s)  %Total  Time (s)  Physical Reads   Hash Value
---------- ------------ ---------- ------ ---------- ---------------  ----------
      4.63            1       4.63   81.0       4.46              12  1373008994
Module: sqlplus@otamesi (TNS V1-V3)
delete from boku_table

項目の見方を記載します。

Elapsed Time(s)・・・合計実行時間(s)
Executions・・・合計実行回数
Elap per Exec(s)・・・1実行当たりの実行時間
%Total・・・DB全体のSQL実行時間における本SQLの実行時間の割合
CPU Time (s)・・・SQLでCPUを使用していた時間
Physical Reads・・・ディスクへの合計アクセス回数
Old Hash Value・・・SQLのHash Value値

分析の手法としては他の項目でも記載したように、正常時と問題発生時のレポートを見比べたり待機イベントを長時間SQLが引き起こしているのか、別原因で待機イベントが発生しSQLが長時間化しているのか判断しアプローチを進めていくのが良いかと思います。

長時間SQL以外にも以下のような観点でレポートにSQL情報が出力されています。
必要に応じて他の情報も確認するのがオススメです!

  • CPUの使用時間が多いSQL(SQL ordered by CPU)
  • 読み込みブロック数が多いSQL(SQL ordered by Gets)
  • ディスクからの読み込みブロック数が多いSQL(SQL ordered by Reads)
  • 実行回数の多いSQL(SQL ordered by Executions)

あとがき

ここまで読んで頂いてありがとうございました。(もちろん全3話すべて読んでくれていますよね?)
これにてSTATSPACK解説は終了となりますが、いかがでしたでしょうか。
特に3話からは知らない単語もあり頭を悩ませる苦しい内容もあったかと思います。

それを想像すると、とても幸せです。(人の苦しみを糧にする悪魔かな?)

いきなりこれをすべて実践するというのも難しいとは思いますが、少しずつ自身のものにして頂き、素敵なSTATSPACKライフをお過ごしください。

当社ではSTATSPACKを用いた性能分析サービスも行っております。
お気軽にお問合せ下さいね!

投稿者プロフィール

技術チーム
技術チーム
DBひとりでできるもんを盛り上げるべく、技術チームが立ち上がり早6年。ひとりでできるもんと言いつつ、技術者が読んでプッとなるような、極めてピンポイントでマニアックな技術ネタを執筆しています!