Advanced Oracle Troubleshooting Guide, Part 9 – OStackProfを使用してSQL*Plusからプロセススタックプロファイリング


http://blog.tanelpoder.com/2008/10/31/advanced-oracle-troubleshooting-guide-part-9-process-stack-profiling-from-sqlplus-using-ostackprof/
の翻訳です。

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

注意事項


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


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

履歴


  • 2013-12-15: 初稿up


Advanced Oracle Troubleshooting Guide, Part 9 – OStackProfを使用してSQL*Plusからプロセススタックプロファイリング

以前ブログの記事で ORADEBUG SHORT_STACKコマンドを記載したことがある。 – これは、SQLPLUSから直接 ターゲット?プロセスの スタックバックトレースを取得、確認する簡単な方法です。UNIX / Windowsサーバーにログオンする必要はありませんし、スタックを抽出するためのOSツールを使用する必要もありません。

私はまた、読みやすさ、またはパフォーマンスのプロファイリングのため、(pstackのような)OSツールを使用して取得した、スタックトレースの後処理をするいくつかのツールを書いた。たとえば、os_explainとDTraceのスタックプロファイラおよび関数呼び出しアグリゲーター – サンプルのDStackProf

では、SQL*Plusから直接手軽にスタックプロファイリングをするためにORADEBUG SHORT_STACKと連携するクライアントサイドの後処理スクリプトOStackProfをご紹介します! – サーバホストにログインする必要はまったくありません!!

数ヶ月《前?》の会議で、このスクリプトをデモして、"すぐに"ブログに書くと約束したのだけど、
結局ブログのエントリを書く機会が今になった(ロンドンでクライアントを支援するためのフライト前、2,3時間空き時間ができた)。お待たせして申し訳ありません 😉

で、これは、プロセス上のORADEBUGのshort_stackを実行したときに表示されるものです。

SQL> oradebug setospid 32200
Oracle pid: 2, Unix process pid: 32200, image: oracle@linux03 (PMON)
SQL>
SQL> oradebug short_stack
<-ksedsts()+275<-ksdxfstk()+22<-ksdxcb()+1599<-sspuser()+102<-__kernel_vsyscall()+2<-ntevpque()+89<-ntevqone()+34<-nsevwait()+10098<-ksnwait()+72<-ksliwat()+7249<-kslwaitctx()+135<-ksuclnwt()+249<-ksucln()+509<-ksbrdp()+1258<-opirip()+548<-opidrv()+500<-sou2o()+71<-opimai_real()+238<-ssthrdmain()+142<-main()+116<-__libc_start_main()+220<-_start()+33
SQL>
 


これがスタックトレースです。一番左がスタックのバックトレースを取った瞬間に現在実行されていた関数です。それから1つ右の関数、左の関数の呼び出し側です。ずっと右には、Linux OSのプロセスローダヘルパー関数である_start()や、C《言語》の main()関数などの、スタックの「bottom」の関数を見ることができる

太字の2つの関数に注意してください。ターゲットプロセスがデバッガの要求を伝える必要があるとき、SIGUSR2シグナルを送信するように動作しますshort_stack ORADEBUG。 sspuser()はSIGUSR2に対するシグナルハンドラであり、そのタスクは呼び出すべきデバッグ機能を確認することです。だから、sspuser()関数とそれから左のすべて《の関数は》、実際にはORADEBUG要求を処理するためのコードパスなので、トラブルシューティングの目的のためにそれを無視できます。
(これは、ORADEBUG short_stackやerrorstackダンプといったものが、Oracleが正常な実行パスから離れていることを証明している。 – OSツールはそれをしない。《OSツールは》プロセスを中断し、プロセススタックフレームやマップされた実行可能シンボルのセクションから必要なもの読むだけです)

だから、今回のターゲットが存在していた、本物の「business《処理的に有意なぐらいの意味か★》」関数は、Linuxにおいて、プロセスがある種のシステムコールを実行していたことを意味する__ kernel_vsyscall()である。私は私の以前のAOTの記事でそれをやった(そして、今後も継続します)ので、ここで関数名の解釈を更に説明するつもりはない。

