All Articles

Magical WinDbg VOL.1【6 章 プロセスダンプからユーザモードアプリケーションのメモリリーク事象を調査する】

4 章と 5 章では、アプリケーションクラッシュダンプやフルメモリダンプから、プロセスやシステムがクラッシュした原因を調査しました。

ここまでの章で確認した通り、ダンプファイルの作成時には通常、クラッシュの原因となった例外の情報が含まれます。

そのため、!analyze -v などのコマンドによってダンプ生成時の例外情報を参照することで、クラッシュが発生した直接の原因(例外)を特定することは比較的容易です。

しかし、クラッシュ以外の問題の原因をダンプファイルから調査する場合には、ダンプファイル作成時に収集される例外発生時の情報が調査の役に立たなくなるため、少々解析の難易度が上がります。

6 章と 7 章では、クラッシュ以外の問題の発生をダンプファイルから調査する例として、ユーザモードアプリケーションのメモリリーク事象を使用します。

本章では、メモリリーク事象を引き起こしているアプリケーションのプロセスダンプの解析を行います。

もくじ

メモリリーク事象の再現

まずは、解析対象のプロセスダンプを取得するためにメモリリーク事象を発生させましょう。

前章までと同じく、D4C.exe を使用して問題を再現します。

D4C.exe を起動し、最初のメニューで 2 を入力してメモリリーク事象の再現を開始します。

D4C.exe でユーザモードメモリリーク事象の再現

実行が始まると、D4C.exe のプロセスのプライベートなメモリが次々と割り当てられ、プロセスの仮想メモリ1領域がリークしていきます。

アプリケーションの仮想メモリ領域が肥大化すると、最終的には RDP 接続がブラックアウトして切断されたり、システム操作やデスクトップ GUI の描画が遅延するなど深刻な問題が発生する場合があります。

ちなみに、D4C.exe の実行後にプロセスの仮想メモリがリークしていく様子は、Sysinternals に含まれる Process Explorer を使用することで確認できます。

また、システム全体で割り当てられた仮想メモリが増大している様子は、タスクマネージャを使用することで確認できます。

以下は、実際にユーザモードのメモリリーク事象を再現しているタイミングで Process Explorer とタスクマネージャを起動した際の画面キャプチャです。

ユーザモードメモリリーク事象発生時のメモリリソース

Process Explorer では、D4C.exe 行の [Private Bytes] 列のサイズが時間とともに増大していく様子を確認できます。

また、タスクマネージャの [パフォーマンス] タブでも、コミット済みの仮想メモリのサイズが増大していることを確認できます。

なお、プロセスのメモリ消費量については、Process Explorer やタスクマネージャ以外にも、リソースモニターや VMMap、Process Hacker など様々なツールで調べることが可能です。

そのため、メモリリークが疑われる状況の場合には、環境や好みに合わせて好きなツールを使用すると良いでしょう。

プロセスダンプを取得する

D4C.exe を使用してアプリケーションのメモリリーク事象を再現できたので、次は解析用のプロセスダンプの取得を行います。

メモリリークのようなアプリケーションクラッシュを伴わない問題の場合は、4 章のように自動的にアプリケーションクラッシュダンプが生成されません。

そのため、問題が発生しているタイミングで任意のツールを使用してプロセスのダンプファイルを取得する必要があります。

プロセスのダンプファイルを取得できるツールはいくつもありますが、本書では Sysinternals に含まれる Process Explorer と Procdump を使用します。

まずは Process Explorer を使用してダンプファイルを取得します。

先ほどプロセスのメモリ使用量を調査した場合と同じく、管理者権限で Process Explorer を起動します。

続いて、プロセスの一覧から D4C.exe の行を右クリックし、[Create Dump]>[Create Full Dump…] をクリックします。

Process Explorer を使用してプロセスダンプを取得

するとファイルエクスプローラのウインドウが起動するので、任意のフォルダにダンプファイルを保存してください。

プロセスのフルダンプ取得に成功した場合、指定のフォルダ内に Process Explorer の [Private Bytes] 列で確認したプロセスのメモリサイズとほぼ同等のサイズのダンプファイルが生成されます。

Process Explorer でダンプファイルを取得した場合、D4C.exe のアプリケーションは終了されないため、[Ctrl+C] キーを使用して手動でアプリケーションを終了します。

これで解析用のプロセスダンプを取得できましたが、同等のダンプファイルは Procdump を使用することでも取得できます。

Procdump の使用方法は非常に簡単です。

D4C.exe のプロセスダンプを取得する場合、管理者権限で起動したコマンドプロンプトで以下のコマンドを実行します。

procdump.exe -ma -w D4C.exe

上記のコマンドを実行すると、カレントフォルダにプロセスダンプが生成されます。

-ma オプションでは、取得するダンプの種類をフルダンプに指定しています。

また、-w オプションでは、ダンプファイルを取得するプロセス名を指定します。

本書では使用しませんが、Procdump を使用してアプリケーションのプロセスダンプを取得する場合は、アプリケーションハングの発生や、CPU やメモリサイズのしきい値など、プロセスダンプの取得条件を細かく定義できます。

