Snapper v3.61 released ? and more work is in progress! – 日本語訳


http://blog.tanelpoder.com/2012/12/18/snapper-v3-61-released-and-more-work-is-in-progress/
の翻訳です。基本的に意訳です。意味をとりやすくするために追加した箇所については、《…》で囲っています。

本文書に関する指摘については、原文著者のTanel Poderさんではなく、渡部まで御連絡お願いいたします。


日本語訳:渡部 亮太 (WR at Csus4 dot net)

履歴


  • 2012-12-19: 初稿up


Snapper v3.61がリリースされた?そして、さらに多くの機能を実装中です!

Oracleセッション・レベルのパフォーマンス・Snapperツールはここにあります:

私は数日中にSnapperに多くのものを追加しようとしてますが、既に:)をテストするための何かを解放するために考えている

  1. 読みやすくするために空行とヘッダ行を表示する(詳細はスクリプトのソースコードを直接見てほしいが、pagesizeパラメータによって制御できる)ような、いくつかの見栄えの調整を行った。
  2. Snapperレポートをちらっと見たときでも、より簡単に理解できるように、視覚的な "graph"列にいくつかの変更を加えました:

    @という文字は、CPU時間を示すために使われる。(@って、ちょっとCという文字に似てない? :)
    #という文字は、他のすべての時間モデル統計の時間を示すために使われる
    Wという文字は待機時間を示すために使われる

  3. Snapperは現在、 デフォルトでは"ASH" breakdown セクションにSQL子カーソル番号を表示します
  4. 主な新機能は、V$SESSION_EVENTからイベントカウント列の追加で、セッションレベルの待機イベントの持続時間の平均を計算するを可能にします。たとえば、次に長時間のlog file sync待機イベントを確認したときには、user committransaction rollbackなどの他のメトリックから導出することなく、すぐに待機の平均をチェックできます。以下の例では、私は 同時にSnapperで調査して、
    commit処理を実行する1つのユーザセッション(SID 298)、とLGWRのセッション(492)を特定しました。

wait time average列を見るために、以下のセクションを右にスクロールしてください。
(もし表示幅をより狭くしたい場合は、特定の列を非表示にするためにスクリプトのソースコードの "configurable stuff"セクションを確認してください)

SQL> @snapper all 5 1 298,492

Sampling SID 298,492 with interval 5 seconds, taking 1 snapshots...

