Advanced Oracle Troubleshooting Guide, Part 8:LatchProfXを使用した、より詳細なラッチのトラブルシューティング


http://blog.tanelpoder.com/2008/07/23/advanced-oracle-troubleshooting-guide-part-8-even-more-detailed-latch-troubleshooting-using-latchprofx/
の翻訳です。

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

注意事項


  • 自動翻訳に手を加えたレベルの翻訳と理解してください
  • 意味をとりやすくするために追加した箇所については、《…》で囲っています。
  • 訳がわからない、または、自信がない箇所は★をつけています。


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

履歴


  • 2013-12-14: 初稿up


Advanced Oracle Troubleshooting Guide, Part 8:LatchProfXを使用した、より詳細なラッチのトラブルシューティング

直近のAOTポストで、V$LATCHHOLDERから詳細なlatchholderデータをサンプリングできるスクリプトLatchProf を公開した。

Latchprofは、セッション?レベルでラッチの問題をドリルダウンすることができます。
(V$LATCH、V$LATCH_PARENTおよびV$LATCH_CHILDRENはできません)したがって、 おそらく 、ほとんどのラッチ競合の問題に貢献して、最もラッチを保持している個々のセッションに関する有益な詳細情報を取得することができます。

しかし、あなたが問題を起こすセッションを発見した後、その次はどうする?一つの方法は、Snapperツールを使用して、V$SESSTATカウンターを調査すること。疑わしいラッチがどのラッチであるかに応じて、cache buffers chainsラッチの様々な統計情報を取得する、ライブラリ?キャッシュ?ラッチを見るとき?パース/実行統計、のように異なる統計を見るだろう。これらの統計が「通常」に見える場合は、さらにドリルダウンする他の方法はありますか?

ええ、ありますし、それを見てみましょう!

サイドコメント:(私の経験では、多くのクライアント先の環境で、常に簡単に、SYSでのアクセス、またはX$表に作成されたプロキシ?ビューを持っていないため)最近は、V$ビューを選び、X$表を使用しないようにしてください。また、単純なV$ビューを使用して仕事を成し遂げることができるなら、なぜ、より複雑なX$表にこだわるのか?(ええ、ずっとcoolですよ、知ってます★)

とにかく、例外があります:LatchProfXスクリプト、それはラッチ保有者に関するいくつかの非常に興味深い拡張情報を提供しているため、拡張されたラッチホルダプロファイラ(Latch holder Profiler eXtended)を意味します。これは、現在保持しているラッチが、最終的に取られた理由を示します 。後者はすべての必要な情報を外部に公開しないので、それは、V$LATCHHOLDERの代わりに、 X$KSUPRLATを使用しています。私は、ラッチの「Where statistics」について話します。

「Where statistics」により、Oracleカーネルのラッチモジュールの開発者が、十分にコード??をインストルメント化していることを意味している。 – ラッチを取得するたびに、ラッチ取得者のコードの位置IDをラッチ構造自体に記録する。

もうお待たせしないようにしましょう。いくつかの例を示します。出力が非常に広いので、それに応じてブラウザのウィンドウのリサイズが必要な場合があります。

通常、あなたはトラブルメーカーである知っている唯一または少数のラッチを監視するために、特定の十分なパラメータでLatchProfXを実行します。ただし、私が最初の例の実行は、LatchProfX結果データの有用性を説明するために、(三番目のパラメータに%《を指定して》)すべてのインスタンスのラッチに対して行う。

LatchProfX構文は、オリジナルのLatchProfと同様です。 ksllwnamksllwlblフィールド名を追加して、you can sample★
これらは、「カーネル内のどこからラッチ獲得されたか」について記述を与える★X$KSUPRLATから得るオペコード、(X$KSLLWからの)《正確に》フィールドです。(構文と内部実装についてはスクリプト自体を見てほしい)

それで、(やっと)それを実行してみましょう:

SQL> @latchprofx name,ksllwnam,ksllwlbl % % 100000