そのため、問題の再現条件がタイミングが不明な場合には、Procdump を使用して任意の条件でプロセスダンプを取得することで、問題の調査に必要なダンプファイルをスムーズに取得できます。

Procdump のオプション一覧については公開情報の記載を参照してください。


ProcDump:

https://learn.microsoft.com/ja-jp/sysinternals/downloads/procdump


プロセスダンプの例外コードを調べる

解析用のプロセスダンプを取得できたので、メモリリーク事象の調査を始めていきます。

4 章と同じく WinDbg にプロセスダンプをロードし、例外コードを調べるところから解析を始めていきます。

使用するダンプファイルは Process Explorer と Procdump どちらで取得したものでも構いません。

以下の通り、どちらの方法で取得したプロセスダンプも .exr -1 コマンドで取得できる例外情報は同じです。

# Process Explorer で取得したプロセスダンプの例外コード
0:000> .exr -1
ExceptionAddress: 0000000000000000
   ExceptionCode: 80000003 (Break instruction exception)
  ExceptionFlags: 00000000
NumberParameters: 0

# Procdump で取得したプロセスダンプの例外コード
0:000> .exr -1
ExceptionAddress: 0000000000000000
   ExceptionCode: 80000003 (Break instruction exception)
  ExceptionFlags: 00000000
NumberParameters: 0

ここで、取得したプロセスダンプに記録されている例外コードが 0x80000003 であることがわかります。

公式ドキュメント2の記載を参照すると、この例外コードはブレークポイントの検出に関するものであることがわかります。

また、.exr -1 コマンドの出力結果にも Break instruction exception と記載されている通り、この例外はブレークポイントに関連していることがわかります。

しかし、当然ですが D4C.exe にはブレークポイントはハードコードされていません。

つまり、この例外はダンプファイルを生成するために Process Explorer や Procdump が強制的に引き起こしたものであると判断できます。

このように、クラッシュを伴わない問題の調査をするためにダンプファイルを生成する場合、ツールが意図的に例外を発生させます。

そのため、今回のメモリリーク事象のような、クラッシュを伴わない問題をダンプファイルを解析する場合には、 .exr -1!analyze -v で取得できる例外情報は役に立たなくなることに注意が必要です。

ダンプファイルからメモリリーク事象を調査する前の準備

では、ダンプファイルの例外情報が役に立たない場合、どのように解析を進めていけばよいでしょうか。

一般的に、ダンプファイルの取得前にある程度問題の原因箇所を絞りこんでおくことが重要です。

例えば、今回の場合だとダンプファイルを解析する前に、 Process Explorer やタスクマネージャ、またはリソースモニターなどによってすでに D4C.exe のメモリリークが発生していることを特定済みであることを前提としています。

また、ダンプファイルの解析を行う前には、D4C.exe のプロセスに割り当てられたメモリ領域のうち、具体的にどの領域が肥大化しているのかを特定しておくとよいでしょう。

ユーザモードプロセスの仮想アドレス領域に割り当てられた各セクションについては、Sysinternals の VMMap を使用することで以下のように分類されていることを確認できます。3

  • Image
  • Mapped File
  • Shareable
  • Heap
  • Managed Heap
  • Stack
  • Private Data

Image 領域は実行可能なイメージなどをマッピングするために割り当てられています。

また、Mapped File 領域はメモリにマッピングされたデータファイル用に割り当てられた領域です。

Shareable 領域には、Image 領域や Mapped File 領域にマッピングされなかった共有可能なメモリが割り当てられます。

Heap 領域はこのプロセスの所有するヒープ用のメモリ領域です。(Managed Heap は CLR によって割り当てられる領域なので、.Net を使用しないプロセスの場合には何も表示されません。)

一般にユーザモードアプリケーションのメモリリークが発生する場合、この Heap 領域のサイズが増大します。

そして、Stack 領域はプロセス内の各実行スレッドが持つスタック用の領域であり、Private Data 領域はスタックとヒープ以外のメモリ割り当てに使用されます。

以下は、VMMap でアプリケーションのメモリリークが発生する前の状態の D4C.exe プロセスの情報を参照した結果です。

VMMap で起動直後のプロセスを調査

2 番のメニューを選択してアプリケーションのメモリリーク事象を再現した後に VMMap の表示を更新すると、以下のようにプロセスのメモリ空間の中で Heap 領域(オレンジの領域)が大きく増大していることを確認できます。

VMMap でメモリリーク事象発生後のプロセスを調査

また、WinDbg でダンプファイルからプロセスのメモリ使用状況を確認する必要がある場合は、!address 拡張機能を使用できます。

!address コマンドの出力結果

上記のように、!address コマンドの出力結果からも、プロセス内で非常に多くのヒープ領域が確保されていることがわかります。

ちなみに、!address コマンドの出力結果は非常に多いので、統計情報を収集できる !address -summary コマンドを使用するとより簡単に調査を行うことができます。

!address -summary コマンドの出力結果

このように、プロセスダンプをロードした WinDbg で !address -summary コマンドを実行することでも、プロセス内で割り当てられた Heap 領域が肥大化している状況を確認できます。

これで、D4C.exe のメモリリーク事象は Heap 領域の肥大化が原因で発生している可能ことを特定できました。

プロセスダンプから Heap 領域を調査する