-- Session Snapper v3.54 by Tanel Poder ( http://blog.tanelpoder.com )

---------------------------------------------------------------------------------------------------------------------------------------------------------------------------
    SID, USERNAME  , TYPE, STATISTIC                                                 ,         DELTA, HDELTA/SEC,    %TIME, GRAPH       , NUM_WAITS,  WAITS/SEC,   AVERAGES
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------
    298, SOE       , STAT, Requests to/from client                                   ,            36,        7.2,         ,             ,          ,           ,
    298, SOE       , STAT, opened cursors cumulative                                 ,           379,       75.8,         ,             ,          ,           ,
    298, SOE       , STAT, user commits                                              ,            54,       10.8,         ,             ,          ,           ,
    298, SOE       , STAT, user calls                                                ,            72,       14.4,         ,             ,          ,           ,
    298, SOE       , STAT, recursive calls                                           ,           433,       86.6,         ,             ,          ,           ,

... lots of output removed ...

    298, SOE       , STAT, execute count                                             ,           323,       64.6,         ,             ,          ,           ,
    298, SOE       , STAT, bytes sent via SQL*Net to client                          ,          2859,      571.8,         ,             ,          ,           ,
    298, SOE       , STAT, bytes received via SQL*Net from client                    ,          6972,      1.39k,         ,             ,          ,           ,
    298, SOE       , STAT, SQL*Net roundtrips to/from client                         ,            34,        6.8,         ,             ,          ,           ,
    298, SOE       , STAT, cell flash cache read hits                                ,            44,        8.8,         ,             ,          ,           ,
    298, SOE       , TIME, parse time elapsed                                        ,          1242,    248.4us,      .0%, [          ],          ,           ,
    298, SOE       , TIME, PL/SQL execution elapsed time                             ,         39365,     7.87ms,      .8%, [#         ],          ,           ,
    298, SOE       , TIME, DB CPU                                                    ,        137978,     27.6ms,     2.8%, [@         ],          ,           ,
    298, SOE       , TIME, sql execute elapsed time                                  ,        152021,     30.4ms,     3.0%, [#         ],          ,           ,
    298, SOE       , TIME, DB time                                                   ,        690485,    138.1ms,    13.8%, [##        ],          ,           ,
    298, SOE       , WAIT, latch: cache buffers chains                               ,            27,      5.4us,      .0%, [          ],         1,         .2,       27us
    298, SOE       , WAIT, log file sync                                             ,        530709,   106.14ms,    10.6%, [WW        ],        20,          4,    26.54ms
    298, SOE       , WAIT, SQL*Net message to client                                 ,            65,       13us,      .0%, [          ],        34,        6.8,     1.91us
    298, SOE       , WAIT, SQL*Net message from client                               ,        511002,    102.2ms,    10.2%, [W         ],        34,        6.8,    15.03ms
    298, SOE       , WAIT, PL/SQL lock timer                                         ,       3589765,   717.95ms,    71.8%, [WWWWWWWW  ],       227,       45.4,    15.81ms
    298, SOE       , WAIT, cell single block physical read                           ,         30350,     6.07ms,      .6%, [W         ],        47,        9.4,   645.74us
    298, SOE       , WAIT, events in waitclass Other                                 ,            50,       10us,      .0%, [          ],         1,         .2,       50us

---------------------------------------------------------------------------------------------------------------------------------------------------------------------------
    SID, USERNAME  , TYPE, STATISTIC                                                 ,         DELTA, HDELTA/SEC,    %TIME, GRAPH       , NUM_WAITS,  WAITS/SEC,   AVERAGES
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------
    492, (LGWR)    , STAT, non-idle wait time                                        ,           328,       65.6,         ,             ,          ,           ,
    492, (LGWR)    , STAT, non-idle wait count                                       ,           350,         70,         ,             ,          ,           ,
    492, (LGWR)    , STAT, in call idle wait time                                    ,           148,       29.6,         ,             ,          ,           ,
    492, (LGWR)    , STAT, messages received                                         ,           343,       68.6,         ,             ,          ,           ,
    492, (LGWR)    , STAT, background timeouts                                       ,             1,         .2,         ,             ,          ,           ,
    492, (LGWR)    , STAT, physical write total IO requests                          ,           384,       76.8,         ,             ,          ,           ,
    492, (LGWR)    , STAT, physical write total bytes                                ,       1330688,    266.14k,         ,             ,          ,           ,
    492, (LGWR)    , STAT, cell physical IO interconnect bytes                       ,       2661376,    532.28k,         ,             ,          ,           ,
    492, (LGWR)    , STAT, redo wastage                                              ,        105336,     21.07k,         ,             ,          ,           ,
    492, (LGWR)    , STAT, redo writes                                               ,           344,       68.8,         ,             ,          ,           ,
    492, (LGWR)    , STAT, redo blocks written                                       ,          2604,      520.8,         ,             ,          ,           ,
    492, (LGWR)    , STAT, redo write time                                           ,           332,       66.4,         ,             ,          ,           ,
    492, (LGWR)    , STAT, redo blocks checksummed by FG (exclusive)                 ,           200,         40,         ,             ,          ,           ,
    492, (LGWR)    , TIME, background cpu time                                       ,        117983,     23.6ms,     2.4%, [#         ],          ,           ,
    492, (LGWR)    , TIME, background elapsed time                                   ,       4282180,   856.44ms,    85.6%, [######### ],          ,           ,
    492, (LGWR)    , WAIT, rdbms ipc message                                         ,       1673152,   334.63ms,    33.5%, [WWWW      ],       261,       52.2,     6.41ms
    492, (LGWR)    , WAIT, log file parallel write                                   ,       3068565,   613.71ms,    61.4%, [WWWWWWW   ],       367,       73.4,     8.36ms
    492, (LGWR)    , WAIT, events in waitclass Other                                 ,            55,       11us,      .0%, [          ],         4,         .8,    13.75us

--  End of Stats snap 1, end=2012-12-18 20:23:18, seconds=5

---------------------------------------------------------------------------------------------
Active% | SQL_ID          | SQL_CHILD | EVENT                               | WAIT_CLASS
---------------------------------------------------------------------------------------------
    71% |                 | 0         | log file parallel write             | System I/O
     7% |                 |           | log file sync                       | Commit
     5% | c13sma6rkr27c   | 0         | ON CPU                              | ON CPU
     2% | 0y1prvxqc2ra9   | 0         | ON CPU                              | ON CPU

--  End of ASH snap 1, end=2012-12-18 20:23:18, seconds=5, samples_taken=42

PL/SQL procedure successfully completed.

セッションレベルの待機イベントの平均持続時間をチェックするための簡単な方法を持つことは、トラブルシューティングをスピードアップできるのではないか?応答が遅いセッションにおいて、1ミリ秒の待機が1000回発生しているのか、1000ミリ秒の待機が1回発生しているのかは、重要な違いなのだから。

もちろん平均はいくつかの詳細を隠すかもしれませんが、Snapperにおけるこれらの平均値はシステム全体レベルから求めたものではなく、セッション・レベルの情報から求めたものであるし、《平均を求める単位期間であるところの》スナップショットの間隔は通常数秒であり、数分または数時間ではない《ため、問題とはならないはずです》。

Snapperの出力に時間モデル統計といくつかのSTATメトリックを追加したあと、次のステップとして、私はより役に立つ平均値(今は、必要に応じて自分で手計算している)を追加することを計画しています。次回そのsuper-criticalな問題をトラブルシューティング時に、数秒を節約するために役立つはずです。;-)

だから、是非これを使ってみて、あなたの考えたことを教えてください!

?

(P.S. 私は2013年のOracleパフォーマンスオンラインセミナー ページを更新しました!)