スタックプロファイリングのトピックを続けます。単一のスタックのバックトレースを取ることは、ターゲット?プロセスが完全にスタックしているときに役立つ。しかし、悪いパフォーマンスの原因を診断する場合は、あなたは、複数のスタックバックトレースを取り、それらを集約し、多くの実行サンプルがfall inしているの「ブランチ」のコードパスを確認する必要があります(例えばDStackProfがやっているのと同様に)。もちろん、通常のOracleのトラブルシューティングのプロセスのステップ1と2をやり終えた後だけ、これを行うだろう。( 1. そのセッションの待機インタフェースのデータを調べる。2. そのセッションの、V$SESSTATカウンターを調べる。)

手動でスタックトレースを集約することは、エラーが発生しやすく、時間がかかり、did I mention boring★ので、 so now I finally OStackProfのV1.00を紹介する!

OStackProf v1.00はORADEBUGのshort_stackが動作する、任意のプラットフォーム上のOracleサーバーのバージョンで使用できます。(一部の警告については、最終的に問題の項を参照)しかし、最初のバージョンは、Windows クライアント上でのみ動作する。理由は、私が主にWindowsワークステーション/ SQL*Plusからの私のコンサルティングやトラブルシューティングを行うことです。従って、私のクライアントのサイトで追加のスクリプト言語のインストールを必要としないよう、VBScriptでスタックアグリゲータを書いた。迅速かつ簡単に。私はより多くの時間があるとき(および必要;) に、このアグリゲータのUnixのバージョンを書く予定だ。

OStackProfは、以下のように実行されます。

@ostackprof SID INTERVAL #SAMPLES
 


SIDにターゲットのセッションID《を指定するところです》。INTERVALがサンプル間スリープする秒数(あなたも、ゼロまたは0.1のような端数《少数の意味か?》を指定できます)で、#SAMPLESが取得するサンプル数です。

私は通常、このようにそれを実行します。

SQL> @ostackprof 136 0 100
 
\-- oStackProf v1.00 - EXPERIMENTAL script by Tanel Poder ( http://www.tanelpoder.com )
 
WARNING! This script can crash the target process on Oracle 9.2 on Windows
and maybe other versions as well. Test this script out thorouhgly in your
dev environment first!
Hit CTRL+C to cancel, ENTER to continue...
 
Sampling...
 
Below is the stack prefix common to all samples:
\------------------------------------------------------------------------
Frame->function()
\------------------------------------------------------------------------
\# 24 ->__libc_start_main()
\# 23  ->main()
\# 22   ->ssthrdmain()
\# 21    ->opimai_real()
\# 20     ->sou2o()
\# 19      ->opidrv()
\# 18       ->opiodr()
\# 17        ->opiino()
\# 16         ->opitsk()
\# 15          ->ttcpip()
\# 14           ->opiodr()
\# 13            ->kpoal8()
\# 12             ->opifch2()
\# 11              ->qergsFetch()
\# 10               ->qercoFetch()
\#  9                ->qerjotFetch()
\#  8                 ->qerjotFetch()
\#  7                  ->qertbFetch()
\#  6                   ->kdsttgr()
\#  5                    ->kdstf0100101000km()
\#  4                     ->__PGOSF476_qerjotRowProc()
\#  3                      ->qertbFetch()
#  ...(see call profile below)
\#
\# -#--------------------------------------------------------------------
\# - Num.Samples -> in call stack()
\# ----------------------------------------------------------------------
    40 ->kdsttgr()->kdstf0100101000km()->kaf4reasrp0km()->->
    34 ->kdsttgr()->kdstf0100101000km()->->
     5 ->kdsttgr()->kdstf0100101000km()->kdst_fetch.()->ktrget2()->kcbgtcr()->->
     3 ->kdsttgr()->kdstf0100101000km()->kdst_fetch.()->ktrget2()->ktrgcm()->->
     3 ->kdsttgr()->kdstf0100101000km()->expeal()->evareo()->lmebco()->->
     3 ->kdsttgr()->kdstf0100101000km()->expeal()->evareo()->->
     2 ->kdsttgr()->kdstf0100101000km()->kdst_fetch.()->kcbrls()->kcbzfs()->->
     2 ->kdsttgr()->kdstf0100101000km()->expeal()->lmebco()->->
     1 ->kdsttgr()->kdstf0100101000km()->qeaeCn1Serial()->->
     1 ->kdsttgr()->kdstf0100101000km()->qeaeCn1Serial()->->
     1 ->kdsttgr()->kdstf0100101000km()->kdst_fetch.()->ktrget2()->kcbgtcr()->kcbs_simulate()->kcbsacc()->->
     1 ->kdsttgr()->kdstf0100101000km()->kdst_fetch.()->ktrget2()->->
     1 ->kdsttgr()->kdstf0100101000km()->kdst_fetch.()->->
     1 ->kdsttgr()->kdstf0100101000km()->expeal()->->
     1 ->kdsttgr()->kaf4reasrp0km()->->
     1 ->kdsttgr()->__PGOSF470_qercoRop()->->
 
SQL>
 


出力は2つのセクションで提供されます。1番目は行われたすべてのサンプルに共通のスタックトレースの「bottom」の部分です。よって、100%のサンプルにおいて、OracleがqertbFetch()関数(または第2の出力部が示すように、子の一部)を実行していたことを、我々はすぐに理解できます。

そして、ボトムセクションでは、上のスタックセクションの「最も深い」された関数であるqertbFetch()によって実行されるすべての子の関数のコールのプロファイルを確認できる。あなたは100の40サンプル(おおむね 40%の時間)は、実行、関数呼び出しツリーの次の分岐していたことがわかります " – > kdsttgr() – > kdstf0100101000km() – > kaf4reasrp0km()」そして、34%の時間は、" – > kdsttgr() – > kdstf0100101000km()”。
上位2つがサンプルの74%を占めるので、下の行を調べてもあまり意味がありません。

それにもかかわらず、サンプリング中の実行時間の大半は(Kernel Data Scan Table Get Rowを意味する)kdsttgr()によって呼び出されたkdstf0100101000km()関数において費やされたことを、視覚的に識別できます。サーバ?プロセスが実行していたコマンドは、ネストされたループを使用して、全表スキャンの多くを行うスクリプトlotslios.sqlだった。だから、それは、非常に多くのqertbFetch(Query Execution Rowsource Fetch)テーブルスキャンを行う機能やkdst *関数)《が実行されていることを★》を説明している。