前項で、D4C.exe のメモリリーク事象の原因は、ユーザモードプロセス内の Heap 領域の肥大化であることを確認しました。

Windows システムで稼働するアプリケーションはヒープマネージャと呼ばれるコンポーネントによって管理されており、一般的に Windows API の HeapCreate 関数4や HeapAlloc 関数5を使用してヒープの作成や割り当てを行います。6

WinDbg でアプリケーションのプロセスダンプからヒープ領域の解析を行う場合には、!heap 拡張機能7を使用できます。

今回取得したメモリリーク事象発生時のプロセスダンプを WinDbg にロードし、!heap コマンドを実行したところ、以下のように 3 つの NT Heap がプロセス内に存在していることを確認できます。

0:000> !heap
        Heap Address      NT/Segment Heap
         1f1adb90000              NT Heap
         1f1ada70000              NT Heap
         1f1adf50000              NT Heap

NT Heap は Windows のアプリケーションで既定で使用されるヒープです。

Windows アプリケーションが使用するヒープには NT Heap の他に Windows 10 / Windows Server 2016 から追加されたセグメントヒープがあります8が、本書ではセグメントヒープは使用しないため、以降のヒープについてはすべて NT Heap を指すものとします。

!heap コマンドによってプロセス内に 3 つのヒープが存在することを確認できたので、次は -S オプションを使用して各ヒープの概要情報を表示します。

!heap -S コマンドでヒープの概要情報を表示

!heap -S コマンドの出力結果を見ると、3 つのヒープのうち 0x1f1adb90000 のヒープのサイズが非常に大きくなっており、このヒープが肥大化していることがわかります。

また、異なる観点での情報を得るため !heap -a コマンドを実行してみます。

!heap -a コマンドでヒープのセグメント情報を表示

!heap -a コマンドを実行してみると、!heap -S コマンドで確認した 0x1f1adb90000 のヒープに 84 個のセグメントが存在していることを確認できます。(Segment at から始まる行が 1 つのセグメントと対応します)

Windows システムでは、NT Heap は ntdll!_HEAP 構造体によって管理されます。9

プロセスダンプをロードした WinDbg で dt ntdll!_HEAP コマンドを実行して ntdll!_HEAP 構造体の情報を参照してみます。

0:000> dt ntdll!_HEAP
  +0x000 Segment          : _HEAP_SEGMENT
  +0x000 Entry            : _HEAP_ENTRY
  +0x010 SegmentSignature : Uint4B
  +0x014 SegmentFlags     : Uint4B
  +0x018 SegmentListEntry : _LIST_ENTRY
  +0x028 Heap             : Ptr64 _HEAP
  +0x030 BaseAddress      : Ptr64 Void
  +0x038 NumberOfPages    : Uint4B
  +0x040 FirstEntry       : Ptr64 _HEAP_ENTRY
  +0x048 LastValidEntry   : Ptr64 _HEAP_ENTRY
{{ 省略 }}

上記のように、ntdll!_HEAP 構造体は ntdll!_HEAP_SEGMENT 構造体と ntdll!_HEAP_ENTRY 構造体から始まっています。

さらに、ntdll!_HEAP_SEGMENT 構造体と ntdll!_HEAP_ENTRY 構造体の情報を参照してみます。

# ntdll!_HEAP_SEGMENT の構造体情報をダンプ
0:000> dt ntdll!_HEAP_SEGMENT
 +0x000 Entry            : _HEAP_ENTRY
 +0x010 SegmentSignature : Uint4B
 +0x014 SegmentFlags     : Uint4B
 +0x018 SegmentListEntry : _LIST_ENTRY
 +0x028 Heap             : Ptr64 _HEAP
 +0x030 BaseAddress      : Ptr64 Void
 +0x038 NumberOfPages    : Uint4B
 +0x040 FirstEntry       : Ptr64 _HEAP_ENTRY
 +0x048 LastValidEntry   : Ptr64 _HEAP_ENTRY
 +0x050 NumberOfUnCommittedPages : Uint4B
 +0x054 NumberOfUnCommittedRanges : Uint4B
 +0x058 SegmentAllocatorBackTraceIndex : Uint2B
 +0x05a Reserved         : Uint2B
 +0x060 UCRSegmentList   : _LIST_ENTRY

# ntdll!_HEAP_ENTRY の構造体情報をダンプ
0:000> dt ntdll!_HEAP_ENTRY 
 +0x000 UnpackedEntry    : _HEAP_UNPACKED_ENTRY
 +0x000 PreviousBlockPrivateData : Ptr64 Void
 +0x008 Size             : Uint2B
 +0x00a Flags            : UChar
 +0x00b SmallTagIndex    : UChar
 +0x008 SubSegmentCode   : Uint4B
 +0x00c PreviousSize     : Uint2B
 +0x00e SegmentOffset    : UChar
 +0x00e LFHFlags         : UChar
 +0x00f UnusedBytes      : UChar
 +0x008 CompactHeader    : Uint8B
 +0x000 ExtendedEntry    : _HEAP_EXTENDED_ENTRY
 +0x000 Reserved         : Ptr64 Void
 +0x008 FunctionIndex    : Uint2B
 +0x00a ContextValue     : Uint2B
 +0x008 InterceptorValue : Uint4B
 +0x00c UnusedBytesLength : Uint2B
 +0x00e EntryOffset      : UChar
 +0x00f ExtendedBlockSignature : UChar
 +0x000 ReservedForAlignment : Ptr64 Void
 +0x008 Code1            : Uint4B
 +0x00c Code2            : Uint2B
 +0x00e Code3            : UChar
 +0x00f Code4            : UChar
 +0x00c Code234          : Uint4B
 +0x008 AgregateCode     : Uint8B

