• リソース不足について - 第 1 回

    こんにちは。 Windows テクノロジー サポートの田辺です。

     

    システムの管理を行っていると必ずと言って良い程直面するのが、システムのリソース不足だと思います。

    システム リソースって?と聞かれるとまず思いつくのが、物理メモリになるかと思いますが、システムで使用しているリソースは、実は物理的に搭載しているメモリだけではありません。

     

    そこで今回はシステム リソースの中からも、デバイスの開発者やサポート業務等に従事している方以外にはあまり知られていないような、ページ プールや 非ページ プールといったリソースをピックアップして紹介させていただきたいと思います。

     

     

    ページ プールと非ページ プールについて

     

    一言で言うと、ページ アウトしないプール領域とページ アウトする事が出来るプール領域という事になりますが、言葉だけだとさっぱり分かりませんね。

    そこで漠然とですが説明しますと、、

     

     - ページ プール

     

    ページ プールとは、カーネル モードで動作するドライバによって確保される仮想メモリ空間で、OS コンポーネントやアプリケーションにより利用される。

    ページ プールはページング ファイルへの書き出し (ページ アウト) を行うことが可能。

    ページ アウトが可能なため、確保されているページ プールが全て物理メモリ上に存在しているわけでは無い。

     

     - 非ページプール

     

    ページ プールとは異なり、ページ アウトが行われない領域。

     

    となります。

     

    ページ プール、非ページ プールの用途は多岐に渡りますが、実際にプール領域を比較的多く使用するモジュールとしては、OS モジュールのほか、I/O を処理するドライバや、ウイルス対策ソフト等に含まれるフィルタ ドライバが一般的に知られています。

     

    そして、これらの領域は共有されているために、椅子取りゲームと同じで特定のフィルタ ドライバ等で多く確保されてしまうと、他のフィルタ ドライバで使う事ができなくなって、様々な問題が発生する可能性があります。

     

    これらの領域が枯渇していきますと、有名なところではイベント ログでは、srv : 2019 srv : 2020 といったイベントが記録されたり、ファイル共有にアクセスできなくなったり、システムがハングアップしてみたり etc... といろいろと不都合な現象が発生してきます。

     

    さて、そこで気になるのがこれって最大でどのくらい使えるの?という事ですが、実は OS 32-bit の環境と64-bit の環境では大きく違ってきます。

     

     

     

    32-bit

    64-bit

    非ページ

    256 MB (/3GB 有効時は 128MB)

    128 GB

    ページ

    491.875 MB (Windows 2000, XP)

    128 GB

    650 MB (Windows Server 2003)

     

    ※ 実際には上記を最大値として、物理メモリ サイズやそのシステムにインストールされているコンポーネントなど様々な要素によって決定されます (詳しい確認方法は続編で)

     

    ページ プール、非ページ プールの枯渇でお悩みの方がいれば、恒久的な対策としては 64-bit のシステムを導入する事が必要だという事にお気づきになるかと思います。

     

    実は Windows Vista および Windows Server 2008 以降の Windows についてはまた異なるのですがそれはまたおいおいご紹介いたします。

     

    32-bit のシステムが現役で、64-bit のシステムや Windows Server 2008 にはすぐに移行できない!

    というのが現実ではあると思いますので、前置きが長くなりましたが、ここではこの 2つのリソースの監視方法について、紹介をさせていただきたいと思います。

     

     

    何で見るか

     

    ページ プールや 非ページ プールを監視する場合には、一般的にはパフォーマンス モニタを使います。

     

     

    何を見れば良いか

     

    パフォーマンス モニタを使用する場合には、以下のカウンタを確認します。

     

    Memory\Pool NonPaged Bytes :

    非ページ プールのサイズ (バイト単位) を測定します。

     

    Memory\Pool Paged Bytes :

    ページ プールのサイズ (バイト単位) を測定します。

     

     

    どう見れば良いか

     

    正常な状態からこれらの値を監視する事で、システムの平均的な値が確認できますので、定期的に監視をして健常性を確認する事をお勧めします。

     

    パフォーマンス状況からは、異常の可能性が高いと判断できる状況としては、以下の二つがあげられます。

     

    ・リーク (長期的な上昇傾向)

    ・スパイク (一時的な高負荷)

     

    定期的に上記カウンタ値を採取いただいて、徐々に増加を続けているような場合には、そのシステムではメモリ リークが発生している可能性があります。

     

    逆に普段増加の傾向が見られないのに、あるタイミングで急増しているような場合には、その瞬間何らかのタスクの影響で瞬間的な負荷によりシステムの健常性が保たれなくなっている可能性があります。

     

     

    どう対応すれば良いか

     

    一時的な負荷の場合には、そのタイミングで登録しているタスクを確認したり、管理ツールで行われる処理やウイルス対策ソフトでスキャンの動作が行われていないか等を確認する事で原因が追求できる場合があります。

     

    ドライバを更新した後からパフォーマンス モニタが正常時と比べて高い値を推移するようになった!

    新しく管理用のツールをインストールした後から急にシステム リソース不足のエラーが多発するようになった!

     

    といったような場合には、まずは最新版のドライバへの更新やアンインストール、更新後であればロールバックして現象が継続するかの切り分けをすることをお勧めします。

    これは動作が変更されている、もしくは既知の障害が修正されている事を期待しての対策ではありますが、初動調査としては非常に有効な切り分けではありますので、是非問題がありましたら確認してみてください。

    現象が収まった場合には、管理用ツールや更新したフィルタ ドライバが影響していると判断する事が出来ますので、モジュールの提供元へご確認いただく事で原因が判明する場合があります。

     

     

    パフォーマンス モニタだけでは特定できない場合は?

     

    ここまででご紹介しましたように、一時的な負荷や現象発生時に行われているタスクがある程度特定できるような場合は良いのですが、まったく想像もできない事が多々あります。

    そのような場合には、ページ プールや非ページ プールをだれが一番多く確保しているのかを確認する必要があります。

     

    残念ながらパフォーマンス モニタではそこまでは確認できませんので、 2 以降では確認方法も含めてより詳細な調査方法についてをご紹介させていただきたいと思います。

     

     

    ~ 第 2 回 へつづく ~ 

     

    - リソース不足について - 第 1 回(今回)

    - リソース不足について - 第 2 回

    - リソース不足について - 第 3 回

  • メモリダンプを解析する

    Windows テクノロジー サポートの永野です。

    ダンプの設定やサイズのお話をしましたので、今回は実際に解析しましょう。

     

    まずは、以下のサイトからデバッガをダウンロードして、インストールしてください。

    32bit版

    http://www.microsoft.com/whdc/devtools/debugging/installx86.mspx

    64bit版

    http://www.microsoft.com/whdc/devtools/debugging/install64bit.mspx

     

    インストールが完了したら、シンボルのありかを環境変数に登録します。

    [システムのプロパティ] - [環境変数] を開きます。

    ユーザでもシステムでも構わないので、[新規] をクリックします。

    変数名に "_NT_SYMBOL_PATH"、変数値に "SRV*c:\websymbols*http://msdl.microsoft.com/download/symbols" を登録します。

    C: ドライブに websymbols フォルダを作成してください。

     

    これで環境が整いました。早速起動しましょう。

    スタートメニューから Debugging Tools for Windows をたどって、WinDbg を選択してください。

    起動したら [File] - [Open Crash Dump] から解��対象のダンプを選択します。

    ちょっと時間がかかりますが、こんな画面が出ます。

    ここで、

        !analyze -v

    と入力してください。

    デバッガによる自動解析が始まります。

    今回解析したダンプは、こんな感じでした。

     

    1: kd> !analyze -v
    *******************************************************************************
    *                                                                             *
    *                        Bugcheck Analysis                                    *
    *                                                                             *
    *******************************************************************************

    MANUALLY_INITIATED_CRASH (e2)
    The user manually initiated this crash dump.
    Arguments:
    Arg1: 00000000
    Arg2: 00000000
    Arg3: 00000000
    Arg4: 00000000

    Debugging Details:
    ------------------


    BUGCHECK_STR:  MANUALLY_INITIATED_CRASH

    DEFAULT_BUCKET_ID:  VISTA_DRIVER_FAULT

    PROCESS_NAME:  System

    CURRENT_IRQL:  5

    LAST_CONTROL_TRANSFER:  from 8fd53c6b to 81d070e3

    STACK_TEXT: 
    805ecc40 8fd53c6b 000000e2 00000000 00000000 nt!KeBugCheckEx+0x1e
    805ecc70 8fd54174 00d54920 0026ebd8 00000000 i8042prt!I8xProcessCrashDump+0x255
    805eccb8 81c8d941 871e0280 86d54868 805ecce4 i8042prt!I8042KeyboardInterruptService+0x21e
    805eccb8 81ceeeae 871e0280 86d54868 805ecce4 nt!KiInterruptDispatch+0x51
    805ecd54 00000000 0000000e 131542b4 0d7306da nt!KiIdleLoop+0x1a


    STACK_COMMAND:  kb

    FOLLOWUP_IP:
    i8042prt!I8xProcessCrashDump+255
    8fd53c6b 83fe01          cmp     esi,1

    SYMBOL_STACK_INDEX:  1

    SYMBOL_NAME:  i8042prt!I8xProcessCrashDump+255

    FOLLOWUP_NAME:  MachineOwner

    MODULE_NAME: i8042prt

    IMAGE_NAME:  i8042prt.sys

    DEBUG_FLR_IMAGE_TIMESTAMP:  47918f5d

    FAILURE_BUCKET_ID:  MANUALLY_INITIATED_CRASH_i8042prt!I8xProcessCrashDump+255

    BUCKET_ID:  MANUALLY_INITIATED_CRASH_i8042prt!I8xProcessCrashDump+255

    Followup: MachineOwner
    ---------

     

    今回、ブルースクリーンを発生させたモジュールがサクッと表示されます。

    MODULE_NAME: i8042prt

    IMAGE_NAME:  i8042prt.sys

    ここに表示されたモジュールが犯人の可能性があります。

    モジュールをアップデートすることで、障害が起きなくなるかどうか等、試してみてはいかがでしょうか?

     

    ちなみに落ちた理由も、自動解析で表示されます。

    今回は、

    MANUALLY_INITIATED_CRASH (e2)
    The user manually initiated this crash dump.

    なので、ユーザが自ら採取したダンプであることがわかります。

    自分でダンプを採取して、遊びたい人のために次回はその方法をご紹介する予定です。

  • Hyper-V ネットワークについて理解を深める

    こんにちは、Windows テクノロジー サポートの酒井です。
    私たちサポート部門からの新しい試み、マイクロソフトの、サポート エンジニアによる、エンジニアのための Web Cast。

    5 minutes シリーズ トラブルシューティング編 の第二回目 Hyper-V ネットワークについて理解を深める を公開いたしました。

    これまで多くの Hyper-V ネットワークに関するお問い合わせをいただく中で、その大部分が ローカルエリア接続のネットワークアダプタ が増加する理由 と、それらの ネットワークアダプタの目的や意味 を正しくご理解いただけていないことから生じている問題だと感じていました。

    トラブルシューティングの形をとりながらも、これらの わかり難かった点を紐解いていく Web Cast にしようと心がけ、作成しました。

    (※) 2013/5 追記
    5 minutes シリーズでは公開を終了したため、Web Cast のみこちらに再アップロードいたしました。

    Click here to play this video



    さっそく、「わかり易いね」とか「こんなこと知らなかったよ」とお褒めのコメントをいただいており、嬉しい限りですが、それらに紛れて「確かに若いな」「前からそう思ってた」「うーん、そうかなぁ」といったコメントも ...

    この話題についてこれない方、ぜひ上記のリンクから Web Cast をご覧いただき、その後に私の自己紹介を読んでみてください。


    Web Cast 連動型 Blog となっています (笑)


    さて、Web Cast 連動型だと宣言しましたので、ここでは Web Cast をご覧いただいたことを前提として、 Web Cast でご紹介しきれなかった点を補足 したいと思います。

    今回の Web Cast では時間の関係上、もっとも実運用環境で採用される可能性の高い Hyper-V 外部ネットワーク についてのみを取り上げる形での説明となりましたが、Hyper-V のネットワーク構成には、この他にも 内部ネットワーク  と プライベートネットワーク があります。

    これらについても、ローカルエリア接続のネットワーク アダプタ構成が変化し、誤解が生じやすくなっている点は同じですので、Web Cast 内でご紹介している Hyper-V ネットワークの (簡略化して、わかり易いと自負する) アーキテクチャ図で、各種ネットワーク構成時の図を作成してみました。

    ローカルエリア接続のネットワークアダプタとして見える箇所を、赤い点線の丸で示しています。
    (イメージをクリックすると大きなイメージでご確認いただけます)


    Hyper-V ネットワーク未構成時




    Hyper-V プライベート ネットワーク構成時




    Hyper-V 内部ネットワーク構成時




    Hyper-V 外部ネットワーク構成時


    Web Cast では、締めくくりとして Hyper-V ネットワークを構成した後の各ローカルエリア接続が持つ用途や目的を理解し、不要な仮想 NIC を見つけて、それらを無効化することを提案しました。これにより、Hyper-V ネットワークを構成する上での自由度は飛躍的に向上します。 

    ところで、Windows Server 2008 R2 RC 版の Hyper-V をお試しいただいている方はいらっしゃいますでしょうか。実は、新しい Hyper-V Manager では UI 上から Hyper-V の仮想 NIC を無効化出来るようになっています。ユーザーの皆様がお困りになっている点を私たちサポートが吸い上げ、製品に反映させることも出来るんです。もっともっとこの流れが出来れば良いですね。

    また、私は、ごくごく普通にサポート案件の担当者としてユーザーの皆様と対峙させていただいています。実際に多くのユーザーの皆様がお困りになられている点を拾い上げ、Web Cast を通じて、事前に注意を促すという流れも作っていきたいと思います。私たちサポート部門が Web Cast を作る大きな意味でもあります。実用的でかゆい所に手が届く技術情報を発信していけるよう頑張ります。

    これからもよろしくお願いします!

  • SCVMM DebugView ログ トレースについて

    こんにちは。

    Windows テクノロジー サポートの大羽です。

     

    SCVMM(Sytem Center Virtual Machine Manager)ネタについても記載して

    いきたいと思います。

     

    製品についてご存知ない方は、以下のサイトをご確認ください。

     

    SCVMM Technet Home

    http://technet.microsoft.com/ja-jp/scvmm/default.aspx

     

     

    SCVMM Hyper-V VMware の統合管理や P2V など、仮想環境における

    様々な機能が盛り込まれた製品です。

     

    OS 上の様々なコンポーネントを利用して、多くの機能を実現しているわけ

    ですが、高機能だけにトラブルが発生したときは大変です。

     

    そんなトラブルが発生したときに、どのようなツールが使えるのか、という

    テーマで記載したいと思います。

     

    今回は DebugView を利用したトレースを採取する方法です。

    英語版の手順は、以下のサイトにありますが、何故か日本語で説明している

    サイトが見受けられないので、記載しておきます。

     

    How to collect SCVMM traces

    http://blogs.technet.com/chengw/archive/2008/05/08/how-to-collect-scvmm-traces.aspx

     

    DebugView は以下のサイトからダウンロードいただけます。

     

    DebugView for Windows v4.76

    http://technet.microsoft.com/en-us/sysinternals/bb896647.aspx

     

     

    事前準備

    ----------

    1. 以下のコードを Text ファイルに記述し、ファイル名を "odsflags.cmd"

       変更します。

     

    @echo off

    echo ODS control flags - only trace with set flags will go to ODS

     

    if (%1)==() goto :HELP

    if (%1)==(-?) goto :HELP

    if (%1)==(/?) goto :HELP

     

    echo Setting flag to %1...

    reg ADD "HKLM\SOFTWARE\Microsoft\Windows NT\CurrentVersion\Tracing\Microsoft\Carmine" /v ODSFLAGS /t REG_DWORD /d %1 /f

    echo Done.

    goto :EXIT

     

    :HELP

    echo Usage: odsflags [flag], where flag is

    echo TRACE_ERROR = 0x2,

    echo TRACE_DBG_NORMAL = 0x4,

    echo TRACE_DBG_VERBOSE = 0x8,

    echo TRACE_PERF = 0x10,

    echo TRACE_TEST_INFO = 0x20,

    echo TRACE_TEST_WARNING = 0x40,

    echo TRACE_TEST_ERROR = 0x80,

     

    :EXIT

     

    2. 以下のコードを Text ファイルに記述し、ファイル名を "odson.reg"

       変更します。

     

    Windows Registry Editor Version 5.00

     

    [HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows NT\CurrentVersion\Tracing\Microsoft\Carmine]

    "ODS"=dword:00000001

     

    3. 以下のコードを Text ファイルに記述し、ファイル名を "odsoff.reg"

       変更します。

     

    Windows Registry Editor Version 5.00

     

    [HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows NT\CurrentVersion\Tracing\Microsoft\Carmine]

    "ODS"=dword:00000000

     

    上記作成したファイルを、SCVMM ホスト上の任意のフォルダに纏めてコピー

    します。

    これで準備完了です。

     

     

    DebugView 採取手順

    ----------------------

    さて、それでは情報を収集してみましょう。

    ※管理者権限で実施してください。

     

    1. SCVMM ホスト上でコマンド プロンプトを起動します。

    2. コマンド プロンプト上で、先ほどコピーした "odson.reg" を実行します。

    3. 同じくプロンプト上で、先ほどコピーした "odsflags.cmd 255" を実行します。

    4. DebugView を起動します。

    5. [Capture] メニュー内の "Capture Win32" "Capture Global Win32"

       両方の項目にチェックをいれます。

     

    これでトレース開始です。

    虫めがねボタンで起動・停止の制御ができます。

     

    採取を終了するときは、ツールを停止してコマンドプロンプトから"odsoff.reg"

    実行します。

    レジストリの Tracing フラグがオフになり、トレースが終了します。

     

    で、どんな情報が採取できるかと言いますと、こんな感じです。

     

    DebugView ログ

    ------------------

    [3788] 0ECC.0C68::05/15-11:50:38.759#04:WsmanAPIWrapper.cs(492): HostSessionCache: elements for [S-1-5-18-MSCS.test.microsoft.com]: [15]

    [3788] 0ECC.0C68::05/15-11:50:38.790#04:WsmanAPIWrapper.cs(906): WSMAN: URL: [http://MSCS.test.microsoft.com:80] Verb: [GET],  resource: [http://schemas.microsoft.com/wbem/wsman/1/wmi/root/virtualization/Msvm_VirtualSystemGlobalSettingData?InstanceID=Microsoft:F658FDFE-752E-4414-B98D-A967D3391429\Global]

    [3788] 0ECC.0C68::05/15-11:50:38.790#04:WsmanAPIWrapper.cs(492): HostSessionCache: elements for [S-1-5-18-MSCS.test.microsoft.com]: [15]

    [3788] 0ECC.0C68::05/15-11:50:38.790#26:PerfRefresher.cs(375): Getting VM perf counters for C:\ProgramData\Microsoft\Windows\Hyper-V\test2\Virtual Machines\F658FDFE-752E-4414-B98D-A967D3391429.xml = 0 , 0,0, 0,0 

    [3788] 0ECC.0C68::05/15-11:50:38.790#21:EventManager.cs(100): PublishUpdateForPerfData 5cdacb70-0254-44ce-93a9-52578025c374

    [3788] 0ECC.0C68::05/15-11:50:38.805#20:ObjectAuthorizationManager.cs(94): Accessibile=True, Profile=Administrator, Object Type=VM, ID=5cdacb70-0254-44ce-93a9-52578025c374

    [3788] 0ECC.0C68::05/15-11:50:38.805#21:EventClientConnection.cs(142): Publish uuid:558d8ef6-0811-4f0d-9aab-8fa195f9f88b;id=4 VM Update

    [3788] 0ECC.0C68::05/15-11:50:38.805#04:tieredPerfCounters.cs(380): GetNextTierDatapoint: Average value for the next tier: 0 [tier: 7]

    [3788] 0ECC.0C68::05/15-11:50:38.805#18:PlacementHelpers.cs(140): PlacementHelpers: ScaleProcessorUtilization, CPU util [0]

    [3788] 0ECC.0C68::05/15-11:50:38.805#18:PlacementHelpers.cs(344): GetHostRatings: GetSourceProcessorWorkload, looking up processor []

    [3788] 0ECC.0C68::05/15-11:50:38.805#18:PlacementHelpers.cs(789): GetHostRatings: GetProcessorConfiguration, Manufacturer: Intel, Model: [Pentium 4], Physical ProcessorCount: [1], Logical ProcessorCount: [4], Cores per Processor: [4], L2CacheSize: [12288] KB, L3CacheSize: [0] KB, Speed: [2833] Mhz, Bus Speed: [1333] Mhz

    [3788] 0ECC.0C68::05/15-11:50:38.805#18:PlacementHelpers.cs(344): GetHostRatings: GetSourceProcessorWorkload, looking up processor [359c1234-add2-4e7f-92da-f1fa384c2f5a]

    [3788] 0ECC.0C68::05/15-11:50:38.805#18:PlacementHelpers.cs(161): PlacementHelpers: ScaleProcessorUtilization, CPU orig: [0], CPU target: [0] (raw value was [0])

    [3788] 0ECC.0C68::05/15-11:50:38.805#04:tieredPerfCounters.cs(380): GetNextTierDatapoint: Average value for the next tier: 0 [tier: 7]

    [3788] 0ECC.0C68::05/15-11:50:38.805#04:tieredPerfCounters.cs(380): GetNextTierDatapoint: Average value for the next tier: 0 [tier: 7]

    [3788] 0ECC.0C68::05/15-11:50:38.805#04:tieredPerfCounters.cs(380): GetNextTierDatapoint: Average value for the next tier: 0 [tier: 7]

    [3788] 0ECC.0C68::05/15-11:50:38.805#04:tieredPerfCounters.cs(380): GetNextTierDatapoint: Average value for the next tier: 0 [tier: 7]

    [3788] 0ECC.0C68::05/15-11:50:38.805#21:EventManager.cs(94): PublishUpdate 5cdacb25-0254-44ce-93a9-52578025c374

    [3788] 0ECC.0C68::05/15-11:50:38.805#20:ObjectAuthorizationManager.cs(94): Accessibile=True, Profile=Administrator, Object Type=TieredPerfData, ID=5cdacb25-0254-44ce-93a9-52578025c374

    [3788] 0ECC.0C68::05/15-11:50:38.805#21:EventClientConnection.cs(142): Publish uuid:558d8ef6-0811-4f0d-9aab-8fa195f9f88b;id=4 TieredPerfData Update

    [3788] 0ECC.0C68::05/15-11:50:38.805#04:CarmineObjectLock.cs(158): CarmineObjectLock, Task b1f8526d-0a67-4813-8a76-3ae9735f8278 Releasing Read lock on OperatingSystem object with ID fd1b1d5a-8ce9-41f2-9d1d-33655579157c|TaskID=B1F8526D-0A67-4813-8A76-3AE9735F8278

    [3788] 0ECC.0C68::05/15-11:50:38.805#04:CarmineObjectLock.cs(106): CarmineObjectLock, Non Running Task b1f8526d-0a67-4813-8a76-3ae9735f8278 requested  lock on VM object with ID 81ff6bb9-66a2-46c5-80cd-8d9cf78d8ba7|TaskID=B1F8526D-0A67-4813-8A76-3AE9735F8278

    [3788] 0ECC.0C68::05/15-11:50:38.805#14:WLCDBAccessHelper.cs(94): Reading object 81ff6bb9-66a2-46c5-80cd-8d9cf78d8ba7 of type VM

    [3788] 0ECC.0C68::05/15-11:50:38.805#14:ImgLibOM.cs(66): VM object test3 instanciated with ID 81ff6bb9-66a2-46c5-80cd-8d9cf78d8ba7 lock NoLock|TaskID=B1F8526D-0A67-4813-8A76-3AE9735F8278

    [3788] 0ECC.0C68::05/15-11:50:38.805#04:CarmineObjectLock.cs(106): CarmineObjectLock, Non Running Task b1f8526d-0a67-4813-8a76-3ae9735f8278 requested  lock on VMHost object with ID 3f6a0784-712c-46d9-9e32-5a8ad96549a2|TaskID=B1F8526D-0A67-4813-8A76-3AE9735F8278

    [3788] 0ECC.0C68::05/15-11:50:38.805#20:UserRoleAuthorizationHelper.cs(163): Get: Running SP prc_ADHC_HostDisk_GetByHost

    [3788] 0ECC.0C68::05/15-11:50:38.805#09:HostDisk.cs(239): Retrieved all HostDisk rows for serverID=3f6a0784-712c-46d9-9e32-5a8ad96549a2, serverType=VMHost

    [3788] 0ECC.0C68::05/15-11:50:38.805#20:UserRoleAuthorizationHelper.cs(163): Get: Running SP prc_ADHC_HostVolume_GetByHost

    [3788] 0ECC.0C68::05/15-11:50:38.805#09:HostVolume.cs(254): Retrieved all HostVolume rows for hostID=3f6a0784-712c-46d9-9e32-5a8ad96549a2

    [3788] 0ECC.0C68::05/15-11:50:38.805#04:CarmineObjectLock.cs(106): CarmineObjectLock, Non Running Task b1f8526d-0a67-4813-8a76-3ae9735f8278 requested  lock on VirtualDVDDrive object with ID ef58abae-ea2b-4952-ba68-7109ebdf11cb|TaskID=B1F8526D-0A67-4813-8A76-3AE9735F8278

    [3788] 0ECC.0C68::05/15-11:50:38.805#14:WLCDBAccessHelper.cs(94): Reading object ef58abae-ea2b-4952-ba68-7109ebdf11cb of type VirtualDVDDrive

    [3788] 0ECC.0C68::05/15-11:50:38.805#14:ImgLibOM.cs(66): VirtualDVDDrive object test3 instanciated with ID ef58abae-ea2b-4952-ba68-7109ebdf11cb lock NoLock|TaskID=B1F8526D-0A67-4813-8A76-3AE9735F8278

    [3788] 0ECC.0C68::05/15-11:50:38.805#04:CarmineObjectLock.cs(106): CarmineObjectLock, Non Running Task b1f8526d-0a67-4813-8a76-3ae9735f8278 requested  lock on VirtualFloppyDrive object with ID 14424183-912a-4757-8bf5-1a06a257e605|TaskID=B1F8526D-0A67-4813-8A76-3AE9735F8278

    [3788] 0ECC.0C68::05/15-11:50:38.805#14:WLCDBAccessHelper.cs(94): Reading object 14424183-912a-4757-8bf5-1a06a257e605 of type VirtualFloppyDrive

    [3788] 0ECC.0C68::05/15-11:50:38.805#14:ImgLibOM.cs(66): VirtualFloppyDrive object test3 instanciated with ID 14424183-912a-4757-8bf5-1a06a257e605 lock NoLock|TaskID=B1F8526D-0A67-4813-8A76-3AE9735F8278

    [3788] 0ECC.0C68::05/15-11:50:38.805#04:CarmineObjectLock.cs(106): CarmineObjectLock, Non Running Task b1f8526d-0a67-4813-8a76-3ae9735f8278 requested  lock on VirtualNetworkAdapter object with ID e22adf44-568e-43c2-bd04-6e88b5e0887e|TaskID=B1F8526D-0A67-4813-8A76-3AE9735F8278

    [3788] 0ECC.0C68::05/15-11:50:38.805#14:WLCDBAccessHelper.cs(94): Reading object e22adf44-568e-43c2-bd04-6e88b5e0887e of type VirtualNetworkAdapter

    [3788] 0ECC.0C68::05/15-11:50:38.805#14:ImgLibOM.cs(66): VirtualNetworkAdapter object test3 instanciated with ID e22adf44-568e-43c2-bd04-6e88b5e0887e lock NoLock|TaskID=B1F8526D-0A67-4813-8A76-3AE9735F8278

    [3788] 0ECC.0C68::05/15-11:50:38.805#04:CarmineObjectLock.cs(106): CarmineObjectLock, Non Running Task b1f8526d-0a67-4813-8a76-3ae9735f8278 requested  lock on VirtualDiskDrive object with ID e666a5aa-497e-4f4d-acf9-081a929350e8|TaskID=B1F8526D-0A67-4813-8A76-3AE9735F8278

    [3788] 0ECC.0C68::05/15-11:50:38.805#14:WLCDBAccessHelper.cs(94): Reading object e666a5aa-497e-4f4d-acf9-081a929350e8 of type VirtualDiskDrive

    [3788] 0ECC.0C68::05/15-11:50:38.805#14:ImgLibOM.cs(66): VirtualDiskDrive object test3 instanciated with ID e666a5aa-497e-4f4d-acf9-081a929350e8 lock NoLock|TaskID=B1F8526D-0A67-4813-8A76-3AE9735F8278

    [3788] 0ECC.0C68::05/15-11:50:38.805#04:CarmineObjectLock.cs(106): CarmineObjectLock, Non Running Task b1f8526d-0a67-4813-8a76-3ae9735f8278 requested  lock on VirtualHardDisk object with ID 62badfa7-9fdb-4302-90a5-24f27f7b3d40|TaskID=B1F8526D-0A67-4813-8A76-3AE9735F8278

    [3788] 0ECC.0C68::05/15-11:50:38.821#14:WLCDBAccessHelper.cs(94): Reading object 62badfa7-9fdb-4302-90a5-24f27f7b3d40 of type VirtualHardDisk

    [3788] 0ECC.0EF0::05/15-11:50:38.821#21:EventClientConnection.cs(239): Server session uuid:558d8ef6-0811-4f0d-9aab-8fa195f9f88b;id=4 - Sending 2 events

    [3788] 0ECC.0C68::05/15-11:50:38.821#14:ImgLibOM.cs(66): VirtualHardDisk object test3_disk_1 instanciated with ID 62badfa7-9fdb-4302-90a5-24f27f7b3d40 lock NoLock|TaskID=B1F8526D-0A67-4813-8A76-3AE9735F8278

    [3788] 0ECC.0C68::05/15-11:50:38.821#04:CarmineObjectLock.cs(106): CarmineObjectLock, Non Running Task b1f8526d-0a67-4813-8a76-3ae9735f8278 requested  lock on VMHost object with ID 3f6a0784-712c-46d9-9e32-5a8ad96549a2|TaskID=B1F8526D-0A67-4813-8A76-3AE9735F8278

                                  

                                   

     

    こんなログが気が遠くなるくらい延々と出力されます。

     

    ログの採取を開始してから現象を再現させ、少し深呼吸します。

     

    それから一気にそれらしいキーワードを探していくわけです。

     

    具体的な事例については、また改めてブログに記載したいと思います。

    まずはツールで色々と流れを見てみま��ょう。