メモリ破壊のデバッグ誰が僕のスタックに『2』と書いたんだ？
数週間前、IL2CPPスクリプト・バックエンドを使用するとゲームがクラッシュするというバグ報告を顧客から受けました。QAはそのバグを検証し、修正のために私に割り当てた。このプロジェクトはかなり大きなもので、（最大規模のものには程遠いが）私のマシンで構築するのに40分かかった。バグレポートにはこう書かれていた："クラッシュするまで5〜10分間ゲームをプレイする"。案の定、指示に従った後、クラッシュを確認した。WinDbgを立ち上げ、釘を刺す準備をした。残念ながら、スタック・トレースはインチキだった：
0:049> k
# Child-SP RetAddr Call Site
00 00000022`e25feb10 00000000`00000010 0x00007ffa`00000102
0:050> u 0x00007ffa`00000102 L10
00007ffa`00000102 ?? ???
^ Memory access error in 'u 0x00007ffa`00000102 l10'明らかに、無効なメモリーアドレスを実行しようとしたのだ。スタック・トレースは破損していたが、破損したのはスタック全体の一部だけで、スタック・ポインタ・レジスタより先のメモリ内容を見れば再構築できるはずだと期待していた。案の定、次にどこを見ればいいのか見当がついた：
0:049> dps @rsp L200
...............
00000022`e25febd8 00007ffa`b1fdc65c ucrtbased!heap_alloc_dbg+0x1c [d:\th\minkernel\crts\ucrt\src\appcrt\heap\debug_heap.cpp @ 447]
00000022`e25febe0 00000000`00000004
00000022`e25febe8 00000022`00000001
00000022`e25febf0 00000022`00000000
00000022`e25febf8 00000000`00000000
00000022`e25fec00 00000022`e25fec30
00000022`e25fec08 00007ffa`99b3d3ab UnityPlayer!std::_Vector_alloc<std::_Vec_base_types<il2cpp::os::PollRequest,std::allocator<il2cpp::os::PollRequest> > >::_Get_data+0x2b [ c:\program files (x86)\microsoft visual studio 14.0\vc\include\vector @ 642]
00000022`e25fec10 00000022`e25ff458
00000022`e25fec18 cccccccc`cccccccc
00000022`e25fec20 cccccccc`cccccccc
00000022`e25fec28 00007ffa`b1fdf54c ucrtbased!_calloc_dbg+0x6c [d:\th\minkernel\crts\ucrt\src\appcrt\heap\debug_heap.cpp @ 511]
00000022`e25fec30 00000000`00000010
00000022`e25fec38 00007ffa`00000001
...............
00000022`e25fec58 00000000`00000010
00000022`e25fec60 00000022`e25feca0
00000022`e25fec68 00007ffa`b1fdb69e ucrtbased!calloc+0x2e [d:\th\minkernel\crts\ucrt\src\appcrt\heap\calloc.cpp @ 25]
00000022`e25fec70 00000000`00000001
00000022`e25fec78 00000000`00000010
00000022`e25fec80 cccccccc`00000001
00000022`e25fec88 00000000`00000000
00000022`e25fec90 00000022`00000000
00000022`e25fec98 cccccccc`cccccccc
00000022`e25feca0 00000022`e25ff3f0
00000022`e25feca8 00007ffa`99b3b646 UnityPlayer!il2cpp::os::SocketImpl::Poll+0x66 [ c:\users\tautvydas\builds\bin2\il2cppoutputproject\il2cpp\libil2cpp\os\win32\socketimpl.cpp @ 1429]
00000022`e25fecb0 00000000`00000001
00000022`e25fecb8 00000000`00000010
...............
00000022`e25ff3f0 00000022`e25ff420
00000022`e25ff3f8 00007ffa`99c1caf4 UnityPlayer!il2cpp::os::Socket::Poll+0x44 [ c:\users\tautvydas\builds\bin2\il2cppoutputproject\il2cpp\libil2cpp\os\socket.cpp @ 324]
00000022`e25ff400 00000022`e25ff458
00000022`e25ff408 cccccccc`ffffffff
00000022`e25ff410 00000022`e25ff5b4
00000022`e25ff418 00000022`e25ff594
00000022`e25ff420 00000022`e25ff7e0
00000022`e25ff428 00007ffa`99b585f8 UnityPlayer!il2cpp::vm::SocketPollingThread::RunLoop+0x268 [ c:\users\tautvydas\builds\bin2\il2cppoutputproject\il2cpp\libil2cpp\vm\threadpool.cpp @ 452]
00000022`e25ff430 00000022`e25ff458
00000022`e25ff438 00000000`ffffffff
...............
00000022`e25ff7d8 00000022`e25ff6b8
00000022`e25ff7e0 00000022`e25ff870
00000022`e25ff7e8 00007ffa`99b58d2c UnityPlayer!il2cpp::vm::SocketPollingThreadEntryPoint+0xec [ c:\users\tautvydas\builds\bin2\il2cppoutputproject\il2cpp\libil2cpp\vm\threadpool.cpp @ 524]
00000022`e25ff7f0 00007ffa`9da83610 UnityPlayer!il2cpp::vm::g_SocketPollingThread
00000022`e25ff7f8 00007ffa`99b57700 UnityPlayer!il2cpp::vm::FreeThreadHandle [ c:\users\tautvydas\builds\bin2\il2cppoutputproject\il2cpp\libil2cpp\vm\threadpool.cpp @ 488]
00000022`e25ff800 00000000`0000106c
00000022`e25ff808 cccccccc`cccccccc
00000022`e25ff810 00007ffa`9da83610 UnityPlayer!il2cpp::vm::g_SocketPollingThread
00000022`e25ff818 000001c4`1705f5c0
00000022`e25ff820 cccccccc`0000106c
...............
00000022`e25ff860 00005eaa`e9a6af86
00000022`e25ff868 cccccccc`cccccccc
00000022`e25ff870 00000022`e25ff8d0
00000022`e25ff878 00007ffa`99c63b52 UnityPlayer!il2cpp::os::Thread::RunWrapper+0xd2 [ c:\users\tautvydas\builds\bin2\il2cppoutputproject\il2cpp\libil2cpp\os\thread.cpp @ 106]
00000022`e25ff880 00007ffa`9da83610 UnityPlayer!il2cpp::vm::g_SocketPollingThread
00000022`e25ff888 00000000`00000018
00000022`e25ff890 cccccccc`cccccccc
...............
00000022`e25ff8a8 000001c4`15508c90
00000022`e25ff8b0 cccccccc`00000002
00000022`e25ff8b8 00007ffa`99b58c40 UnityPlayer!il2cpp::vm::SocketPollingThreadEntryPoint [ c:\users\tautvydas\builds\bin2\il2cppoutputproject\il2cpp\libil2cpp\vm\threadpool.cpp @ 494]
00000022`e25ff8c0 00007ffa`9da83610 UnityPlayer!il2cpp::vm::g_SocketPollingThread
00000022`e25ff8c8 000001c4`155a5890
00000022`e25ff8d0 00000022`e25ff920
00000022`e25ff8d8 00007ffa`99c19a14 UnityPlayer!il2cpp::os::ThreadStartWrapper+0x54 [ c:\users\tautvydas\builds\bin2\il2cppoutputproject\il2cpp\libil2cpp\os\win32\threadimpl.cpp @ 31]
00000022`e25ff8e0 000001c4`155a5890
...............
00000022`e25ff900 cccccccc`cccccccc
00000022`e25ff908 00007ffa`99c63a80 UnityPlayer!il2cpp::os::Thread::RunWrapper [ c:\users\tautvydas\builds\bin2\il2cppoutputproject\il2cpp\libil2cpp\os\thread.cpp @ 80]
00000022`e25ff910 000001c4`155a5890
...............
00000022`e25ff940 000001c4`1e0801b0
00000022`e25ff948 00007ffa`e6858102 KERNEL32!BaseThreadInitThunk+0x22
00000022`e25ff950 000001c4`1e0801b0
00000022`e25ff958 00000000`00000000
00000022`e25ff960 00000000`00000000
00000022`e25ff968 00000000`00000000
00000022`e25ff970 00007ffa`99c199c0 UnityPlayer!il2cpp::os::ThreadStartWrapper [ c:\users\tautvydas\builds\bin2\il2cppoutputproject\il2cpp\libil2cpp\os\win32\threadimpl.cpp @ 26]
00000022`e25ff978 00007ffa`e926c5b4 ntdll!RtlUserThreadStart+0x34
00000022`e25ff980 00007ffa`e68580e0 KERNEL32!BaseThreadInitThunkスタックトレースを大まかに再構築してみた：
00000022`e25febd8 00007ffa`b1fdc65c ucrtbased!heap_alloc_dbg+0x1c [...\appcrt\heap\debug_heap.cpp @ 447]
00000022`e25fec28 00007ffa`b1fdf54c ucrtbased!_calloc_dbg+0x6c [...\appcrt\heap\debug_heap.cpp @ 511]
00000022`e25fec68 00007ffa`b1fdb69e ucrtbased!calloc+0x2e [...\appcrt\heap\calloc.cpp @ 25]
00000022`e25feca8 00007ffa`99b3b646 UnityPlayer!il2cpp::os::SocketImpl::Poll+0x66 [...\libil2cpp\os\win32\socketimpl.cpp @ 1429]
00000022`e25ff3f8 00007ffa`99c1caf4 UnityPlayer!il2cpp::os::Socket::Poll+0x44 [...\libil2cpp\os\socket.cpp @ 324]
00000022`e25ff428 00007ffa`99b585f8 UnityPlayer!il2cpp::vm::SocketPollingThread::RunLoop+0x268 [...\libil2cpp\vm\threadpool.cpp @ 452]
00000022`e25ff7e8 00007ffa`99b58d2c UnityPlayer!il2cpp::vm::SocketPollingThreadEntryPoint+0xec [...\libil2cpp\vm\threadpool.cpp @ 524]
00000022`e25ff878 00007ffa`99c63b52 UnityPlayer!il2cpp::os::Thread::RunWrapper+0xd2 [...\libil2cpp\os\thread.cpp @ 106]
00000022`e25ff8d8 00007ffa`99c19a14 UnityPlayer!il2cpp::os::ThreadStartWrapper+0x54 [...\libil2cpp\os\win32\threadimpl.cpp @ 31]
00000022`e25ff948 00007ffa`e6858102 KERNEL32!BaseThreadInitThunk+0x22
00000022`e25ff978 00007ffa`e926c5b4 ntdll!RtlUserThreadStart+0x34IL2CPPのランタイム・ソケット・ポーリング・スレッドだ。このスレッドの責任は、ソケットがデータの送受信の準備ができたことを他のスレッドに伝えることである。他のスレッドからソケットポーリングリクエストが投入されるFIFOキューがあり、ソケットポーリングスレッドはこれらのリクエストを1つずつデキューし、select()関数を呼び出し、select()が結果を返すと、元のリクエストにあったコールバックをスレッドプールにキューイングする。
つまり、誰かがスタックをひどく破損させているのだ。検索を絞り込むために、そのスレッドではほとんどのスタックフレームに「スタックセンチネル」と書くことにした。私のスタック・センチネルの定義はこうだ：
これが構築されると、バッファは "0xDD "で満たされる。破壊されたとき、それらの値が変化していないかどうかをチェックする。これは信じられないほどうまくいった！代わりに主張したのだ：
誰かが歩哨の陰部を触っていたのだ。さらに2、3回実行したが、結果は同じだった。メモリビューを見て、私は自分が見たものが見慣れたものであることに気づいた：
これらは、最初に破損したスタック・トレースで見たのとまったく同じ値である。先ほどのクラッシュの原因が何であれ、スタック・センチネルを破損させたことにも責任があることに気づいた。最初は、これはある種のバッファオーバーフローで、誰かがローカル変数の境界外に書き込んでいるのだと思った。そこで、このスタック・センチネルをもっと積極的に配置するようにした。スレッドが行うほとんどすべての関数呼び出しの前だ。しかし、破損は不定期に起こるようで、この方法では何が原因なのかを見つけることはできなかった。
私のセンチネルがスコープに入っている間、メモリが常に破損していることは知っていた。私はどうにかして、それを腐敗させるものを現行犯で捕まえる必要があった。スタックセンチネルのメモリは、スタックセンチネルが生きている間だけ読み出し専用にしようと考えた：私なら、コンストラクタでVirtualProtect()を呼び出してページを読み取り専用にし、デストラクタでもう一度呼び出して書き込み可能にする：
驚いたことに、まだ破損していた！そしてデバッグ・ログのメッセージはこうだった：
メモリが 0xd046ffeea8 で破損しました。破損したときは読み取り専用だった。
CrashingGame.exeがブレークポイントをトリガーしました。
これは私にとって赤信号だった。メモリが読み出し専用になっている間、あるいは読み出し専用にする直前に、誰かがメモリを破壊していたのだ。アクセス違反がなかったので、後者だと思い、マジック値を設定した直後にメモリの内容が変わったかどうかをチェックするようにコードを変更した：
私の仮説は正しかった：
メモリが 0x79b3bfea78 で破損しました。
CrashingGame.exeがブレークポイントをトリガーしました。
この時点で私は考えていた：「別のスレッドが私のスタックを壊しているのだろう。そうでなければならない。そうだろう？ 。これを調査するために私が知っていた唯一の方法は、データ（メモリ）ブレークポイントを使って犯人を捕まえることだった。残念なことに、x86では一度に4つのメモリロケーションしか監視できないので、監視できるのはせいぜい32バイトだ。ブレークポイントをどこに設定すればいいのか、なんとなく考える必要があった。私は腐敗のパターンを観察し始めた。最初はランダムであるかのように見えたが、それはASLRの性質による錯覚に過ぎなかった。ゲームを再起動するたびに、スタックをランダムなメモリーアドレスに配置するため、破損する場所は当然異なる。しかし、このことに気づいてからは、メモリが破損するたびにゲームを再起動するのをやめ、そのまま実行を続けた。その結果、あるデバッグ・セッションにおいて、破損したメモリー・アドレスが常に一定であることを発見した。言い換えれば、一度破損すると、プログラムを終了させない限り、常にまったく同じメモリー・アドレスで破損してしまうのだ：
メモリが 0x90445febd8 で破損しました。
CrashingGame.exeがブレークポイントをトリガーしました。
メモリが 0x90445febd8 で破損しました。
CrashingGame.exeがブレークポイントをトリガーしました。
私はそのメモリー・アドレスにデータ・ブレークポイントを設定し、それを0xDDというマジック値に設定するたびにブレークし続けるのを見ていた。しかし、Visual Studioでは、ブレークポイントに条件を設定することができる：
分後、ついにこのブレークポイントがヒットした。デバッグを始めて3日目にして、この時点にたどり着いた。これが私の勝利になるはずだった。「ついにお前を押さえ込んだぞ！」と私は宣言した。そう楽観的に考えていた：
デバッガーを見ながら、私の心は答えよりも疑問でいっぱいになった：“What?こんなことが可能なのか？私は気が狂っているのだろうか？".分解して見ることにした：
案の定、そのメモリー位置は変更されていた。しかし、0x02ではなく、0xDDが書き込まれていた！メモリーウィンドウを見ると、すでに全領域が破損していた：
壁に頭を打ちつけようとしたとき、私は同僚に電話して、私が何か明らかなことを見落としていないか見てくれるよう頼んだ。一緒にデバッグコードを見直したが、そのような奇妙な現象を引き起こすようなものは少しも見つからなかった。それから一歩下がって、そのコードが "2 "に値をセットしていると考えて、デバッガーをブレークさせる原因は何だろうと想像してみた。私は次のような仮説の連鎖を思いついた：
1. mov byte ptr [rax], 0DDh がメモリ位置を変更し、CPUは実行を中断してデバッガにプログラムの状態を検査させる。
2.記憶が何かによって壊される
3.デバッガーはメモリ・アドレスを検査し、その中に "2 "を見つけ、それが変更されたものだと考える。
では...デバッガーによってプログラムがフリーズしている間に、何がメモリの内容を変えることができるのか？私の知る限り、このようなことが起こりうるのは2つのシナリオがある：他のプロセスがやっているか、OSカーネルがやっているかのどちらかだ。このどちらかを調査するためには、従来のデバッガーではうまくいかない。カーネル・デバッグの世界に入る。
意外なことに、Windowsではカーネル・デバッグの設定は非常に簡単だ。デバッガーが動作するマシンと、デバッグするマシンの2台が必要だ。デバッグするマシンで昇格コマンドプロンプトを開き、次のように入力する：
ホストIPは、デバッガを実行しているマシンのIPアドレスです。指定されたポートをデバッガー接続に使用する。49152から65535の間である。つ目のコマンドでエンターキーを押すと、デバッガーを接続する際のパスワードとなるシークレットキー（写真では切り捨ててある）が表示される。これらの手順を完了したら、再起動する。
もう一方のコンピューターでWinDbgを開き、File -> Kernel Debugをクリックし、ポートとキーを入力する。
すべてがうまくいけば、Debug -> Breakを押して実行を中断できる。それがうまくいけば、「デブゲー」コンピューターはフリーズする。実行を続けるには「g」を入力する。
私はゲームを立ち上げ、メモリが破損するアドレスを調べるために、ゲームが一度壊れるのを待った：
メモリが 0x49d05fedd8 で破損しました。
CrashingGame.exeがブレークポイントをトリガーしました。
さて、データ・ブレークポイントを設定するアドレスがわかったところで、実際にブレークポイントを設定するためにカーネル・デバッガーを設定しなければならない：
kd> !process 0 0
PROCESS ffffe00167228080
SessionId: 1 Cid: 26b8 Peb: 49cceca000 ParentCid: 03d8
DirBase: 1ae5e3000 ObjectTable: ffffc00186220d80 HandleCount:
Image: CrashingGame.exe
kd> .process /i ffffe00167228080
You need to continue execution (press 'g' ) for the context
to be switched. When the debugger breaks in again, you will be in
the new process context.
kd> g
Break instruction exception - code 80000003 (first chance)
nt!DbgBreakPointWithStatus:
fffff801`7534beb0 cc int 3
kd> .process
Implicit process is now ffffe001`66e9e080
kd> .reload /f
kd> ba w 1 0x00000049D05FEDD8 ".if (@@c++(*(char*)0x00000049D05FEDD8 == 2)) { k } .else { gc }"しばらくして、ブレークポイントが実際にヒットした...。
# Child-SP RetAddr Call Site
00 ffffd000`23c1e980 fffff801`7527dc64 nt!IopCompleteRequest+0xef
01 ffffd000`23c1ea70 fffff801`75349953 nt!KiDeliverApc+0x134
02 ffffd000`23c1eb00 00007ffd`7e08b4bd nt!KiApcInterrupt+0xc3
03 00000049`d05fad50 cccccccc`cccccccc UnityPlayer!StackSentinel::StackSentinel+0x4d [...\libil2cpp\utils\memory.cpp @ 21]さて、何が起こっているんだ？センチネルが楽しげにマジック値を設定し、その後ハードウェア割り込みが入り、完了ルーチンが呼び出され、スタックに "2 "が書き込まれる。すごいね。さて、どういうわけかWindowsカーネルが私のメモリを破壊している。でも、なぜ？
最初は、これはWindowsのAPIを呼び出して、無効な引数を渡しているのだと思った。そこで、もう一度ソケット・ポーリング・スレッドのコードをすべて調べてみたところ、そこで呼び出していたシステム・コールはselect()関数だけだった。私はMSDNに行き、select()に関するドキュメントを1時間かけて読み直し、自分たちのやり方が正しいかどうか再確認した。私が見た限りでは、これを使って悪いことをすることはあまりなかったし、「このパラメータを渡すと、スタックに2を書き込む」というようなことも、ドキュメントには書かれていなかった。私たちはすべて正しいことをしているように思えた。
試すべきことが尽きたので、デバッガを使ってselect()関数に入り、その逆アセンブルを経て、どのように動作するかを解明することにした。数時間かかったけど、なんとかできたよ。select()関数はWSPSelect()のラッパーで、おおよそ次のようなものらしい：
auto completionEvent = TlsGetValue(MSAFD_SockTlsSlot);
/* setting up some state
…
*/
IO_STATUS_BLOCK statusBlock;
auto result = NtDeviceIoControlFile(networkDeviceHandle, completionEvent, nullptr, nullptr, &statusBlock, 0x12024,
buffer, bufferLength, buffer, bufferLength);
if (result == STATUS_PENDING)
WaitForSingleObjectEx(completionEvent, INFINITE, TRUE);
/* convert result and return it
...
*/ここで重要なのは、NtDeviceIoControlFile()の呼び出しと、ローカル変数statusBlockをoutパラメータとして渡していること、そして最後にalertable waitを使ってイベントが通知されるのを待っていることである。カーネル関数を呼び出し、リクエストをすぐに完了できない場合はSTATUS_PENDINGを返す。この場合、WSPSelect() は、イベントがセットされるまで待機します。NtDeviceIoControlFile()が終了すると、結果をstatusBlock変数に書き込み、イベントを設定する。待機が完了し、WSPSelect()が戻る。
IO_STATUS_BLOCK 構造体は次のようになる：
typedef struct _IO_STATUS_BLOCK
{
union
{
NTSTATUS Status;
PVOID Pointer;
};
ULONG_PTR Information;
} IO_STATUS_BLOCK, *PIO_STATUS_BLOCK;64ビットでは、この構造体は16バイト長になる。最初の4バイトが破損し（NTSTATUSは4バイト長）、次に4バイトがスキップされ（PVOIDのパディング/スペース）、最後に8バイトが破損する。もしそれが本当にメモリに書き込まれていたのなら、最初の4バイトには結果のステータスが含まれているはずだ。最初の4バイトは常に0x00000102だった。そしてそのエラーコードは...STATUS_TIMEOUTである！WSPSelect()がNtDeviceIOControlFile()の完了を待たなければ、それは正しい理論だろう。でも、そうなった。
select()関数がどのように機能するのかを理解した後、ソケットポーリングスレッドがどのように機能するのか、全体像を見てみることにした。そして、そのときレンガのような衝撃が走った。
他のスレッドがソケットをプッシュすると、ソケットポーリングスレッドはその関数の select() を呼び出す。select()はブロッキングコールであるため、別のソケットがソケットポーリングスレッドキューにプッシュされると、何らかの方法でselect()を中断し、新しいソケットを早急に処理する必要がある。select()関数に割り込む方法は？どうやら、select()がブロックされている間にQueueUserAPC()を使って非同期プロシージャを実行し、例外を発生させたようだ！スタックを展開し、さらにコードを実行させ、将来のある時点でカーネルが作業を完了し、結果をstatusBlockローカル変数（その時点ではもう存在しない）に書き込む。もしスタック上のリターンアドレスにぶつかったら、クラッシュしてしまう。
QueueUserAPC()を使う代わりに、ループバックソケットを作成し、select()に割り込む必要があるときにバイトを送信するようにしたのだ。このパスはPOSIXプラットフォームではかなり以前から使われており、現在ではWindowsでも使われている。このバグはUnity 5.3.4p1で修正されました。
これは夜も眠れないバグのひとつだ。このバグを解決するのに5日かかったが、おそらく私がこれまで調べて直した中で最も難しいバグのひとつだろう。教訓：システム・コール内にいる場合は、非同期プロシージャから例外を投げてはいけない！