上記の情報から、ntdll!_HEAP 構造体は ntdll!_HEAP_ENTRY 構造体を含む ntdll!_HEAP_SEGMENT 構造体から構成されていることがわかります。

Windows のバージョンが XP 以下の場合は、ntdll!_HEAP_ENTRY 構造体の Size の値を 8 倍したアドレスを加算していくことでプロセス内の特定のヒープセグメント内の ntdll!_HEAP_ENTRY 構造体を辿ることができます。10

しかし、Vista 以降のバージョンでは ASLR によるプロセスヒープのランダム化が行われているため、この方法は使用できません。11

そのため、ヒープセグメント内の ntdll!_HEAP_ENTRY 構造体を辿るためには、!heap 拡張機能を使用します。

まずは、今回肥大化が発生しているヒープのアドレスである 0x1f1adb90000 を指定し、!heap -a 0x1f1adb90000 コマンドによってこのヒープ内の情報を取得しました。(ヒープの ID を使用して !heap -a 1 コマンドを実行することでも同等の出力を得られます。)

このコマンドの出力結果は非常に多いので、必要に応じて .logopen コマンドによるファイルへの出力設定を実施しておくと良いでしょう。(.logopen コマンドについては本書の「付録A: WinDbg の Tips」に記載しています。)

実際にプロセスダンプをロードした WinDbg で !heap -a 0x1f1adb90000 コマンドを実行してみると、このヒープ内の 84 個のヒープセグメントと、その中のヒープエントリを列挙することができました。

以下は、84 番目のヒープセグメントとその中のヒープエントリに関する出力結果です。

# 84 番目のヒープセグメントとその中のヒープエントリに関する出力結果のみ抜粋
Segment83 at fbec0000:
  Flags:           00000000
  Base:            1f1fbec0000
  First Entry:     fbec0070
  Last Entry:      1f1fce8f000
  Total Pages:     00000fcf
  Total UnCommit:  00000b5b
  Largest UnCommit:00000000
  UnCommitted Ranges: (1)

Heap entries for Segment83 in Heap 000001f1adb90000
  address: psize . size  flags   state (requested size)
  000001f1fbec0000: 00000 . 00070 [101] - busy (6f)
  000001f1fbec0070: 00070 . 41f90 [101] - busy (41f80) Internal 
  000001f1fbf02000: 41f90 . 42010 [101] - busy (41ff0) Internal 
  000001f1fbf44010: 42010 . 41ff0 [101] - busy (41fe0) Internal 
  000001f1fbf86000: 41ff0 . 42010 [101] - busy (41ff0) Internal 
  000001f1fbfc8010: 42010 . 41ff0 [101] - busy (41fe0) Internal 
  000001f1fc00a000: 41ff0 . 42010 [101] - busy (41ff0) Internal 
  000001f1fc04c010: 42010 . 00400 [101] - busy (3f0) Internal 
  000001f1fc04c410: 00400 . 41bf0 [101] - busy (41be0) Internal 
  000001f1fc08e000: 41bf0 . 42010 [101] - busy (41ff0) Internal 
  000001f1fc0d0010: 42010 . 41ff0 [101] - busy (41fe0) Internal 
  000001f1fc112000: 41ff0 . 42010 [101] - busy (41ff0) Internal 
  000001f1fc154010: 42010 . 41ff0 [101] - busy (41fe0) Internal 
  000001f1fc196000: 41ff0 . 42010 [101] - busy (41ff0) Internal 
  000001f1fc1d8010: 42010 . 41ff0 [101] - busy (41fe0) Internal 
  000001f1fc21a000: 41ff0 . 42010 [101] - busy (41ff0) Internal 
  000001f1fc25c010: 42010 . 41ff0 [101] - busy (41fe0) Internal 
  000001f1fc29e000: 41ff0 . 42010 [101] - busy (41ff0) Internal 
  000001f1fc2e0010: 42010 . 41ff0 [101] - busy (41fe0) Internal 
  000001f1fc322000: 41ff0 . 11fc0 [100]
  000001f1fc333fc0: 11fc0 . 00040 [111] - busy (3d)
  000001f1fc334000:      00b5b000      - uncommitted bytes.

プログラムがプロセスが割り当てたヒープに情報を書き込む場合、書き込まれたデータは、各ヒープエントリのヘッダ以降のメモリ領域に記録されます。12

実際に、!heap -a 0x1f1adb90000 コマンドで特定したいくつかのヒープエントリのアドレスを指定して 0x100 程度のメモリをダンプしてみると、以下のように ==> Allocated addr: <Address> という文字列が各ヒープエントリに書き込まれていることを特定できます。

ヒープエントリのアドレスのメモリ情報をダンプ

メモリリークの原因箇所を特定する