ここでは別の例を示します。

SQL> @ostackprof 136 0 100
 
\-- oStackProf v1.00 - EXPERIMENTAL script by Tanel Poder ( http://www.tanelpoder.com )
 
WARNING! This script can crash the target process on Oracle 9.2 on Windows
and maybe other versions as well. Test this script out thorouhgly in your
dev environment first!
Hit CTRL+C to cancel, ENTER to continue...
 
Sampling...
 
Below is the stack prefix common to all samples:
\------------------------------------------------------------------------
Frame->function()
\------------------------------------------------------------------------
\# 56 ->__libc_start_main()
\# 55  ->main()
\# 54   ->ssthrdmain()
\# 53    ->opimai_real()
\# 52     ->sou2o()
\# 51      ->opidrv()
\# 50       ->opiodr()
\# 49        ->opiino()
\# 48         ->opitsk()
\# 47          ->ttcpip()
\# 46           ->opiodr()
\# 45            ->kpoal8()
\# 44             ->opiexe()
\# 43              ->kkxexe()
\# 42               ->peicnt.()
\# 41                ->plsql_run()
\# 40                 ->pfrrun()
\# 39                  ->pfrrun_no_tool()
\# 38                   ->pfrinstr_BFTCHC()
\# 37                    ->pevm_BFTCHC()
\# 36                     ->psdnal()
\# 35                      ->psddr0()
\# 34                       ->rpidrv.()
\# 33                        ->rpiswu2.()
\# 32                         ->rpidru()
\# 31                          ->skgmstack()
\# 30                           ->__PGOSF126_rpidrus()
\# 29                            ->opiodr()
\# 28                             ->opipls()
\# 27                              ->opiosq0()
\# 26                               ->kksParseCursor()
\# 25                                ->kkspbd0()
\# 24                                 ->kksfbc()
\# 23                                  ->kxsGetRuntimeLock()
\# 22                                   ->kksLoadChild()
\# 21                                    ->rpiswu2.()
\# 20                                     ->kksFullTypeCheck()
\# 19                                      ->opitca()
\# 18                                       ->apadrv()
\# 17                                        ->apaqbd.()
\# 16                                         ->apaqbdListReverse()
\# 15                                          ->apaqbdDescendents()
\# 14                                           ->apakkoqb.()
\# 13                                            ->kkoqbc.()
\# 12                                             ->kkooqb()
#  ...(see call profile below)
\#
\# -#--------------------------------------------------------------------
\# - Num.Samples -> in call stack()
\# ----------------------------------------------------------------------
     8 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kketac()->kkeidc()->->
     4 ->kkocnp()->kkojnp()->->
     3 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kkofmx()->->
     3 ->kkocnp()->kkojnp()->kkejnc()->->
     3 ->kkocnp()->kkojnp()->kkeisj()->kkescl()->kkewat.()->slmtnpow()->pow()->->
     2 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kkofmx()->appget()->appopd()->qksfroChild.()->->
     2 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kkofmx()->appget()->appopd()->->
     2 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kketac()->kkeidc()->kkeIdxSelectivity()->kkepsl.()->kkeapr.()->kkewat.()->slmtnpow()->pow()->->
     2 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kketac()->kkeidc()->kkeIdxSelectivity()->kkeapr.()->kkewat.()->slmtnpow()->pow()->->
     2 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kketac()->kkeidc()->kkeGetMinNotNullSel()->ceil()->->
     2 ->kkocnp()->kkojnp()->kkotap.()->kkoitbp()->appget()->->
     2 ->kkocnp()->kkojnp()->kkejnc()->kkesrc.()->kkeSortCosts()->->
     2 ->kkocnp()->kkojnp()->kkeisj()->kkescl()->kkewat.()->slmtnpow()->__ieee754_pow()->->
     1 ->kkognp.()->kkogfp.()->kkoojt.()->->
     1 ->kkocnp()->kkojnp()->qkkFreeKey()->kghfre()->kghfrmrg()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkotsc()->kketac()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkoocl()->appget()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kkofmx()->appopd()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kkofmx()->appget()->applog()->applog()->appopd()->appopd()->appqbc()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kkofmx()->appget()->applog()->applog()->applog()->appopd()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kkofmx()->appget()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kketac()->kkeidc()->kkesScaleIO()->__isnan()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kketac()->kkeidc()->kkepsl.()->kkestRecColUsage.()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kketac()->kkeidc()->kkepsl.()->kkeOperCost.()->kkeOperCost1()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kketac()->kkeidc()->kkepsl.()->kkeapr.()->kkewat.()->slmtnpow()->pow()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kketac()->kkeidc()->kkeMarkIdxPreds()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kketac()->kkeidc()->kkeIdxSelectivity()->kkofsq.()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kketac()->kkeidc()->kkeIdxSelectivity()->kkestBuildMCCtxFromKeys()->kkestBuildMCCtx()->kkestAddMCPredToCtx()->kkestGetMCOpns()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kketac()->kkeidc()->kkeIdxSelectivity()->kkepsl.()->kkofsq.()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kketac()->kkeidc()->kkeIdxSelectivity()->kkepsl.()->kkestRecColUsage.()->ksl_get_shared_latch()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kketac()->kkeidc()->kkeIdxSelectivity()->kkepsl.()->kkestRecColUsage.()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kketac()->kkeidc()->kkeIdxSelectivity()->kkepsl.()->kkeEqJoinSel.()->kkeGetNDVForJoinSel()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kketac()->kkeidc()->kkeIdxSelectivity()->kkepsl.()->kkeapr.()->kkewat.()->__errno_location()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kketac()->kkeidc()->kkeIdxSelectivity()->kkepsl.()->kkeapr.()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kketac()->kkeidc()->kkeIdxSelectivity()->kkepsl.()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kketac()->kkeidc()->kkeIdxSelectivity()->kkeAdjIndexSel.()->qkshtGetOptEstimate()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kketac()->kkeidc()->kkeIdxSelectivity()->ceil()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kketac()->kkeidc()->kkeIdxSelectivity()->0AC591FB->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kketac()->kkeidc()->kkeGetMinNotNullSel()->kkeapr.()->kkewat.()->slmtnpow()->pow()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->kketac()->kkeidc()->kkeGetMinNotNullSel()->kkeapr.()->kkewat.()->slmtnpow()->__ieee754_pow()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->appget()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkonxc.()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkoitbp()->appget()->appopd()->appopd()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkoitbp()->appget()->applog()->appopd()->appopd()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkoiff()->kkonxc.()->kkoixc()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkoiff()->kkonxc.()->kkofmx()->->
     1 ->kkocnp()->kkojnp()->kkotap.()->kkecostb()->->
     1 ->kkocnp()->kkojnp()->kkoSwapOk.()->qkshtQBInfOrg()->qkshtTokenToEnum()->->
     1 ->kkocnp()->kkojnp()->kkosmsel()->qkkAllocFkk.()->->
     1 ->kkocnp()->kkojnp()->kkoPWJfull()->kkoqcp.()->kkoppar.()->qksfroGetPara.()->kkfdPaPrm.()->->
     1 ->kkocnp()->kkojnp()->kkoppar.()->qksfroGetPara.()->kkfdPaPrm.()->->
     1 ->kkocnp()->kkojnp()->kkogjro()->qkkFreeKey()->kghfre()->kghfrmrg()->->
     1 ->kkocnp()->kkojnp()->kkofhsmjk()->appopd()->->
     1 ->kkocnp()->kkojnp()->kkofhsmjk()->appget()->appopd()->->
     1 ->kkocnp()->kkojnp()->kkofhsmjk()->appget()->->
     1 ->kkocnp()->kkojnp()->kkejnc()->qerhjComputeFanoutAndBPS.()->ktatminextsz()->kqrprl()->kqreqd()->kglFreeSO()->->
     1 ->kkocnp()->kkojnp()->kkejnc()->qerhjComputeFanoutAndBPS.()->ktatminextsz()->kqrpre1()->kqrLockAndPinPo()->kglGetSO()->->
     1 ->kkocnp()->kkojnp()->kkejnc()->qerhjComputeFanoutAndBPS.()->->
     1 ->kkocnp()->kkojnp()->kkejnc()->kkesrc.()->ceil()->->
     1 ->kkocnp()->kkojnp()->kkejnc()->floor()->->
     1 ->kkocnp()->kkojnp()->kkejcd()->kkestGetJoinMCSel()->kkestProductSel()->qksopOptASJLeftOpn()->->
     1 ->kkocnp()->kkojnp()->kkejcd()->kkestGetJoinMCSel()->kkestProductSel()->qksopOptASJLeftOpn()->->
     1 ->kkocnp()->kkojnp()->kkejcd()->kkestGetJoinMCSel()->kkestProductSel()->kkepsl.()->kkeEqJoinSel.()->->
     1 ->kkocnp()->kkojnp()->kkejcd()->kkestGetJoinMCSel()->kkestProductSel()->kkepsl.()->kkeapr.()->kkewat.()->slmtnpow()->__ieee754_pow()->->
     1 ->kkocnp()->kkojnp()->kkejcd()->kkestBuildJoinMCCtx()->kkestGetJoinColGroupHtEl()->kgghteFind()->kgghteGetEle()->->
     1 ->kkocnp()->kkojnp()->kkejcd()->kkestBuildJoinMCCtx()->kkestGetJoinColGroupHtEl()->kgghteFind()->->
     1 ->kkocnp()->kkojnp()->kkejcd()->kkestBuildJoinMCCtx()->kkestGetJoinColGroupHtEl()->->
     1 ->kkocnp()->kkojnp()->kkejcd()->kkepsl.()->ksl_get_shared_latch()->->
     1 ->kkocnp()->kkojnp()->kkejcd()->kkepsl.()->kkeEqJoinSel.()->kkeast()->->
     1 ->kkocnp()->kkojnp()->kkejcd()->kkepsl.()->kkeEqJoinSel.()->->
     1 ->kkocnp()->kkojnp()->kkejcd()->kkepsl.()->kkeapr.()->kkewat.()->slmtnpow()->pow()->->
     1 ->kkocnp()->kkojnp()->kkejcd()->kkepsl.()->kkeapr.()->kkewat.()->->
     1 ->kkocnp()->kkojnp()->kkejcd()->kkeAdjJoinPrefCard()->qkshtGetOptEstimate()->->
     1 ->kkocnp()->kkojnp()->kkejcd()->kkeAdjJoinPrefCard()->kghstack_alloc()->->
     1 ->kkocnp()->kkojnp()->kkeisj()->kkescl()->kkewat.()->->
     1 ->kkocnp()->kkojnp()->kkeisj()->->
 


上のセクションの一番下から再び《見ます》、すべてのスタックサンプルが、kkooqb()関数からスタックの最初(main()関数)まで、共通のスタックバックトレースをもつことがわかります。

Metalinkのノート175982.1は、kkoはKernel Kompile Optimizeを意味を教えてくれます。私はkkooqbはkernel compile optimize Optimize Query Blockを意味すると推測しています。だから、いくつかのクエリの最適化(ハード解析処理の一部)が起こっています。私は、そのテストケース用の新しいSQLをハード解析するPL/SQLループを繰り返して実行していた。

kkooqb()より下のループは、「ゆるい」または「そのタイトではないループ」であることように見えることに注意してください★。それは、非常に多くの関数が、1だけ、または数個のサンプルが記録されているためです。《ある特定の関数が集中的に実行されていないことを指しているようだ》上部のセクションにより、すべての時間にわたりすべてのプロセスが実行していたメイン関数コールスタックが特定されているため、これはちょっと興味深い情報です。だから、一番上のセクションは、調べるべき常に最初の部分である。未解決の疑問が多く残っている場合に(たとえば、opiexe()が何かを実行していることを示している場合)、多くの時間が費やされた関数があるかどうかを確認するため、下のセクションのプロファイルを調査することは有意義である。

標準のinstrumentation(wait interfaceおよびV$SESSTATパフォーマンスカウンタ)で、問題を識別することに失敗した場合にのみ、このツールを使用するべきであることに注意してください。これが、このブログエントリのタイトルを "Advanced" Oracle Toubleshooting と呼んでいる理由です。もちろん、学習の目的のためなら、任意の本番データベースでそれをしない限り、これをいつでも実行することができます。

このツールは実験的なものであり、完全に開発されテストされた製品ではないので、いくつかの問題(というかORADEBUG SHORT_STACKが持っている問題)があります。

問題:

時には、まったく関数を確認できないか、__kernel_vsyscall()のようなたった1つの関数しか確認できない場合があります。これは、Oracleはすべてのサンプルの間に、Oracleがシステムコール内にいたときです。
いくつかのプラットフォームでは、プロセスがシステムコール内にいるとき、short_stackコマンドが完全なユーザランドのスタックのバックトレースを返しません。

SQL> @ostackprof 136 0 10
 
\-- oStackProf v1.00 - EXPERIMENTAL script by Tanel Poder ( http://www.tanelpoder.com )
 
WARNING! This script can crash the target process on Oracle 9.2 on Windows
and maybe other versions as well. Test this script out thorouhgly in your
dev environment first!
Hit CTRL+C to cancel, ENTER to continue...
 
Sampling...
 
Below is the stack prefix common to all samples:
\------------------------------------------------------------------------
Frame->function()
\------------------------------------------------------------------------
\#  0 ->__kernel_vsyscall()
\#  ...(see call profile below)
\#
\# -#--------------------------------------------------------------------
\# - Num.Samples -> in call stack()
\# ----------------------------------------------------------------------
    10 ->->
 


(以下の)他の関連する問題は、すべての取得されたスタック内の上記のように単一の「truncateされた」スタックトレースのみがある場合は、明らかに、すべてのサンプルで確認された関数呼び出しで、共通したサブセットがない。(他のすべての関数はmain()のような《関数》で始まる。しかし、1つのkernel_vsyscall()がある★)したがって、すべてのスタックが下部セクションに完全に出力され、出力は非常に大きくなる。(あなたのブラウザはそれを処理できることを願ってます:-))

SQL> @ostackprof 132 0 10
 
\-- oStackProf v1.00 - EXPERIMENTAL script by Tanel Poder ( http://www.tanelpoder.com )
 
WARNING! This script can crash the target process on Oracle 9.2 on Windows
and maybe other versions as well. Test this script out thorouhgly in your
dev environment first!
Hit CTRL+C to cancel, ENTER to continue...
 
Sampling...
 
Below is the stack prefix common to all samples:
\------------------------------------------------------------------------
Frame->function()
\-		-----------------------------------------------------------------------
\#  ...(see call profile below)
\#
\# -#--------------------------------------------------------------------
\# - Num.Samples -> in call stack()
\# ----------------------------------------------------------------------
     2 ->__kernel_vsyscall()->->
     1 ->__libc_start_main()->main()->ssthrdmain()->opimai_real()->sou2o()->opidrv()->opiodr()->opiino()->opitsk()->ttcpip()->opiodr()->kpoal8()->opiexe()->kkxexe()->peicnt.()->plsql_run()->pfrrun()->pfrrun_no_tool()->pfrinstr_EXIM()->pevm_EXIM()->psdnal()->psddr0()->rpidrv.()->rpiswu2.()->rpidru()->skgmstack()->__PGOSF126_rpidrus()->opiodr()->opipls()->opiosq0()->kksParseCursor()->kkspsc0()->kksfbc()->kxsGetRuntimeLock()->kksLoadChild()->rpiswu2.()->kksParseChildCursor()->opiprs()->opiParse()->prsdrv()->prscmd()->qcpicmd()->qcpiqry()->qcpiqex()->qcpiqbk()->qcpisel()->qcpihnt()->qcplgnt()->qcplgte()->qcplgte_multibyte()->->
     1 ->__libc_start_main()->main()->ssthrdmain()->opimai_real()->sou2o()->opidrv()->opiodr()->opiino()->opitsk()->ttcpip()->opiodr()->kpoal8()->opiexe()->kkxexe()->peicnt.()->plsql_run()->pfrrun()->pfrrun_no_tool()->pfrinstr_EXIM()->pevm_EXIM()->psdnal()->psddr0()->rpidrv.()->rpiswu2.()->rpidru()->skgmstack()->__PGOSF126_rpidrus()->opiodr()->opipls()->opiosq0()->kksParseCursor()->kkspsc0()->kksfbc()->kxsGetRuntimeLock()->kksLoadChild()->rpiswu2.()->kksFullTypeCheck()->opitca()->qkadrv2()->qkeAnalyzeAllExprs()->qkeaan()->qkerfex()->qkerf0ex()->->
     1 ->__libc_start_main()->main()->ssthrdmain()->opimai_real()->sou2o()->opidrv()->opiodr()->opiino()->opitsk()->ttcpip()->opiodr()->kpoal8()->opiexe()->kkxexe()->peicnt.()->plsql_run()->pfrrun()->pfrrun_no_tool()->pfrinstr_EXIM()->pevm_EXIM()->psdnal()->psddr0()->rpidrv.()->rpiswu2.()->rpidru()->skgmstack()->__PGOSF126_rpidrus()->opiodr()->opipls()->opiosq0()->kksParseCursor()->kkspsc0()->kksfbc()->kxsGetRuntimeLock()->kksLoadChild()->rpiswu2.()->kksFullTypeCheck()->opitca()->qkadrv2()->qkadrv2Post()->qkaEnableWideTableSelect()->qkaRowShippingAnnotation()->->
     1 ->__libc_start_main()->main()->ssthrdmain()->opimai_real()->sou2o()->opidrv()->opiodr()->opiino()->opitsk()->ttcpip()->opiodr()->kpoal8()->opiexe()->kkxexe()->peicnt.()->plsql_run()->pfrrun()->pfrrun_no_tool()->pfrinstr_EXIM()->pevm_EXIM()->psdnal()->psddr0()->rpidrv.()->rpiswu2.()->rpidru()->skgmstack()->__PGOSF126_rpidrus()->opiodr()->opipls()->opiosq0()->kksParseCursor()->kkspsc0()->kksfbc()->kxsGetRuntimeLock()->kksLoadChild()->rpiswu2.()->kksFullTypeCheck()->opitca()->opiDeferredSem()->opiSem()->kkqgbpdrv()->->
     1 ->__libc_start_main()->main()->ssthrdmain()->opimai_real()->sou2o()->opidrv()->opiodr()->opiino()->opitsk()->ttcpip()->opiodr()->kpoal8()->opiexe()->kkxexe()->peicnt.()->plsql_run()->pfrrun()->pfrrun_no_tool()->pfrinstr_EXIM()->pevm_EXIM()->psdnal()->psddr0()->rpidrv.()->rpiswu2.()->rpidru()->skgmstack()->__PGOSF126_rpidrus()->opiodr()->opipls()->opiosq0()->kksParseCursor()->kkspsc0()->kksfbc()->kxsGetRuntimeLock()->kksLoadChild()->rpiswu2.()->kksFullTypeCheck()->opitca()->apadrv()->apaqbd.()->apaqbdListReverse()->apaqbdDescendents()->apakkoqb.()->kkoqbc.()->kkooqb()->kkoiqb()->qksshMemAllocPerm()->kghalp()->0AC59043->->
     1 ->__libc_start_main()->main()->ssthrdmain()->opimai_real()->sou2o()->opidrv()->opiodr()->opiino()->opitsk()->ttcpip()->opiodr()->kpoal8()->opiexe()->kkxexe()->peicnt.()->plsql_run()->pfrrun()->pfrrun_no_tool()->pfrinstr_EXIM()->pevm_EXIM()->psdnal()->psddr0()->rpidrv.()->rpiswu2.()->rpidru()->skgmstack()->__PGOSF126_rpidrus()->opiodr()->opipls()->opiosq0()->kksParseCursor()->kkspsc0()->kksfbc()->kxsGetRuntimeLock()->kksLoadChild()->qksceCopyEnv.()->->
     1 ->__libc_start_main()->main()->ssthrdmain()->opimai_real()->sou2o()->opidrv()->opiodr()->opiino()->opitsk()->ttcpip()->opiodr()->kpoal8()->opiexe()->kkxexe()->peicnt.()->plsql_run()->pfrrun()->pfrrun_no_tool()->pfrinstr_EXIM()->pevm_EXIM()->psdnal()->psddr0()->rpidrv.()->rpiswu2.()->rpidru()->skgmstack()->__PGOSF126_rpidrus()->opiodr()->opipls()->opiosq0()->kksParseCursor()->kkspsc0()->kksfbc()->kxsGetRuntimeLock()->kksLoadChild()->qksceCopyEnv.()->->
     1 ->__libc_start_main()->main()->ssthrdmain()->opimai_real()->sou2o()->opidrv()->opiodr()->opiino()->opitsk()->ttcpip()->opiodr()->kpoal8()->opiexe()->kkxexe()->peicnt.()->plsql_run()->pfrrun()->pfrrun_no_tool()->pfrinstr_EXIM()->pevm_EXIM()->psdnal()->psddr0()->rpidrv.()->rpiswu2.()->rpidru()->skgmstack()->__PGOSF126_rpidrus()->opiodr()->opipls()->opiosq0()->kksParseCursor()->kkspsc0()->kksfbc()->kghalo()->kghprmalo()->kghfnd()->kghgex()->kghalo()->kghfnd()->kghfrunp()->->
 
SQL>
 


とにかく、このツールは私の人生を容易にしました。ちょうど何かをテストするときに、OSにログオンする必要はありませんし、スタック処理スクリプトを実行する必要もありませんので。また、oStackProfは、パラメータ(とはSPID)としてSIDを取るので、手動で探す時間を少し節約できます。

いくつかの注意事項:

1)このスクリプトは、Windows上にあるようにSQLPLUS クライアントが必要です。それこれは後処理スタックトレースのためのVBスクリプトを使用しているためです。なぜVBとWindows?それは私のほとんどの顧客が自分のワークステーションに持っている構成《だから》です。そして、PerlやPythonとawkなどを含む多くのものは追加のダウンロードが必要なのに対して、VBの実行機能はデフォルトでそこにインストールされています。

これらのツールは、デフォルトでインストールされるような、Unix上でなぜこの《処理》を実行しないのか?もう一度《いうが》、Windowsはより便利であり、ときどき★、OSレベルでDBサーバへアクセスするには時間がかかりすぎる、または不可能です(そこに何かダウンロードしたい場合は特に)。

2)このスクリプトは、 実験的なものです! スクリプトのヘッダーにある注意書きを読んでください。いくつかのプラットフォームでは、ORADEBUGのshort_stackは調査中にターゲットプロセスがクラッシュさせます。

インストール:

1) http://www.tanelpoder.com/files/scripts/ostackprof.sqlからostackprof.sqlをダウンロードする
2)http://www.tanelpoder.com/files/scripts/stack_helper.vbsからstack_helper.vbsダウンロードします。
3)スクリプトをダウンロードしたディレクトリにあなたのSQLPATH環境変数を設定します。
4)SQL*Plusを実行します。
5)@ostackprof SID 0 10 を実行します。

もう一度思い出してください。このスクリプトは実験的であり、本番データベースには使用しないでください。

スタックトレースを解釈する方法についての完成途中の資料がある。今、非常に忙しいので、1か月ぐらいで《何とか》完成させたいと思っている。
(11月に7都市でAdvanced Oracle Troubleshooting セミナーを提供する予定です。あなたはoStackProfの詳細を知りたいなら、後で申し込んでください :-)

Happy スタック?サンプリング!