Driver Verifier によるメモリーリークのデバッグ方法について

皆様、既に 2 月ですが明けましておめでとうございます！

I沢です。今年もよろしくお願いいたします。

 

今回の記事はドライバーのメモリーリークがテーマです。

時間の経過とともに少しずつメモリー使用量が増えていく…でもなにが要因となっているかわからない…ドライバーのソースコードを眺めてもただ時間が過ぎるだけ…

 

そんなときにはこれ！Driver Verifier！

私共もメモリー関連のお問い合わせをよくいただくのですが、大抵の場合、最初の原因切り分けのために、こちらのツールをご案内します。

それだけ強力なツールですので、過去にも本ブログで 「ドライバー検証ツール」 や 「特別なプール (Special Pool)」 といった内容でご案内しておりますが、

今回はメモリーリークのデバッグに焦点を当ててご案内しております。

 

メモリーリークを発生させよう！

 

Driver Verifier の効果を確認しようにも、メモリーリークのためのドライバーを実装して…となるともうこの記事を読む気が無くなりますよね。

こんなこともあろうかと Microsoft SysInternals では NotMyfault というツールを公開しております。

こちらのツールを使用することで簡単に BSoD を発生させることもできるため、特定のタイミングでのメモリダンプを取得する際に使用された方もいらっしゃるかもしれません。

まずは以下の URL からツールをダウンロードをしましょう。

https://download.sysinternals.com/files/NotMyFault.zip

ダウンロードが完了したら、zip ファイルを展開してください。

展開したフォルダの直下に x86、x64 というフォルダがあり、それぞれ NotMyfault.exe と myfault.sys という二つのファイルが確認できると思います。

メモリーリークを起こしたい環境の CPU アーキテクチャに合わせてこれら二つのファイルを同じフォルダにいれたままターゲットマシンに持っていきましょう。

今回私は Windows 8.1 x86 環境にて確認いたしますので、x86 フォルダに格納されているファイルを使用します。

 

二つのファイルをターゲットマシンにコピーできましたら、おもむろに NotMyFault.exe をダブルクリックしましょう。

以下のようなダイアログが出てきましたね？

 

 

今回はメモリーリークが目的ですので、表示されているダイアログの [Leak タブ] を選択しましょう。

 

 

後は [Leak Paged] をクリックすれば Paged Pool を、 [Leak Nonpaged] をクリックすれば Nonpaged Pool を Leak/Second に指定した速度でリークさせることが可能です！

 

Driver Verifier を有効にしよう！

 

実際にメモリーリークさせる前に Driver Verifier の設定を行いましょう。

C:\Windows\System32 フォルダにある verifier.exe をダブルクリックします。

次のようなダイアログが表示されると思いますので、 「カスタム設定を作成する(コード開発者用)」 を選択し [次へ(N)] をクリックします。

 

 

 今回はリークしている Pool を確認したいので、 「プールのトラック」 を選択して、 [次へ(N)] をクリックします。

 

 

引き続き検証したいドライバーを選択します。

今回は 「一覧からドライバ―を選択する(U)」 を選択して、NotMyfault のドライバーである myfault.sys を検証ドライバーとして選択しておりますが、もし原因のドライバーが特定できていない状況であれば、 「このコンピューターにインストールされているドライバーを全て自動的に選択する(A)」 を選択することで、検証対象を全てのドライバーにすることが可能です。

 

 

 

最後に再起動を促されます。再起動すれば設定完了なのですが、いつものように Windbg を用いてカーネルデバッガーを接続しておきましょう。

Windbg の接続方法やシンボルの設定方法についての説明はここでは割愛いたします。

 

 

 

デバッグしよう！

 

それでは接続した Windbg からデバッグしてみましょう。

今回 Windbg で使用するコマンドは !verifier のみです！簡単ですね。

 

!verifier

https://msdn.microsoft.com/ja-jp/library/ff565591(v=vs.85).aspx

 

まずは、Driver Verifier の設定を確認します。"!verifier 3" を実行してみましょう。

いろいろ出てきますが、"Pool tracking" が有効であること、Driver Verification List に myfault.sys が表示されることを確認しましょう。

 