ダンプファイルから割り当てられたヒープ領域の解析を行った結果、==> Allocated addr: <Address> という文字列が格納されたヒープ領域が解放されていないためにメモリリークが発生している可能性が高いことを特定しました。

メモリリークのような問題は、よほど断続的にメモリの割り当てが発生していない限り、ダンプファイルの採取時のコールスタックに情報が記録されることは稀です。

そのため、基本的にはダンプファイルの解析よりも、ライブデバッグやソースコードの参照、またはアプリケーションのリバースエンジニアリングによる解析を行う方が効率的な場合が多いです。

ただし、本書ではできる限りダンプファイルの解析を通してメモリリークの発生原因となる処理を特定していきます。

まず、WinDbg でプロセスダンプファイルをロードした状態で k コマンドを実行してスタックバックトレースを出力してみます。

0:000> k
 # Child-SP          RetAddr               Call Site
00 0000003d`d1eff6e8 00007ffa`382d30ce     ntdll!NtWaitForSingleObject+0x14
01 0000003d`d1eff6f0 00007ff6`dfe213b9     KERNELBASE!WaitForSingleObjectEx+0x8e
02 0000003d`d1eff790 00007ff6`dfe21a40     D4C+0x13b9
03 0000003d`d1effa50 00007ffa`38b17344     D4C+0x1a40
04 0000003d`d1effa90 00007ffa`3a9c26b1     kernel32!BaseThreadInitThunk+0x14
05 0000003d`d1effac0 00000000`00000000     ntdll!RtlUserThreadStart+0x21

残念ながら、ヒープの割り当てに使用される HeapAlloc 関数などの呼び出しはスタックバックトレースには記録されていませんでした。

しかし、4 章や 5 章では扱いませんでしたが、一般的なアプリケーションの多くはマルチスレッドで実行されています。

WinDbg にプロセスダンプをロードした状態で k コマンドを実行した際に取得できる情報は、プロセスのメインスレッドのスタックバックトレースのみですので、念のため他のスレッドのスタックバックトレースも調査してみましょう。

ユーザモードプロセス内で稼働するスレッドは !threads 拡張機能13を使用することで列挙できます。

!threads コマンドの実行結果

今回の解析対象のプロセスダンプをロードした状態で !threads コマンドを実行すると、上記のようにメインスレッド(ID:0 のスレッド)に加えて、2 つのスレッドが作成されていることを確認できます。(!threads コマンド実行時に No export threads found が表示される場合は、一度 !analyze -v コマンドを実行してみてください)

現在のプロセスコンテキストで稼働するすべてのスレッドのスタックバックトレースを参照したい場合、~*k コマンドを使用します。

また、~1k~2k のように、特定のスレッドのインデックスを指定することも可能です。

さらに、特定のスレッドのインデックスを指定して ~1s~2s コマンドを実行することで、現在のスレッドコンテキストを変更することも可能です。

つまり、~1s; k コマンドを実行することでも、~1k コマンドと同じく、インデックスが 1 のスレッドのスタックバックトレースを参照することが可能です。


~s (現在のスレッドの設定):

https://learn.microsoft.com/ja-jp/windows-hardware/drivers/debugger/-s—set-current-thread-


今回は ~*k コマンドによってすべてのスレッドのスタックバックトレースをまとめて出力してみます。

0:000> ~*k

.  0  Id: 159c.10d4 Suspend: 0 Teb: 0000003d`d1ce8000 Unfrozen
 # Child-SP          RetAddr               Call Site
00 0000003d`d1eff6e8 00007ffa`382d30ce     ntdll!NtWaitForSingleObject+0x14
01 0000003d`d1eff6f0 00007ff6`dfe213b9     KERNELBASE!WaitForSingleObjectEx+0x8e
02 0000003d`d1eff790 00007ff6`dfe21a40     D4C+0x13b9
03 0000003d`d1effa50 00007ffa`38b17344     D4C+0x1a40
04 0000003d`d1effa90 00007ffa`3a9c26b1     kernel32!BaseThreadInitThunk+0x14
05 0000003d`d1effac0 00000000`00000000     ntdll!RtlUserThreadStart+0x21

   1  Id: 159c.2390 Suspend: 0 Teb: 0000003d`d1cf0000 Unfrozen
 # Child-SP          RetAddr               Call Site
