本文書に関する指摘については、原文著者の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と同様です。 ksllwnam、ksllwlblフィールド名を追加して、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パーセント使用されているときは、LatchProfと LatchProfX、WaitProfを使用しないでください 。二つの理由から。
- これらのスクリプトはサンプリング中sleepせず、CPU上でスピンする。 – よって、CPU不足がさらに悪化させるだろう。
- より重要なこと。すべてのCPUが100%の使用率で実行している場合は、あなたが見ているラッチの競合は、おそらくCPU不足自体によって《もたらされる》単なる症状です!同じことが待機イベンにも当てはまります。 – CPUの待ち行列が長い場合は、
CPUの実行キューの待ち時間の代わりにI/Oような待機イベントに帰せられる。(たとえば、I/Oが完了したとき、I/O待機を終了させるためのプロセスのCPU獲得ができません。)
私は、Oracle 9iまたは10g以降で実行しているかどうかを検出し、バージョンに基づき動的に異なるコードを実行するよう、LatchProfとLatchProfXの両方を更新した。(9iには、V$LATCHHOLDERのGET列がない)