kd> !verifier 3   Verify Flags Level 0x00000008     STANDARD FLAGS:     [X] (0x00000000) Automatic Checks     [ ] (0x00000001) Special pool     [ ] (0x00000002) Force IRQL checking     [X] (0x00000008) Pool tracking     [ ] (0x00000010) I/O verification     [ ] (0x00000020) Deadlock detection     [ ] (0x00000080) DMA checking     [ ] (0x00000100) Security checks     [ ] (0x00000800) Miscellaneous checks     [ ] (0x00020000) DDI compliance checking     ADDITIONAL FLAGS:     [ ] (0x00000004) Randomized low resources simulation     [ ] (0x00000200) Force pending I/O requests     [ ] (0x00000400) IRP logging     [ ] (0x00002000) Invariant MDL checking for stack     [ ] (0x00004000) Invariant MDL checking for driver     [ ] (0x00008000) Power framework delay fuzzing     [ ] (0x00040000) Systematic low resources simulation     [ ] (0x00080000) DDI compliance checking (additional)     [ ] (0x00200000) NDIS/WIFI verification     [ ] (0x00800000) Kernel synchronization delay fuzzing     [ ] (0x01000000) VM switch verification       [X] Indicates flag is enabled     Summary of All Verifier Statistics     RaiseIrqls 0x0   AcquireSpinLocks 0x0   Synch Executions 0x0   Trims 0x0     Pool Allocations Attempted 0x0   Pool Allocations Succeeded 0x0   Pool Allocations Succeeded SpecialPool 0x0   Pool Allocations With NO TAG 0x0   Pool Allocations Failed 0x0     Current paged pool allocations 0x0 for 00000000 bytes   Peak paged pool allocations 0x0 for 00000000 bytes   Current nonpaged pool allocations 0x0 for 00000000 bytes   Peak nonpaged pool allocations 0x0 for 00000000 bytes   Driver Verification List ------------------------     MODULE: 0x80225ba8 myfault.sys (Hasn't loaded)

 

上記のように myfault.sys (Hasn't loaded) と表示される場合は、まだ myfault.sys がシステム上にロードされていません。

NotMyfault.exe を実行することでドライバーがロードされ myfault.sys (Loaded) と表示されドライバーが保持している Pool 情報が表示されるようになります。

 

kd> !verifier 3 <--- 省略 ---> Driver Verification List   ------------------------     MODULE: 0x80225ba8 myfault.sys (Loaded)       Pool Allocation Statistics: ( NonPagedPool / PagedPool )         Current Pool Allocations: ( 0x00000000 / 0x00000000 )       Current Pool Bytes: ( 0x00000000 / 0x00000000 )       Peak Pool Allocations: ( 0x00000000 / 0x00000001 )       Peak Pool Bytes: ( 0x00000000 / 0x00000078 )       Contiguous Memory Bytes: 0x00000000       Peak Contiguous Memory Bytes: 0x00000000       Contiguous allocations are not displayed with public symbols.

 

さて、いよいよメモリーリークさせてみましょう。[Leak Paged] をクリックするとリークが始まりますので…

 

 

[Stop Paged] をクリックして適当なタイミングでリークを止めましょう。ここでは Paged Pool 1000 KB を 10 回リークさせたところで止めました。

 

 

この状態で、もう一度 "!verifier 3" を実行します…すると "Leak" というタグ付きの 1000 KB バイトの Paged Pool が確かに 10 回確保されていることが確認できます。

 

kd> !verifier 3 <--- 省略 ---> Summary of All Verifier Statistics     RaiseIrqls 0x0   AcquireSpinLocks 0x0   Synch Executions 0x0   Trims 0x0     Pool Allocations Attempted 0xb   Pool Allocations Succeeded 0xb   Pool Allocations Succeeded SpecialPool 0xa   Pool Allocations With NO TAG 0x1   Pool Allocations Failed 0x0     Current paged pool allocations 0xa for 009CE000 bytes   Peak paged pool allocations 0xa for 009CE000 bytes   Current nonpaged pool allocations 0x0 for 00000000 bytes   Peak nonpaged pool allocations 0x0 for 00000000 bytes   Driver Verification List ------------------------     MODULE: 0x80225b28 myfault.sys (Loaded)       Pool Allocation Statistics: ( NonPagedPool / PagedPool )         Current Pool Allocations: ( 0x00000000 / 0x0000000a )       Current Pool Bytes: ( 0x00000000 / 0x009ce000 )       Peak Pool Allocations: ( 0x00000000 / 0x0000000a )       Peak Pool Bytes: ( 0x00000000 / 0x009ce000 )       Contiguous Memory Bytes: 0x00000000       Peak Contiguous Memory Bytes: 0x00000000       Pool Allocations:         Address Length Tag Caller          ---------- ---------- ---- ----------       0x9d2fb000 0x000fb000 Leak 0x98726659 myfault!PoolLeak+0x21       0x9d200000 0x000fb000 Leak 0x98726659 myfault!PoolLeak+0x21       0x9d0fb000 0x000fb000 Leak 0x98726659 myfault!PoolLeak+0x21       0x9d000000 0x000fb000 Leak 0x98726659 myfault!PoolLeak+0x21       0x9cefb000 0x000fb000 Leak 0x98726659 myfault!PoolLeak+0x21       0x9ce00000 0x000fb000 Leak 0x98726659 myfault!PoolLeak+0x21       0x9ccfb000 0x000fb000 Leak 0x98726659 myfault!PoolLeak+0x21       0x9cc00000 0x000fb000 Leak 0x98726659 myfault!PoolLeak+0x21       0x9cafb000 0x000fb000 Leak 0x98726659 myfault!PoolLeak+0x21       0x9ca00000 0x000fb000 Leak 0x98726659 myfault!PoolLeak+0x21       Contiguous allocations are not displayed with public symbols.

 

さらに "!verifier 80 0x9d2fb000" を実行してみましょう。0x9d2fb000 は確保されている Pool のアドレスの 1 つです。

 

kd> !verifier 80 0x9d2fb000   Log of recent kernel pool Allocate and Free operations:   There are up to 0x10000 entries in the log.   Parsing 0x00010000 log entries, searching for address 0x9d2fb000.     ====================================================================== Pool block 9d2fb000, Size 000fa000, Thread 98090300 81530238 nt!XdvExAllocatePoolInternal+0x17 8152718e nt!VerifierExAllocatePoolWithTag+0x24 98726659 myfault!PoolLeak+0x21 98726ab3 myfault!MyfaultDeviceControl+0x13f 98726b26 myfault!MyfaultDispatch+0x5c 815258f3 nt!IovCallDriver+0x82 810d3a52 nt!IofCallDriver+0x62 812e765e nt!IopSynchronousServiceTail+0x16e 812ea318 nt!IopXxxControlFile+0x3e8 812e9f22 nt!NtDeviceIoControlFile+0x2a 81186377 nt!KiSystemServicePostCall+0 Parsed entry 00010000/00010000... Finished parsing all pool tracking information.

 

なんと対象アドレスの Pool がどのように確保されたかコールスタックを表示してくれるんですね…

ここで NotMyfault.exe を終了させてみましょう。これで確保された Pool は解放されたはずです。

そしてもう一度、"!verifier 80 0x9d2fb000" を実行すると…

 

kd> !verifier 80 0x9d2fb000   Log of recent kernel pool Allocate and Free operations:   There are up to 0x10000 entries in the log.   Parsing 0x00010000 log entries, searching for address 0x9d2fb000.     ====================================================================== Pool block 9d2fb000, Size 000fb000, Thread 980cd040 8124fbd1 nt!ExFreePoolWithTag+0x7b1 81527241 nt!VerifierExFreePoolWithTag+0x3e 987266bb myfault!FreePoolLeak+0x33 815258f3 nt!IovCallDriver+0x82 810d3a52 nt!IofCallDriver+0x62 812e4174 nt!IopDeleteFile+0xf4 812ee7f9 nt!ObpRemoveObjectRoutine+0x43 810d549b nt!ObfDereferenceObjectWithTag+0x6b 8134d51d nt!ExSweepHandleTable+0x95 8134d2cc nt!ObKillProcess+0x28 8134cb82 nt!PspRundownSingleProcess+0xf2 8130627a nt!PspExitThread+0x456 813a7efc nt!KiSchedulerApcTerminate+0x1a ====================================================================== Pool block 9d2fb000, Size 000fa000, Thread 98090300 81530238 nt!XdvExAllocatePoolInternal+0x17 8152718e nt!VerifierExAllocatePoolWithTag+0x24 98726659 myfault!PoolLeak+0x21 98726ab3 myfault!MyfaultDeviceControl+0x13f 98726b26 myfault!MyfaultDispatch+0x5c 815258f3 nt!IovCallDriver+0x82 810d3a52 nt!IofCallDriver+0x62 812e765e nt!IopSynchronousServiceTail+0x16e 812ea318 nt!IopXxxControlFile+0x3e8 812e9f22 nt!NtDeviceIoControlFile+0x2a 81186377 nt!KiSystemServicePostCall+0 Parsed entry 00010000/00010000... Finished parsing all pool tracking information.

 

今度は Pool が解放された時のコールスタックも表示されるようになりました！

つまり "!verifier 80 <Pool Address>" コマンドを使用することで、対象 Pool の操作履歴が確認できるわけですね！

 

以上の手順で、対象ドライバーがどこでどのように Pool を確保 / 解放しているかがわかります。

今回の場合では、myfault ドライバーの MyfaultDispatch 関数から PoolLeak 関数までの Pool 確保の流れと、FreePoolLeak 関数が呼ばれるタイミングあたりが確認ポイントとなります。

この情報があれば、具体的にドライバーのソースコードのどこを確認すればよいか非常に明確になりますよね。

直接のリークの原因の解析はまた別途ソースコードの確認が必要かと思いますが、一次切り分けツールとしては非常に強力です。

もし、ドライバーのメモリー関連でお悩みの方がいらっしゃいましたら、まずは Driver Verifier をお試しいただくのがよいかと思います。

 

ではでは！