00 0000003d`d22fe838 00007ffa`382fb4ee     ntdll!NtDelayExecution+0x14
01 0000003d`d22fe840 00007ff6`dfe21680     KERNELBASE!SleepEx+0x9e
02 0000003d`d22fe8e0 00007ffa`38b17344     D4C+0x1680
03 0000003d`d22ff930 00007ffa`3a9c26b1     kernel32!BaseThreadInitThunk+0x14
04 0000003d`d22ff960 00000000`00000000     ntdll!RtlUserThreadStart+0x21

   2  Id: 159c.1018 Suspend: 0 Teb: 0000003d`d1cf2000 Unfrozen
 # Child-SP          RetAddr               Call Site
00 0000003d`d23fea68 00007ffa`382fb4ee     ntdll!NtDelayExecution+0x14
01 0000003d`d23fea70 00007ff6`dfe21680     KERNELBASE!SleepEx+0x9e
02 0000003d`d23feb10 00007ffa`38b17344     D4C+0x1680
03 0000003d`d23ffb60 00007ffa`3a9c26b1     kernel32!BaseThreadInitThunk+0x14
04 0000003d`d23ffb90 00000000`00000000     ntdll!RtlUserThreadStart+0x21

上記の出力結果から、インデックスが 1 と 2 のスレッドがそれぞれ同じように D4C+0x1680 から KERNELBASE!SleepEx 関数を呼び出していることがわかります。

しかし、このままではどのスレッドから解析を進めるべきかを決められません。

そのため、少し違うアプローチで各スレッドの情報を調査してみましょう。

WinDbg では !runaway 拡張機能14を使用することで各スレッドによって消費された時間に関する情報を取得できます。

今回取得したダンプファイルをロードした WinDbg で !runaway 7 コマンドを実行してみると以下の出力を得られます。(7 は、!runaway 拡張機能を使用してユーザモードで消費した時間、およびカーネルモードで消費した時間、そして各スレッドが作成されてから経過した時間のすべての情報を出力するためのオプションフラグです)

0:000> !runaway 7

User Mode Time
Thread       Time
  1:2390     0 days 0:00:27.031
  2:1018     0 days 0:00:11.093
  0:10d4     0 days 0:00:00.000

Kernel Mode Time
Thread       Time
  1:2390     0 days 0:01:38.703
  2:1018     0 days 0:00:01.703
  0:10d4     0 days 0:00:00.000

Elapsed Time
Thread       Time
  0:10d4     0 days 0:30:53.547
  1:2390     0 days 0:30:45.242
  2:1018     0 days 0:30:45.242

上記の !runaway 7 コマンドの出力結果を参照すると、インデックス 1 のスレッドが極端に多くのカーネル時間を消費していることがわかります。

一般に、メモリリークなどのシステムパフォーマンスに関わる問題は、より多くのシステムリソースを消費しているスレッド(=より多くの実行時間を消費しているスレッド)の動作に起因していることが多いです。

また、ヒープの割り当てなど、メモリの操作に関わる処理は基本的にカーネルモードで実行されます。

そのため、より多くのカーネル時間を消費しているインデックス 1 のスレッドが問題の原因である可能性が高いため、優先的に調査を実施していくことにします。

ちなみに、プロセス内で稼働するスレッドの数や実行時間については、WinDbg を使用しなくても Process Explorer などのツールから調査することが可能です。

Process Explorer を使用する場合は、ダンプファイルを取得した際と同じく管理者権限で Process Explorer を起動し、D4C.exe のプロセスを右クリックします。

そして、[Properties..] をクリックした後 [Threads] タブを開くことで、以下のようにプロセス内で稼働するスレッドの情報を参照できます。

Process Explorer でスレッドの情報を参照する

各スレッドが実行している処理を解析する

ここまでの調査では、D4C.exe のメモリリーク事象について以下の情報を特定することができました。

  • D4C.exe のプロセスのヒープ領域が肥大化している
  • 大量に確保されたまま解放されていないヒープエントリのメモリ内には、==> Allocated addr: <Address> という文字列が書き込まれている
  • D4C.exe のプロセス内では 3 つのスレッドが稼働しており、特にインデックス 1 のスレッドが極端にカーネルモードでの実行時間を消費している

ここから、実際にプロセスのヒープ領域を肥大化させてメモリリークを引き起こしている処理を特定していきます。

しかし、これまでに行ったクラッシュ事象の解析とは異なり、ユーザが任意のタイミングで取得したダンプファイルには、都合よく問題を引き起こす処理の実行に関する情報が記録されているとは限りません。

これは、ダンプファイルに含まれる情報は、あくまでダンプファイル採取時点のメモリの情報に過ぎないためです。

このような場合にヒープ領域への書き込みを行う処理を特定するためには、ライブデバッグやソースコードの解析を行うか、4 章や 5 章で使用した Ghidra などのデコンパイラを使用する方が効果的です。

ヒープ領域への書き込みを行う処理を特定する方法は複数考えられますが、本書では以下のアプローチで解析を進めていくことにします。

  1. アプリケーションのデータ領域の中から、==> Allocated addr: という文字列がハードコードされているオフセットを特定する。
  2. デコンパイラを使用して [1.] で特定したオフセットのデータを参照しているコードを特定することで、==> Allocated addr: <Address> という文字列をメモリに書き込んでいる処理を特定する。

ここまでの項で確認した通り、今回割り当てられているヒープ領域のメモリ内には ==> Allocated addr: <Address> という文字列が書き込まれておりますが、==> Allocated addr: の部分はどのヒープ領域でも不変でした。

つまり、プログラムで難読化が行われていない限り、==> Allocated addr: というテキストがプログラム内にハードコードされている可能性が高いと推察できます。

プログラムにハードコードされたテキストなどのデータは通常、実行プロセスの中の .rdata 領域(読み取り専用の初期化データ)に展開されます。15

そのため、まずはプロセスダンプファイルをロードしている WinDbg で .rdata 領域をスキャンして ==> Allocated addr: というテキストがハードコードされてるアドレスを特定していきます。

.rdata 領域をスキャンするためには対象のアドレスを特定する必要があるので、まずは !dh -s コマンドを使用して D4C.exe のセクションヘッダの情報を表示しましょう。

0:000> !dh -s !D4C

SECTION HEADER #1
 .text name
  15EC virtual size
  1000 virtual address
  1600 size of raw data
   400 file pointer to raw data
     0 file pointer to relocation table
     0 file pointer to line numbers
     0 number of relocations
     0 number of line numbers
60000020 flags
       Code
       (no align specified)
       Execute Read

SECTION HEADER #2
.rdata name
  343A virtual size
  3000 virtual address
  3600 size of raw data
  1A00 file pointer to raw data
     0 file pointer to relocation table
     0 file pointer to line numbers
     0 number of relocations
     0 number of line numbers
40000040 flags
       Initialized Data
       (no align specified)
       Read Only

{{ 省略 }}

SECTION HEADER #3
 .data name
   638 virtual size
  7000 virtual address
   200 size of raw data
  5000 file pointer to raw data
     0 file pointer to relocation table
     0 file pointer to line numbers
     0 number of relocations
     0 number of line numbers
C0000040 flags
       Initialized Data
       (no align specified)
       Read Write

{{ 省略 }}

今回のプロセスダンプをロードしている WinDbg で !dh -s !D4C コマンドを実行したところ、上記の通り .rdata セクションの virtual address が 0x3000 であり、アライメントされたサイズが 0x3600 であることがわかりました。

つまり、このプロセスダンプの .rdata セクションは !D4C+0x3000(D4C.exe のイメージベースアドレスに 0x3000 を加算したアドレス) から 0x3600 バイト分の範囲に存在していると判断できます。

.rdata セクションのアドレス範囲を特定できたので、次は s コマンドを使用して指定のアドレス範囲からテキストを検索してみます。16

s コマンドを使用して指定のアドレス範囲から ASCII テキストを検索する場合、s -a <検索開始アドレス> L<検索するサイズ> "<検索する ASCII テキスト>" を実行します。 (-a オプションは、検索対象が ASCII 文字列であることを指定しています。Unicode 文字列を検索したい場合には -u オプションを使用します。)

D4C.exe のプロセス内の .rdata セクションから ==> Allocated addr: というテキストを検索する場合は、s -a !D4C+0x3000 L0x3600 "==> Allocated addr:" を実行します。

実際にこのコマンドを実行してみたところ、以下のように 0x7ff6dfe236b0 のアドレスに該当の文字列が定義されていることを確認できました。

0:000> s -a !D4C+0x3000 L0x3600 "==> Allocated addr:" 
00007ff6`dfe236b0  3d 3d 3e 20 41 6c 6c 6f-63 61 74 65 64 20 61 64  ==> Allocated ad