-- LatchProfX 1.06 by Tanel Poder ( http://www.tanelpoder.com )

NAME                                KSLLWNAM                                 KSLLWLBL                   Held       Gets  Held %     Held ms Avg hold ms
----------------------------------- ---------------------------------------- -------------------- ---------- ---------- ------- ----------- -----------
shared pool                         kghalo                                                              9705       5987    9.71     185.366        .031
ges resource hash list              kjuscl: lock close request                                          2429       2350    2.43      46.394        .020
kks stats                           kksAllocChildStat                                                   2001       1460    2.00      38.219        .026
ges resource hash list              kjrmas1: lookup master node                                         1780       1724    1.78      33.998        .020
shared pool                         kghupr1                                  Chunk Header               1618        891    1.62      30.904        .035
row cache objects                   kqrpre: find obj                                                     988        986     .99      18.871        .019
shared pool simulator               kglsim_unpin_simhp                                                   804         97     .80      15.356        .158
ges process parent latch            kjlalc: lock allocation from lmon                                    779        766     .78      14.879        .019
active service list                 kswsgetso: get service object                                        663        658     .66      12.663        .019
shared pool                         kghalp                                                               635        628     .64      12.129        .019
ges process parent latch            kjatioc                                                              518        518     .52       9.894        .019
shared pool simulator               kglsim_upd_newhp                                                     402        401     .40       7.678        .019
ges resource hash list              kjrref: find matched resource                                        374        371     .37       7.143        .019
row cache objects                   kqreqd                                                               360        360     .36       6.876        .019
ges process parent latch            kjlrem: detach lock from group                                       235        229     .24       4.489        .020
enqueues                            ksqdel                                                               162        162     .16       3.094        .019
enqueues                            ksqgel: create enqueue                   parent obj                  148        148     .15       2.827        .019
row cache objects                   kqreqd: reget                                                        108        105     .11       2.063        .020
enqueue hash chains                 ksqrcl                                   resource addr               101        101     .10       1.929        .019
shared pool                         kgh_heap_sizes                                                        99         99     .10       1.891        .019
enqueue hash chains                 ksqgtl3                                  acquiring session            93         93     .09       1.776        .019
ges enqueue table freelist          kjlalc: lock allocation                                               85         83     .09       1.624        .020
shared pool                         kghfre                                   Chunk Header                 74         65     .07       1.413        .022
shared pool simulator               kglsim_scan_lru: scan                                                 69         69     .07       1.318        .019
ges process parent latch            kjucll: closing lock                                                  68         61     .07       1.299        .021
shared pool simulator               kglsim_chg_simhp_free                                                 48         47     .05        .917        .020
ges domain table                    kjdmlad: add a lock to an xid-hashed loc                              42         41     .04        .802        .020
shared pool simulator               kglsim_chg_simhp_noob                                                 41         41     .04        .783        .019
shared pool simulator               kglsim_unpin_simhp: fast path                                         39         39     .04        .745        .019
ksuosstats global area              ksugetosstat                                                          29          1     .03        .554        .554
ges group table                     kjgdgll: move a lock from group lock lis                              13          6     .01        .248        .041
kokc descriptor allocation latch    kokcdlt: regular free                    latch                        11          4     .01        .210        .053
ges enqueue table freelist          kjlfr: remove lock from parent object                                 11         11     .01        .210        .019
kokc descriptor allocation latch    kokcdlt: allocation                      latch                         5          4     .01        .096        .024
cache buffers chains                kcbgtcr: fast path                                                     3          3     .00        .057        .019
ges caches resource lists           kjrchc: cached obj cleanup                                             2          2     .00        .038        .019
process allocation                  ksufap: active procs                                                   2          2     .00        .038        .019
ges group table                     kjgagll: move a lock from process lock l                               2          2     .00        .038        .019
ges domain table                    kjdmlrm: remove a lock from its xid-hash                               1          1     .00        .019        .019
ges caches resource lists           kjchc: clean resource cache                                            1          1     .00        .019        .019
ges resource hash list              kjruch: move resource from cache to free                               1          1     .00        .019        .019
name-service memory objects         kjxgsnep: get a value-block object                                     1          1     .00        .019        .019
active service list                 kswsite: service iterator                                              1          1     .00        .019        .019

43 rows selected.

Elapsed: 00:00:02.06


私たちが見ているものは何か?LatchProfは単にどの(子)ラッチが保持されていたか、そのSIDによって保持されていたかというラッチホルダー情報を表示しますが、LatchProfXは、それに加えて、なぜそのラッチが取得されたかを表示します。

上の例から、共有プール?ラッチが保持されたのに様々な理由があることがわかります。
しかし《それだけでなく?》、共有プールラッチが最も時間を保持された理由は、カーネルの一般的なヒープ割り当てを意味するであろう、kghaloというコードロケーションだったことがわかります。それは、本質的には、共有プールから空き領域を検索および割り当てるために使用される関数です。チャンクを開放し、ヒープグローバル統計更新するような種の処理は単純な操作である。なぜなら、Oracleがすでにそれが更新する必要があるメモリ位置を知っているから。しかし、
割り当てのための空きチャンクを検索することは、適切なチャンクがフリーリストにない場合は、多くのチャンクのスキャンが必要な場合がある。また、LRUのスキャンも必要になる。

次に、総サンプリング時間の1.62パーセントの共有プール?ラッチの保持を起こしているkghupr1というロケーションがあります。関数kghupr1(un-pin recreable)内のこのロケーションは、un-pinされたチャンクをヒープLRUリストに戻すため、共有プール?ラッチを取る必要があります。Oracleカーネル開発者《coder》もまた、LWLBL列から確認できるラベル(action description)に「チャンクヘッダ」と指定していました。チャンクヘッダーを更新する必要があるので、Its in place to state that ★このカーネルロケーションが共有プール?ラッチを取得すること – あるチャンクをLRUリストへ戻すことは、チャンクヘッダー(および、その周辺のヘッダ)を更新を意味します。

グローバルヒープ統計(あなたが例えば五$ SGASTATから見えるもの)を更新するkgh_heap_sizes?、とヒープ内のチャンクを解放するkghfre というロケーションも出力されています。

(ひどい競合が発生している状況で)どのラッチがトラブルメーカーであるか、その理由は「なぜ」のかWherever you have estabilished★、おそらく、問題を寄与したセッションを知りたいでしょう。LatchProfXはそれを表示できます。

SQL> @latchprofx sid,name,ksllwnam,ksllwlbl % "shared pool" 100000

-- LatchProfX 1.06 by Tanel Poder ( http://www.tanelpoder.com )

       SID NAME                                KSLLWNAM                                 KSLLWLBL                   Held       Gets  Held %     Held ms Avg hold ms
---------- ----------------------------------- ---------------------------------------- -------------------- ---------- ---------- ------- ----------- -----------
       113 shared pool                         kghalo                                                              5038       2787    5.04      92.699        .033
       112 shared pool                         kghalo                                                              4723       2820    4.72      86.903        .031
       113 shared pool                         kghupr1                                  Chunk Header                875        369     .88      16.100        .044
       113 shared pool simulator               kglsim_unpin_simhp                                                   728         48     .73      13.395        .279
       112 shared pool                         kghupr1                                  Chunk Header                623        438     .62      11.463        .026
       112 shared pool simulator               kglsim_unpin_simhp                                                   273         37     .27       5.023        .136
       112 shared pool                         kghalp                                                               232        232     .23       4.269        .018
       113 shared pool simulator               kglsim_upd_newhp                                                     230        230     .23       4.232        .018
       113 shared pool                         kghalp                                                               224        223     .22       4.122        .018
       112 shared pool simulator               kglsim_upd_newhp                                                     194        194     .19       3.570        .018
       112 shared pool                         kgh_heap_sizes                                                        49         49     .05        .902        .018
       113 shared pool                         kgh_heap_sizes                                                        49         49     .05        .902        .018
       112 shared pool                         kghfre                                   Chunk Header                 37         37     .04        .681        .018
       113 shared pool simulator               kglsim_scan_lru: scan                                                 32         32     .03        .589        .018
       112 shared pool simulator               kglsim_scan_lru: scan                                                 28         27     .03        .515        .019
       112 shared pool simulator               kglsim_chg_simhp_free                                                 27         27     .03        .497        .018
       113 shared pool simulator               kglsim_chg_simhp_free                                                 26         25     .03        .478        .019
       113 shared pool                         kghfre                                   Chunk Header                 24         23     .02        .442        .019
       112 shared pool simulator               kglsim_unpin_simhp: fast path                                         23         23     .02        .423        .018
       113 shared pool simulator               kglsim_chg_simhp_noob                                                 22         22     .02        .405        .018
       112 shared pool simulator               kglsim_chg_simhp_noob                                                 18         18     .02        .331        .018
       113 shared pool simulator               kglsim_unpin_simhp: fast path                                         18         18     .02        .331        .018
       112 shared pool sim alloc               kglsim_chk_objlist: alloc                                              1          1     .00        .018        .018
       122 shared pool                         kghfre                                   Chunk Header                  1          1     .00        .018        .018

24 rows selected.

Elapsed: 00:00:01.93
SQL>


上記から、主に2つのセッションが共有プールのラッチの競合に寄与していることがわかるでしょう。共に、メモリを割り当てるkghaloをたくさん呼び出している。それらのセッションのV$SESSTATが、高い「parse count (hard)」統計を示していたとき、

負荷の高い共有プール処理は、ハード解析によることが明らかである(非常に多くの場合、過剰のハード解析が共有プール?ラッチ競合の理由であるのは、ある種の一般常識である)。しかし、同じパラメータで別のサンプルに注目してみましょう:

SQL> @latchprofx sid,name,ksllwnam,ksllwlbl % "shared pool" 100000

-- LatchProfX 1.06 by Tanel Poder ( http://www.tanelpoder.com )

       SID NAME                                KSLLWNAM                                 KSLLWLBL                   Held       Gets  Held %     Held ms Avg hold ms
---------- ----------------------------------- ---------------------------------------- -------------------- ---------- ---------- ------- ----------- -----------
         0 shared pool                         kghalo                                                             10714          5   10.71     212.137      42.427
       122 shared pool                         kghalo                                                              7685         42    7.69     152.163       3.623
       112 shared pool                         kghalo                                                              3874       2305    3.87      76.705        .033
       113 shared pool                         kghalo                                                              3616       2318    3.62      71.597        .031
       112 shared pool                         kghupr1                                  Chunk Header                659        327     .66      13.048        .040
       113 shared pool                         kghupr1                                  Chunk Header                597        353     .60      11.821        .033
       112 shared pool simulator               kglsim_unpin_simhp                                                   416         29     .42       8.237        .284
[...snip...]
       122 shared pool simulator               kglsim_upd_newhp                                                       2          2     .00        .040        .020
       117 shared pool                         kghupr1                                  Chunk Header                  2          2     .00        .040        .020
       122 shared pool                         kghalp                                                                 2          2     .00        .040        .020
       117 shared pool                         kghalp                                                                 1          1     .00        .020        .020

38 rows selected.

Elapsed: 00:00:02.14

SQL>


これは何でしょう?なぜ、kghalo関数をコールし、他のセッションよりも平均的にはるかに長くラッチを保持する、SID= 0のセッションがあるのでしょうか?LatchProfXは、そのセッションによる、合計で最も時間をとっているkghaloのロケーションからの、たった5回のラッチ獲得を検知した。そして、他のほとんどの《ラッチ獲得が》マイクロ秒単位である一方で、そのラッチの平均保持時間は42ミリ秒以上と算出された。(ラッチの平均保持時間が3.6ミリ秒であっても、非常に長い《と考えられる》)

このような長い保持時間の理由の一つとして、CPUのプリエンプションの可能性がある – ラッチホルダプロセスは、CPUからswitch offされて、戻されるまでの間、処理を完了し、再びラッチを解除するのにしばらく時間がかかった。しかし、私の4 CPUテストマシンで利用可能なCPU時間は多くあったため、このようなプリエンプションが問題ではなかったはずだった。SID 0が手がかりを与えます。新しいセッションがOracleで起動すると、《in some places》セッション初期化シーケンス中は、SID 0として報告されることが明らかである。《報告される内容には、》V$SESSTATおよびV$SESSION_EVENTアレイ、セッション?パラメータ値などのためのメモリ割り当てが含まれる。《and set events in some cases》これらの構造体の合計サイズが通常の共有プールの使用状況コンテキスト(KB数十)では非常に大きいことを考えると、空きリストが空であると、LRUスキャンが起こる必要がある場合は、必然的に時間がかかる – そして、共有プール?ラッチは、その間を保持される。 (あー、私は短い文を記述する必要がありますね)。

とにかく、私は、テスト環境で、ハード解析、ソフト解析、物理IOおよびバッファ獲得のようなさまざまなワークロードを実行する このスクリプトで遊ぶことをお勧めします。
そして、あなたは、いくつかのOracleの内部動作《の動作》方法に対するかなり良い概要を取得すべきです。うまくいけば、私がどのようにOracleの関数名の一部とその目的を知っているか《知ったか》の答えになるでしょう – その答えは、Oracle自身が、私のスクリプトで使用しているX$表で、かなり多くの情報を公開しているということです。実験し、観察し、kghaloなどのような関数の背後にある真の名前が何かを考える必要があるだけです。楽しんで :)

さらにいくつかの注意事項:

子ラッチレベルにドリルダウンする場合は、LatchProfXへの最初のパラメータに(SID,NAMEなど)の別のフィールドとしてLADDRを使用すること(これはAOT guide part 7 で説明済みである)。

サーバーのCPUが100パーセント使用されているときは、LatchProfLatchProfXWaitProfを使用しないでください 。二つの理由から。

  1. これらのスクリプトはサンプリング中sleepせず、CPU上でスピンする。 – よって、CPU不足がさらに悪化させるだろう。
  2. より重要なこと。すべてのCPUが100%の使用率で実行している場合は、あなたが見ているラッチの競合は、おそらくCPU不足自体によって《もたらされる》単なる症状です!同じことが待機イベンにも当てはまります。 – CPUの待ち行列が長い場合は、
    CPUの実行キューの待ち時間の代わりにI/Oような待機イベントに帰せられる。(たとえば、I/Oが完了したとき、I/O待機を終了させるためのプロセスのCPU獲得ができません。)

私は、Oracle 9iまたは10g以降で実行しているかどうかを検出し、バージョンに基づき動的に異なるコードを実行するよう、LatchProfとLatchProfXの両方を更新した。(9iには、V$LATCHHOLDERのGET列がない)