2014-11-08 GCCについて追記。
ワトソン博士は事後専用のポストモーテム デバッガ(postmortem debugger)の1種で、Windows 2000/XP では標準でインストールされている(有効になっているかどうかは不明)。
設定ダイアログはコマンドラインから drwtsn32 で起動する。詳しくはヘルプボタンを押して参照(さして詳しくはないが、一通りの事は書いてある)。
Windows 2000 のデフォルトでは C:\Documents and Settings\All Users\Documents\DrWatsonに、ログファイルとクラッシュダンプがそれぞれ
drwtsn32.log
で作成される。
user.dmp
簡単な説明をしておくと、ワトソン博士が働く為にはレジストリに登録しておく必要があり、それはコマンドラインで drwtsn32 -i とする。すると次のメッセージボックスが表示される。
--------------------------- Dr. Watson for Windows 2000 --------------------------- ワトソン博士が既定のアプリケーション デバッガとしてインストールされました。 --------------------------- OK ---------------------------
おっと、その前に Visual Studio なんかをインストールすると、そっちのデバッガが起動するようにレジストリが書き換えられているはずなので(インストール時の選択肢があったかどうか失念)、キーを改名して保存しておくといいだろう。自分の場合、VS2005 をインストールしており、次のようになっていた。
[HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows NT\CurrentVersion\AeDebug]
"Auto"="0"
"UserDebuggerHotKey"=dword:00000000
"Debugger"="\"C:\\WINNT\\system32\\vsjitdebugger.exe\" -p %ld -e %ld"
drwtsn32 -i により Debugger キーは
"Debugger"="drwtsn32 -p %ld -e %ld -g"
となる。Windows がエラーを検知した時に呼び出すプログラムをここで指定する訳で、ワトソン博士がメモリに常駐して監視する訳ではない。
ステート ダンプと称するスレッド毎の情報が書き込まれる。多分、例外を起こしたスレッドが最初に記録されると思う。
最初はレジスタ ダンプ。重要なのは例外が起きたアドレスを示すeip、スタックトップアドレスのesp、コールツリーの起点となるebp。
スレッド ID 0x### のステート ダンプ
eax=00000003 ebx=005bb760 ecx=00000000 edx=00000000 esi=00000000 edi=00000110
eip=0040152d esp=0012fb7c ebp=0012fbb4 iopl=0 nv up ei pl zr na po nc
cs=001b ss=0023 ds=0023 es=0023 fs=0038 gs=0000 efl=00000246
次に例外を起こした命令前後の逆アセンブルリスト。eipの前後の逆アセンブル命令数は [インストラクションの数] で指定する。デフォルトは10。なお、クラッシュダンプ user.dmp を作成するようにしておけば WinDbg へ読み込んでもっと広い範囲を Disassembly で見る事が出来る。
ファンクション: <nosymbols>
00401511 56 push esi
00401512 57 push edi
00401513 8965e8 mov [ebp+0xe8],esp ss:00d89a9a=????????
00401516 33c0 xor eax,eax
00401518 8945fc mov [ebp+0xfc],eax ss:00d89a9a=????????
0040151b 8945dc mov [ebp+0xdc],eax ss:00d89a9a=????????
0040151e c745d803000000 mov dword ptr [ebp+0xd8],0x3 ss:00d89a9a=????????
00401525 b803000000 mov eax,0x3
0040152a 99 cdq
0040152b 33c9 xor ecx,ecx
フォールト->0040152d f7f9 idiv ecx
0040152f 8945d4 mov [ebp+0xd4],eax ss:00d89a9a=????????
00401532 8d55e0 lea edx,[ebp+0xe0] ss:00d89a9a=????????
00401535 bf14914000 mov edi,0x409114
0040153a 83c9ff or ecx,0xff
0040153d 33c0 xor eax,eax
0040153f f2ae repne scasb es:00000110=??
00401541 f7d1 not ecx
00401543 2bf9 sub edi,ecx
00401545 8bc1 mov eax,ecx
00401547 8bf7 mov esi,edi
00401549 8bfa mov edi,edx
この例は故意に0除算で例外を起こした為、ユーザー領域の 0040152d が原因であるから MAPファイルを追うなりすれば原因の当りはつくが、システムコールの奥底で起きた場合は呼び出し履歴(コールツリー)が欲しくなる。
お目当てはコレ!
*----> スタック バック トレース <----*
FramePtr ReturnAd Param#1 Param#2 Param#3 Param#4 ファンクション名
0012FBB4 004014E1 77E0A454 00160524 00000110 0010052E !<nosymbols>
0012FBD8 77DF8CD3 004014A0 00160524 00000110 0010052E !<nosymbols>
0012FC14 77DE62FA 00160524 00000110 0010052E 00000000 user32!CharPrevW
0012FC44 77DF9DA0 005BB760 00000110 0010052E 00000000 user32!IsWindowVisible
0012FCFC 77E14300 00400000 00000008 00000000 005BB760 user32!CharPrevW
0012FD2C 77E08D37 00400000 0040E858 00000000 004014A0 user32!CheckRadioButton
0012FD4C 77E0EDE7 00400000 0040E858 001F0542 004014A0 user32!DialogBoxIndirectParamAorW
0012FD78 004013E3 00400000 00000067 001F0542 004014A0 user32!DialogBoxParamA
0012FE68 77DE4605 00401320 001F0542 00000111 00000068 !<nosymbols>
0012FEF4 77DE5B77 0012FF1C 00000001 0040120A 0012FF1C user32!TranslateMessageEx
77DE55C4 7E816608 7500E508 0C76FF15 FF0876FF 36FF0476 user32!DispatchMessageA
24748B56 00000000 00000000 00000000 00000000 00000000 <nosymbols>
FramePtr | スタック中のアドレスを表す。フレームとはスタックフレームの意。関数のコールツリーを知りたいだけなら無用だが、辿った根拠として表示してある。例外が起きた時の ebp レジスタが起点になる。 |
ReturnAd | 関数の戻り番地。CALL命令によってスタックに残る。 |
Param#1~4 | 関数の引数、もしくは呼び出した側の関数のローカル変数。どちらなのかは一概に言えないので固定で4個となっている。必要なら ロウ スタック ダンプ を見るべし! |
ファンクション名 | シンボルテーブルから得た関数名。 |
どうすればこのバックトレース出力を得られるかについては、次に書かれてある ロウ スタック ダンプ を見た方が判り易い。
まずレジスタ ダンプ ebp = 0012fbb4 から始まる。そのアドレスの値は 0012fbd8 であり、さらにそのアドレスの値は 0012fc14 と言う風にポインタのリストと考えれば良い(ピンク枠で図示)。
簡単に書けば次のようなコードになると思う(終了条件は端折っている)。
for (const DWORD* pEbp = (constDWORD*)pInfo->ContextRecord->Ebp;
IsBadReadPtr(pEbp, sizeof(DWORD)+sizeof(DWORD)) == 0 && pEbp != 0 && *pEbp != 0;
pEbp = (const DWORD* )*pEbp)
{
fprintf(fp, "%08X %08X \n", pEbp, pEbp[1]); // FramePtr と ReturnAd の表示
}
そうやって辿った各々の位置の直後が Return Address である(関数の戻り番地。青枠で図示)。
なお ロウ スタック ダンプ をどれだけログに残すかのサイズ設定は無さそうだが、始まりは例外が起きた時点のスタックの底である esp の値からのようである。これもクラッシュダンプ user.dmp を作成するようにしておいて WinDbg へ読み込んでもっと広い範囲を Memory Dump で見る事が出来る。
WinDbg を使用するにしても、最初からクラッシュダンプを解析するには辛いので、ワトソンログを見ながら解析するのが良さそうである。
少々場違いだが、GCC で関数の戻りアドレスを得るのに __builtin_return_address(level) が使える。
static const void* func1() { return __builtin_return_address(2); // 2つ前まで遡ってみる。 }
こんな関数をビルド後にディスアセンブル objdump -d a.out して見ると
080483e4 <_ZL5func1v>: 80483e4: 55 push %ebp 80483e5: 89 e5 mov %esp,%ebp 80483e7: 8b 45 00 mov 0x0(%ebp),%eax ...(0) 80483ea: 8b 00 mov (%eax),%eax ......(1) 80483ec: 8b 40 04 mov 0x4(%eax),%eax ...(2) 80483ef: 5d pop %ebp 80483f0: c3 ret
何とまぁ、固定回数なので実に単純なアクセスで戻り番地を返している。判りやすいが...
MAP ファイルは次のような状態で、eip=0040152d により Sample関数で例外を起こしている。OK
Address Publics by Value Rva+Base Lib:Object
0001:00000000 ?aaaaaaaaaaa 00401000 f xxxx.obj
0001:00000180 _WinMain@16 00401180 f yyy.obj
0001:00000240 ?MyRegisterClass@@... 00401240 f yyy.obj
0001:000002d0 ?InitInstance@@... 004012d0 f yyy.obj
0001:00000330 ?WndProc@@... 00401330 f yyy.obj
0001:000004a0 ?About@@... 004014a0 f yyy.obj
0001:000004f0 ?Sample@@YAHXZ 004014f0 f yyy.obj <---- 例外発生!
0001:00000580 _fprintf 00401580 f LIBC:fprintf.obj
About関数での Sample関数の呼び出し直後のアドレスは、004014a0 + 00041 = 004014e1。最初の青枠の Return Address と合っている。OK
?About@@... PROC NEAR ; About, COMDAT
...
0003c e8 00 00 00 00 call ?Sample@@YAHXZ ; Sample();
00041 b8 01 00 00 00 mov eax, 1 ; 0x004014e1
CALL命令によって呼び出された Sample 関数は大抵の関数がそうするようにプロローグ部分で ebp をプッシュする。バック トレースはこのような構造が一般的である事を利用している。
?Sample@@YAHXZ PROC NEAR ; Sample, COMDAT
55 push ebp ........ 0012fbd8 がスタックトップに積まれる。
8b ec mov ebp, esp ... スタックトップ 0012fbb0 をベースとする。
83 ec 1c sub esp, 28 .... 関数内ローカル変数の領域確保。
... 関数内の処理(省略)
8b e5 mov esp, ebp ... スタックポインタを戻す --> 0012fbb4
5d pop ebp ........ 0012fbd8 を取り戻す。
c3 ret 0 ..........
先に示したスタック バック トレースではユーザーアプリケーションのファンクション名には !<nosymbols> とだけ表示されていたが、デバッグ情報ファイルを作成しておけば下のようにちゃんと表示する事も出来る(VC限定 とは言い切れないが、ワトソンが他社のデバッグ情報を読めるのだろうか...)。
*----> スタック バック トレース<----*
FramePtr ReturnAd Param#1 Param#2 Param#3 Param#4 ファンクション名
0012FBB8 00401521 77E0A454 006607CC 00000110 0073078A !Sample
0012FBBC 77E0A454 006607CC 00000110 0073078A 00000000 !About (FPO:[4,0,0])
0012FBDC 77DF8CD3 004014E0 006607CC 00000110 0073078A user32!SetWindowPlacement
0012FC18 77DE62FA 006607CC 00000110 0073078A 00000000 user32!CharPrevW
0012FC48 77DF9DA0 005A70F8 00000110 0073078A 00000000 user32!IsWindowVisible
0012FD00 77E14300 00400000 00000008 00000000 005A70F8 user32!CharPrevW
0012FD30 77E08D37 00400000 0040F858 00000000 004014E0 user32!CheckRadioButton
0012FD50 77E0EDE7 00400000 0040F858 00570570 004014E0 user32!DialogBoxIndirectParamAorW
0012FD7C 0040142E 00400000 00000067 00570570 004014E0 user32!DialogBoxParamA
0012FE48 77E0A454 00570570 00000111 00000068 00000000 !WndProc (FPO:[4,45,2])
0012FE68 77DE4605 00401370 00570570 00000111 00000068 user32!SetWindowPlacement
0012FEF4 77DE5B77 0012FF1C 00000001 0040125A 0012FF1C user32!TranslateMessageEx
77DE55C4 7E816608 7500E508 0C76FF15 FF0876FF 36FF0476 user32!DispatchMessageA
24748B56 00000000 00000000 00000000 00000000 00000000 <nosymbols>
*----> ロウ スタック ダンプ <----*
0012fb80 10 01 00 00 00 00 00 00 - f8 70 5a 00 9c 64 14 00 .........pZ..d..
0012fb90 03 00 00 00 00 00 00 00 - a8 30 5c 00 87 00 00 00 .........0\.....
0012fba0 80 fb 12 00 d4 f7 12 00 - e4 fe 12 00 3c 1a 40 00 ............<.@.
0012fbb0 60 91 40 00 00 00 00 00 - dc fb 12 00 21 15 40 00 `.@.........!.@.
0012fbc0 54 a4 e0 77 cc 07 66 00 - 10 01 00 00 8a 07 73 00 T..w..f.......s.
0012fbd0 00 00 00 00 00 00 00 00 - cd ab ba dc 18 fc 12 00 ................
0012fbe0 d3 8c df 77 e0 14 40 00 - cc 07 66 00 10 01 00 00 ...w..@...f.....
0012fbf0 8a 07 73 00 00 00 00 00 - f0 42 66 00 10 01 00 00 ..s......Bf.....
0012fc00 f8 70 5a 00 8a 07 73 00 - 87 00 00 00 00 00 00 00 .pZ...s.........
0012fc10 00 00 00 00 00 00 00 00 - 48 fc 12 00 fa 62 de 77 ........H....b.w
0012fc20 cc 07 66 00 10 01 00 00 - 8a 07 73 00 00 00 00 00 ..f.......s.....
0012fc30 00 00 00 00 00 00 00 00 - f8 70 5a 00 8a 07 73 00 .........pZ...s.
0012fc40 cc 07 66 00 00 00 00 00 - 00 fd 12 00 a0 9d df 77 ..f............w
0012fc50 f8 70 5a 00 10 01 00 00 - 8a 07 73 00 00 00 00 00 .pZ.......s.....
0012fc60 00 00 00 00 70 05 57 00 - 01 00 00 00 ff ff 00 00 ....p.W.........
0012fc70 00 00 00 80 00 00 00 00 - 70 05 57 00 01 00 00 00 ........p.W.....
0012fc80 ff ff 00 00 00 00 00 00 - 04 00 00 00 06 00 00 00 ................
0012fc90 46 f9 40 00 00 04 00 00 - 00 00 00 00 00 04 00 00 F.@.............
0012fca0 00 00 00 00 04 00 00 00 - 01 00 03 50 86 01 0e 00 ...........P....
0012fcb0 3c 00 19 00 01 00 00 00 - 4c f9 40 00 50 f9 40 00 <.......L.@.P.@.
VC 使いならば .pdb をカレントかシステムディレクトリに置いておけば良い。VC6 では次の設定とする。
[C/C++] - [一般] - [プログラム データベースを使用] を選択
[リンク] - [一般] - □デバッグ情報を生成する を On
[リンク] - [デバッグ] - □デバッグ情報 を On
なお、こうすると作成した .pdb へのフルパスが実行ファイルに埋め込まれる等、実行ファイルは僅かに大きくなる。開発環境と実行環境とは異なるのが通常なので、あまり意味が無い上にみっともないので止めて欲しい。
About関数とWndProc関数に (FPO: [4,0,0])等と表示されているのは Frame Pointer Omission と呼ばれ、コンパイラがフレーム ポインタを省略する事らしい(MS では古くから FPO: [x,y,z] と表現するみたい)。
先に示した辿り方のように単純に ロウ スタック ダンプ を見ながら ebp を追っていくだけだと FPO の付いた関数は辿れない(バックトレースから抜けてしまう)。
ワトソンがスタック ダンプだけを頼りにしていないのは想像が付くので、試しに .pdb を探せないようにしてもう1度例外を起こしてみると案の定、FPO の行がスタックバックトレースから欠落した。
FPO: に続く括弧の中 [N1,N2,N3] は何を意味するのか?
About (FPO: [4,0,0]) の関数定義は
LRESULT CALLBACK About( HWND hDlg, UINT
message, WPARAM wParam, LPARAM lParam )
で自動変数無し。
!WndProc (FPO: [4,45,2]) は
LRESULT CALLBACK WndProc(HWND hWnd, UINT
message, WPARAM wParam, LPARAM lParam)
で、諸々の自動変数用に
sub esp, 180 ;
000000b4H
N1: 引数の数 ( push 回数?)
N2: 自動変数の ワード数(ワード = 4byte)
N3: 不明
因みに About 関数に _alloca で自動変数領域を確保したら FPO が解除されフレーム ポインタが残るようになった。
ネット上を漁ってもヒントが得られないので WinDbg を調べていたら Debugging Tools for Windows ヘルプ - KV (Display Stack Backtrace) にそれらしい記述があった。 WinDbg を使いこなしている人には見慣れた表現なのかも知れない。
書式 | 解説 |
---|---|
FPO: [non-Fpo] |
No FPO data for frame |
FPO: [N1,N2,N3] |
N1 is the total number of parameters. N2 is the number of DWORDs for the locals. N3 is number of registers saved. |
FPO: [N1,N2] TrapFrame @ Address |
N1 is the total number of parameters. N2 is the number of DWORDs for the locals. Address is the address of the trap frame. |
FPO: TaskGate Segment:0 |
Segment is task gate segment selector. |
FPO: [EBP 0xBase] |
Base is the base pointer for the frame |
さて、このような FPO に関する出力はサンプルに無かったのだが、ドキュメントを良く読んでみると STACKFRAME 構造体の FuncTableEntry メンバが FPO_DATA 構造体を返すようである。
typedef struct _FPO_DATA { DWORD ulOffStart; // Offset of the first byte of the function code. DWORD cbProcSize; // Number of bytes in the function. DWORD cdwLocals; // Number of local variables, in DWORDs. WORD cdwParams; // Size of the parameters, in DWORDs. WORD cbProlog : 8; // Number of bytes in the function prolog code. WORD cbRegs : 3; // Number of registers saved. WORD fHasSEH : 1; // Indicates whether the function uses structured exception handling. WORD fUseBP : 1; // Indicates whether the EBP register has been allocated. WORD reserved : 1; // Reserved for future use. WORD cbFrame : 2; // Indicates the frame type. // FRAME_FPO FPO frame // FRAME_TRAP Trap frame // FRAME_TSS TSS frame // FRAME_NONFPO Non-FPO frame } FPO_DATA, *PFPO_DATA;
この構造体を出力させ、ワトソン ログと対応させてみると...
FPO: [5984,146,25,4, 0,1,0,0,0] ... !About (FPO: [4,25,1])
FPO: [5616,357,45,4, 0,2,0,0,0] ... !WndProc (FPO: [4,45,2])
[N1,N2,N3] は cdwParams, cdwLocals, cbRegs に相当するようである。
最初のメンバ ulOffStart が関数のアドレスを指すようなのでマップファイルの情報と見比べる。
5984(0x1760), 5616(0x15f0) Rva に一致している。OK
Address Publics by Value Rva+Base Lib:Object 0001:000005f0 ?WndProc@@YGJPAUHWND__@@IIJ@Z 004015f0 f xxx.obj 0001:00000760 ?About@@YGJPAUHWND__@@IIJ@Z 00401760 f xxx.obj
結局の処、FPO を含んだ正確なコールスタックを得るにはシンボル情報が肝となる。
自分で書くコードにコールスタックが吐けるルーチンを含めたく、サンプルを探した。
StackWalk 関数を初めて見た時は、引数も多く何の事かさっぱりだったが、大体次のような使われ方をすると思う。(2) <- (5) は繰り返しを意味する。
(1) SymInitialize // シンボルハンドラを初期化 +-> (2) StackWalk コール // 次フレームの STACKFRAME 構造体が返る。 | (3) 成否判定 // break | (4) SymGetSymFromAddr コール // 関数名取得 +-- (5) SymGetModuleInfo コール // モジュール名取得 (6) SymCleanup
ややこしい事この上ない。後に知った glibc の backtrace/backtrace_symbols_fd と比べると雲泥の差がある。MSDN には「汎用性のある方法を提供」とあるが、マシンやコンパイラに依存する訳で、汎用性を謳っても煩雑になるだけである。
2008年1月現在、MSDNによると DbgHelp には次のバージョンがあるらしい(Debugging Tools の物が OS添付の 5.x をスキップしている... 恐らく別物なのだろう)。
Version Date stamp Distribution Vehicle 6.8 10/07/2007 Debugging Tools for Windows 6.8 6.6 7/10/2006 Debugging Tools for Windows 6.6 6.5 5/24/2005 Debugging Tools for Windows 6.5 6.4 1/10/2005 Debugging Tools for Windows 6.4 6.3 5/24/2004 Debugging Tools for Windows 6.3 6.2 7/11/2003 Debugging Tools for Windows 6.2 *5.2 3/25/2003 Windows Server 2003 6.1 Debugging Tools for Windows 6.1 6.0 Debugging Tools for Windows 6.0 4.0 Debugging Tools for Windows 4.0 *5.1 Windows XP ........................ SYMBOL_INFO 構造体の導入 3.0 Debugging Tools for Windows 3.0 2.0 Debugging Tools for Windows 2.0 1.0 Debugging Tools for Windows 1.0 *5.0 Windows 2000
Windows Vista では drwtsn32 が存在しないらしい。代替案を用意しているのだろうか...
さらに Windows 2000 環境で出力されるクラッシュダンプは Visual C++ 2005 以降では扱えないらしい。Visual C++.NET 2003 はOKらしい。
マイクロソフトサイトから出ているいかなる保証もない情報を見つけた!
アクセス違反のエラー メッセージが表示されたときに、ワトソン博士が User.dmp と Drwtsn32.log を作成しない
それによると障害を起こしたコードの命令の名前が cmp xchg 8b のように長い場合に発生するとの事。原因と言うより状況でしかないのだが...
修正されたバージョンは次の通り。
日付 時刻 バージョン サイズ ファイル名 -------------------------------------------------------------- 12-Dec-2002 10:25 5.0.2195.6158 72,464 Drwtsn32.exe
それにしてもコードによって動作しないのは不可解...
ワトソン博士がダメでも User.dmp は間違いなく残して欲しいなぁ…
有難い事に wine で DbgHelp.dll が実装されていたので見てみる。
DbgHelp は dlls/dbghelp にある。
StackWalk は stack.c に有り、stack_walk のラッパーとなっている。 16bit 処理が混在してごちゃごちゃしているが、肝の部分を見ると大した事はやっていない。
プログラム カウンタ更新は
frame->AddrPC = frame->AddrReturn;
スタック ポインタは、フレーム ポインタの1つ手前が戻り番地だから、さらにもう1つ手前とし、フレーム ポインタは、単純にその中身で更新する。
frame->AddrStack.Offset = frame->AddrFrame.Offset + 2 * sizeof(DWORD); /* "pop up" previous EBP value */ if (!sw_read_mem(cb, frame->AddrFrame.Offset, &frame->AddrFrame.Offset, sizeof(DWORD)))
リターン アドレスは更新したフレーム ポインタの直後。 関数パラメータは更新したフレーム ポインタの2つ手前。この辺りはもう通常の関数のアセンブリコードに同じ。
sw_read_mem(cb, frame->AddrFrame.Offset + sizeof(DWORD), &frame->AddrReturn.Offset, sizeof(DWORD))) sw_read_mem(cb, frame->AddrFrame.Offset + 2 * sizeof(DWORD), frame->Params, sizeof(frame->Params));
…と言う具合で FPO 最適化に関しては無視されているようである。
FPO_DATA 構造体を返す STACKFRAME 構造体の FuncTableEntry メンバの更新も、実質は NULL が代入されている。
PVOID WINAPI SymFunctionTableAccess(HANDLE hProcess, DWORD AddrBase) { WARN("(%p, 0x%08x): stub\n", hProcess, AddrBase); return NULL; }
Windows でまともに Debug するならやっぱりこれに目を通しておく必要がある。以降、 かなり古い 6.8 版の話。
/Debuggers/Installation and Setup/User-Mode Setup
事後デバッグの準備