上記の s コマンドの出力結果からは定義されているテキストの全文を参照できませんでしたので、da コマンドを使用して指定のアドレスに定義されているテキストを表示してみます。17

0:000> da 00007ff6dfe236b0
00007ff6`dfe236b0  "==> Allocated addr: 0x%08x."

これで、上記の通り、0x7ff6dfe236b0 のアドレスに ==> Allocated addr: 0x%08x. というテキストがハードコードされていることを確認できました。

最後に、このテキストがハードコードされている相対仮想アドレス(RVA)を特定します。

このテキストがハードコードされているアドレス 0x7ff6dfe236b0 から D4C.exe のイメージベースアドレスを引くことで、RVA を特定することが可能です。

0:000> ? 0x7ff6dfe236b0 - !D4C
Evaluate expression: 14000 = 00000000`000036b0

上記コマンドでアドレスを計算した結果、対象のテキストが定義されている RVA は 0x36b0 であることを特定できました。

==> Allocated addr: という文字列がハードコードされているオフセットを特定できたので、続けて Ghidra デコンパイラを使用し、このテキストをヒープ領域に書き込む処理を特定します。

4 章や 5 章と同じ手順で Ghidra を起動して D4C.exe をロードしたら、キーボードの [g] を押して GoTo ウインドウを起動します。

続いて、D4C.exe を Ghidra にロードしたときの既定のイメージベースアドレス 0x140000000 に、先ほど確認したオフセット 0x36b0 を加算した値を入力し、[OK] をクリックします。

Ghidra の GoTo ウインドウで指定のアドレスにジャンプする

これでアドレス 0x1400036b0 にジャンプし、==> Allocated addr: 0x%08x. というテキストがハードコードされていることを Ghidra 上でも確認することができました。

なお、Ghidra の Listing ウインドウでアドレス 0x1400036b0 のテキストを参照してみると、右側に XREF[1]: FUN_1400015a0:14000161d(*) と表示されていることを確認できます。

これは、このデータを参照しているコードのアドレスを指しています。

Ghidra で XREF[1]: FUN_1400015a0:14000161d(*) の表示をダブルクリックしてみると、以下のように 0x1400036b0 のテキストをロードしているアドレス 0x14000161d にジャンプできます。

ヒープへの書き込みを行う処理を特定する

このアドレスの前後の処理を Ghidra でデコンパイルした結果、以下のような疑似コードを得ることができました。

while( true ) {
   _Dst = (char *)malloc((longlong)(int)param_1);
   if (_Dst == (char *)0x0) break;
      printf("Count: %d\n",(ulonglong)uVar2,param_3,param_4);

   param_4 = (ulonglong)_Dst & 0xffffffff;
   _SizeInBytes = (ulonglong)(int)(param_1 - 1)

   pcVar3 = "==> Allocated addr: 0x%08x\n";
   FUN_140001540(local_1030,_SizeInBytes,"==> Allocated addr: 0x%08x\n",param_4);

   printf(&DAT_1400036cc,local_1030,pcVar3,param_4);
   printf("==> Total allocated size: 0x%08x\n",(ulonglong)uVar1,pcVar3,param_4);

   param_3 = local_1030;
   strcpy_s(_Dst,_SizeInBytes,param_3);

   if (0x1fffffff < (int)uVar1) {
      printf("==> Slow Down...\n",_SizeInBytes,param_3,param_4);
      Sleep(1000);
   }

   uVar2 = uVar2 + 1;
   uVar1 = uVar1 + param_1;
}

この疑似コードを解析すると、while によるループ処理の中で malloc 関数によって確保されたヒープ領域に strcpy_s 関数で書き込みを行う処理を繰り返し行っているにも関わらず、確保したヒープを解放する処理が定義されていないことがわかります。

これで、D4C.exe のユーザモードメモリリークが発生していた原因箇所を特定することができました。

6 章のまとめ

本章では、クラッシュを伴わない問題の原因をダンプファイルから調査する例として、ユーザモードアプリケーションのメモリリーク事象の解析を行いました。

本書の最後の章となる 7 章では、本章で調査したものと同じメモリリーク事象をシステムのフルメモリダンプから調査していきます。

一括りに「ダンプファイル」といっても、ユーザモードプロセスのダンプとシステムのフルメモリダンプでは解析手法や調査のアプローチが大きく変わります。

4 章や 5 章で扱ったクラッシュダンプの解析と比較すると少々難解に思えるかもしれませんが、このような問題の調査はダンプファイル解析の醍醐味の一つかと思いますので、ぜひ最後まで楽しんでお読みいただければ幸いです。

各章へのリンク


  1. 仮想メモリと物理メモリ https://learn.microsoft.com/ja-jp/windows-hardware/drivers/debugger/virtual-and-physical-memory

  2. バグ チェック 0x8E:KERNEL_MODE_EXCEPTION_NOT_HANDLED https://learn.microsoft.com/ja-jp/windows-hardware/drivers/debugger/bug-check-0x8e—kernel-mode-exception-not-handled

  3. インサイド Windows 第 7 版 上 P.402 (Pavel Yosifovich, Alex Ionescu, Mark E. Russinovich, David A. Solomon 著 / 山内 和朗 訳 / 日系 BP 社 / 2018 年)

  4. HeapCreate 関数 https://learn.microsoft.com/ja-jp/windows/win32/api/heapapi/nf-heapapi-heapcreate

  5. HeapAlloc 関数 https://learn.microsoft.com/ja-jp/windows/win32/api/heapapi/nf-heapapi-heapalloc

  6. インサイド Windows 第 7 版 上 P.366 (Pavel Yosifovich, Alex Ionescu, Mark E. Russinovich, David A. Solomon 著 / 山内 和朗 訳 / 日系 BP 社 / 2018 年)

  7. !heap 拡張機能 https://learn.microsoft.com/ja-jp/windows-hardware/drivers/debugger/-heap

  8. インサイド Windows 第 7 版 上 P.368 (Pavel Yosifovich, Alex Ionescu, Mark E. Russinovich, David A. Solomon 著 / 山内 和朗 訳 / 日系 BP 社 / 2018 年)

  9. インサイド Windows 第 7 版 上 P.372 (Pavel Yosifovich, Alex Ionescu, Mark E. Russinovich, David A. Solomon 著 / 山内 和朗 訳 / 日系 BP 社 / 2018 年)

  10. Advanced Windows Debugging 1st Edition P.276 (Mario Hewardt, Daniel Pravat 著 / Addison-Wesley Professional / 2007 年)

  11. インサイド Windows 第 7 版 上 P.406 (Pavel Yosifovich, Alex Ionescu, Mark E. Russinovich, David A. Solomon 著 / 山内 和朗 訳 / 日系 BP 社 / 2018 年)

  12. Windows ダンプの極意 エラーが発生したら、まずダンプ解析! P.120 (上原 祥市 著 / アスキーメディアワークス / 2008 年)

  13. !threads 拡張機能 https://learn.microsoft.com/ja-jp/windows-hardware/drivers/debugger/-thread

  14. !runaway 拡張機能 https://learn.microsoft.com/ja-jp/windows-hardware/drivers/debugger/-runaway

  15. PE 形式 https://learn.microsoft.com/ja-jp/windows/win32/debug/pe-format

  16. s メモリの検索 https://learn.microsoft.com/ja-jp/windows-hardware/drivers/debugger/s—search-memory-

  17. d、da、db、dc、dd、dD、df、dp、dq、du、dw ディスプレイメモリ https://learn.microsoft.com/ja-jp/windows-hardware/drivers/debugger/d—da—db—dc—dd—dd—df—dp—dq—du—dw—dw—dyb—dyd—display-memor