.NET Framework デバッグ ~ 例外オブジェクトの捕まえ方
下手なコードを書くプログラマーの中には、 「例外をキャッチさえすればプログラムがクラッシュしない」 といわんばかりに、 あちらこちら例外を catch しては、その問題を闇に葬り去るひとがいます。
特に重要なところでは、問題が起きたとき、エラーメッセージとしてそれを知らせてくれるか、 ログに記録するなりすると良いのですが、そうなっていないときもあります。
運用環境で、Visual Studio が無いような状況でそんなことが起きたときにどうしたらよいか。 調査テクニックを紹介します。
実際に動かして、Exception オブジェクトのメッセージを見る
ここで使うサンプルプログラムはこんなものです。
ボタンが二つあり、左の Test1 、右の Test2 を押すとそれぞれ、下の button1_click 及び button2_click が実行されます。 button1_click 、 button2_click ではそれぞれ例外を発生させています。
using System; using System.Collections.Generic; using System.ComponentModel; using System.Data; using System.Drawing; using System.Text; using System.Windows.Forms; namespace ExceptionTest1 { public partial class Form1 : Form { public Form1() { InitializeComponent(); } private void button1_Click( object sender , EventArgs e ) { try { int i = 1; int j = 0; int z = i / j; } catch ( Exception ex ) { // Do Nothing } } private void button2_Click( object sender , EventArgs e ) { try { throw new OutOfMemoryException( "Hello, ExceptionTest1.exe!!" ); } catch ( Exception ex ) { // Do Nothing } } } }
例外はどちらもキャッチされていますから、プログラムがクラッシュすることはありません。
さて、このような時、どうすればいいでしょうか。
このテストプログラムはあまりに単純で何も問題はありませんが、通常はこんなにシンプルではなく、 どのメソッドの呼び出しで問題が起きているのかわからない場合が多いです。
そのような時は、問題発生箇所を特定することが問題解決のファーストステップになります。
問題発生箇所を特定する方法として、例外オブジェクトとのメッセージを見られれば、たいていの場合何かわかるでしょう。
ここでは 「例外オブジェクトのメッセージを見る」 までを目標にしてみましょう。
0除算例外の場合は自動的にブレークする
それではさっそく試してみましょう。
デバッガの基本的な使い方、環境設定の方法については IIS システムデバッグ入門 などを参考にしてください。
また、ここではマネージドコードのデバッグになりますから、SOS.DLL は .NET Framework のシステムディレクトリから、 デバッガのディレクトリにコピーしておいてください。
ではさっそく、やってみましょう。
テストプログラムの起動後、デバッガをアタッチし、g でプログラムを続行します。
0:004> g
この状態で、Test1 ボタンをクリックします。0除算の SEH 例外が発生するはずです。
(f64.1478): Integer divide-by-zero - code c0000094 (first chance)
First chance exceptions are reported before any exception handling.
This exception may be expected and handled.
eax=00000001 ebx=01d482ac ecx=00000000 edx=00000000 esi=01d38cc4 edi=01d37aec
eip=00a5034c esp=001febe0 ebp=001fec00 iopl=0 nv up ei pl zr na pe nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00010246
00a5034c f7f9 idiv eax,ecx
確かに divide-by-zero 例外が発生し、デバッガがブレークしました。
そこで、問題発生時のマネージドスタックを見てみます。コマンドは !sos.clrstack です。
0:000> !sos.clrstack OS Thread Id: 0x1478 (0) ESP EIP 001febe0 00a5034c ExceptionTest1.Form1.button1_Click(System.Object, System.EventArgs) 001fec0c 64404170 System.Windows.Forms.Control.OnClick(System.EventArgs) 001fec24 643ff55a System.Windows.Forms.Button.OnClick(System.EventArgs) 001fec34 64996da4 System.Windows.Forms.Button.OnMouseUp(System.Windows.Forms.MouseEventArgs) 001fec50 649675d3 System.Windows.Forms.Control.WmMouseUp(System.Windows.Forms.Message ByRef, System.Windows.Forms.MouseButtons, Int32) 001fecdc 64c99b66 System.Windows.Forms.Control.WndProc(System.Windows.Forms.Message ByRef) 001fece0 64c98325 [InlinedCallFrame: 001fece0] 001fed78 64432550 System.Windows.Forms.Button.WndProc(System.Windows.Forms.Message ByRef) 001fed84 64438640 System.Windows.Forms.Control+ControlNativeWindow.OnMessage(System.Windows. Forms.Message ByRef) 001fed8c 644385c1 System.Windows.Forms.Control+ControlNativeWindow.WndProc(System.Windows. Forms.Message ByRef) 001feda0 6443849a System.Windows.Forms.NativeWindow.Callback(IntPtr, Int32, IntPtr, IntPtr) 001fef48 002609dc [NDirectMethodFrameStandalone: 001fef48] System.Windows.Forms. UnsafeNativeMethods.DispatchMessageW(MSG ByRef) 001fef58 64448cce System.Windows.Forms.Application+ComponentManager.System.Windows.Forms. UnsafeNativeMethods.IMsoComponentManager.FPushMessageLoop(Int32, Int32, Int32) 001feff4 64448937 System.Windows.Forms.Application+ThreadContext.RunMessageLoopInner(Int32, System.Windows.Forms.ApplicationContext) 001ff048 64448781 System.Windows.Forms.Application+ThreadContext.RunMessageLoop(Int32, System.Windows.Forms.ApplicationContext) 001ff078 64405911 System.Windows.Forms.Application.Run(System.Windows.Forms.Form) 001ff08c 00a5009a ExceptionTest1.Program.Main() 001ff2b4 71401b4c [GCFrame: 001ff2b4]
これで確かに button1_onclick というメソッドがわかりました。
しかし、ここで Exception オブジェクトを見ようとしてもうまくいきません。
0:000> !sos.dumpstackobjects
OS Thread Id: 0x1478 (0)
ESP/REG Object Name
ebx 01d482ac System.Windows.Forms.MouseEventArgs
esi 01d38cc4 System.EventHandler
edi 01d37aec System.Windows.Forms.Button
001febf0 01d482ac System.Windows.Forms.MouseEventArgs
001febf4 01d482ac System.Windows.Forms.MouseEventArgs
001febf8 01d38cc4 System.EventHandler
001febfc 01d37aec System.Windows.Forms.Button
...
001ff034 01d34498 System.Windows.Forms.Application+ThreadContext
001ff044 01d39c8c System.Windows.Forms.ApplicationContext
001ff060 01d33a5c ExceptionTest1.Form1
001ff064 01d39c8c System.Windows.Forms.ApplicationContext
001ff068 01d34498 System.Windows.Forms.Application+ThreadContext
001ff074 01d39c8c System.Windows.Forms.ApplicationContext
001ff07c 01d33a5c ExceptionTest1.Form1
これは 0除算例外は CLR 上の例外ではなく、SEH 例外ですからデバッガがブレークしたタイミングでは、 まだ CLR の例外に変換されていないからです。
0除算の例外、ということがわかっているので、いまさら例外オブジェクトを見つけてもあまり意味はありませんが、 一応、当初の目標「例外オブジェクトの Message を見る」 ところまでやってみましょう。
button1_Click メソッドの catch ブロックのアドレスを取得する
例外ハンドラに入るところでブレークしましょう。
そのために、button1_Click メソッドの情報をみる必要があります。メソッドの情報はメソッド・ディスクリプタ (メソッド記述子、MethodDesc) に記録されています。メソッドディスクリプタを取得するには、まず最初に そのクラスの EEClass を取得。次に EEClass からメソッドテーブルを取得できます。 メソッドテーブルから、メソッドディスクリプタが取得できる。という段取りになります。
では、やってみましょう。
クラス名から EEClass を取得できます。
0:000> !sos.name2ee ExceptionTest1 ExceptionTest1.Form1 Module: 00382c5c (ExceptionTest1.exe) Token: 0x02000005 MethodTable: 00385a40 EEClass: 00381574 Name: ExceptionTest1.Form1
ここに MethodTable (メソッドテーブル) のアドレスが記載されています。
メソッドディスクリプタ付でメソッドテーブルをダンプするのは、!sos.dumpmt -md コマンドです。 このコマンドにメソッドテーブルのアドレスを渡します。
0:000> !dumpmt -md 00385a40 EEClass: 00381574 Module: 00382c5c Name: ExceptionTest1.Form1 mdToken: 02000005 (C:\Temp\Projects\bin\Release\ExceptionTest1.exe) BaseSize: 0x14c ComponentSize: 0x0 Number of IFaces in IFaceMap: 15 Slots in VTable: 377 -------------------------------------- MethodDesc Table Entry MethodDesc JIT Name 643e6350 64258338 PreJIT System.Windows.Forms.Form.ToString() 6ffc6a90 6fe4493c PreJIT System.Object.Equals(System.Object) 6ffc6b00 6fe4496c PreJIT System.Object.GetHashCode() 6f7a2ea0 6f6909dc PreJIT System.ComponentModel.Component.Finalize() ... 649920b0 642582dc PreJIT System.Windows.Forms.Form.ShouldSerializeAutoScaleBaseSize() 6499189c 642583d8 PreJIT System.Windows.Forms.Form.OnResizeBegin(System.EventArgs) 64991810 642583e0 PreJIT System.Windows.Forms.Form.OnResizeEnd(System.EventArgs) 0038c054 003859cc JIT ExceptionTest1.Form1..ctor() 0038c074 003859d8 JIT ExceptionTest1.Form1.button1_Click(System.Object, System.EventArgs) 0038c084 003859e4 NONE ExceptionTest1.Form1.button2_Click(System.Object, System.EventArgs) 0038c064 003859f8 JIT ExceptionTest1.Form1.InitializeComponent()
MethodDesc のカラムに着目します。これから button1_Click メソッドのメソッドディスクリプタのアドレスは、 003859d8 であることがわかります。
例外ハンドラの情報は !sos.ehinfo コマンドでわかります。
0:000> !sos.ehinfo 003859d8 MethodDesc: 003859d8 Method Name: ExceptionTest1.Form1.button1_Click(System.Object, System.EventArgs) Class: 00381574 MethodTable: 00385a40 mdToken: 0600000a Module: 00382c5c IsJitted: yes CodeAddr: 00420328 EHHandler 0: TYPED Clause: [00420344, 00420350] [1c, 28] Handler: [00420350, 00420355] [28, 2d]
やっと例外ハンドラのアドレスが取得できました。bp でこれにブレークポイントを設定し、 プログラムを走らせます。
0:000> bp 00420350 0:000> g Breakpoint 0 hit eax=01cea030 ebx=01ce8fa0 ecx=00458dac edx=0024dcb8 esi=01cb8cc4 edi=01cb7aec eip=00420350 esp=0024dc90 ebp=0024e970 iopl=0 nv up ei pl nz na pe nc cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000206 00420350 e8df18fe70 call mscorwks!JIT_EndCatch (71401c34)
ブレークしたタイミングで例外オブジェクトを見てみると次のようになります。
0:000> !sos.dumpstackobjects OS Thread Id: 0x1768 (0) ESP/REG Object Name eax 01cea030 System.DivideByZeroException ebx 01ce8fa0 System.Windows.Forms.MouseEventArgs esi 01cb8cc4 System.EventHandler edi 01cb7aec System.Windows.Forms.Button 0024dcb8 01cea030 System.DivideByZeroException 0024dcbc 01ce8fa0 System.Windows.Forms.MouseEventArgs 0024dcc8 01cb8cc4 System.EventHandler 0024dccc 01cb7aec System.Windows.Forms.Button ... 0024ede4 01cb9c8c System.Windows.Forms.ApplicationContext 0024edec 01cb3a5c ExceptionTest1.Form1 0:000> !sos.pe 01cea030 Exception object: 01cea030 Exception type: System.DivideByZeroException Message: Attempted to divide by zero. InnerException: <none> StackTrace (generated): SP IP Function 0024E950 0042034D ExceptionTest1!ExceptionTest1.Form1.button1_Click( System.Object, System.EventArgs)+0x25 StackTraceString: <none> HResult: 80020012
このように例外オブジェクトがダンプできました。
なお、ここで出てきた登場人物をごく簡単に整理するとこんな風になります。
EEClass |
* そのクラスのあらゆるメソッド呼び出しの前にクラスローダによって生成される * Method Table へのポインタを持つ * デバッガではクラス名とモジュール名を指定して取得可能 (!sos.name2ee コマンド) |
Method Table |
* クラスに含まれるメソッドの一覧表 * メソッドの状態を記述する Method Descriptor へのポインタを含む * デバッガでは !sos.dumpmt で表示。Method Descriptor の情報を含めるときは !sos.dumpmt -md |
Method Descriptor |
* メソッドの状態を記述する * デバッガでは !sos.dumpmd で表示 |
ちょっと変った方法
例外オブジェクトは CreateCOMPlusExceptionObject で作られます。 SSCLI の clr\src\vm\excep.h や clr\src\vm\i386\excepx86.cpp を見ると次のようにわかります。
OBJECTREF CreateCOMPlusExceptionObject( Thread* pThread, EXCEPTION_RECORD* pExceptionRecord, BOOL bAsynchronousThreadStop);
... // Create the managed exception object. OBJECTREF throwable = CreateCOMPlusExceptionObject(pThread, pExceptionRecord, bAsynchronousThreadStop); ...
この情報を元に、例外オブジェクトが生成されるところでブレークしてみましょう。
これは mscorwks.dll に実装されていますから、次のようにブレークポイントを設定します。
> bp mscorwks!CreateCOMPlusExceptionObject
そこで処理を流すと確かにブレークします。
0:000> g Breakpoint 1 hit eax=0014ec70 ebx=002e8e08 ecx=00000000 edx=0014eb60 esi=002e8f88 edi=0014e764 eip=7146e9c9 esp=0014e500 ebp=0014e614 iopl=0 nv up ei pl nz na po nc cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000202 mscorwks!CreateCOMPlusExceptionObject: 7146e9c9 68a0000000 push 0A0h
CreateCOMPlusExceptionObject の戻り値が例外オブジェクトのはずですから、 これのリターンアドレスまで実行して、その戻り値を見てみましょう。
リターンアドレスの擬似レジスタは @$ra ですから、リターンアドレスまで実行するには、g @$ra とします。
0:000> g @$ra
eax=01ec13cc ebx=002e8e08 ecx=7146eb62 edx=0014e4f0 esi=002e8f88 edi=0014e764
eip=7146eb96 esp=0014e510 ebp=0014e614 iopl=0 nv up ei pl zr na pe nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000246
mscorwks!CPFH_RealFirstPassHandler+0x396:
7146eb96 50 push eax
戻り値は eax に入ります。マネージドオブジェクトのダンプは sos!dumpobj ですから、 次のようにします。
0:000> !sos.dumpobj eax Name: System.DivideByZeroException MethodTable: 7068a978 EEClass: 6feb0ffc Size: 72(0x48) bytes (C:\Windows\assembly\GAC_32\mscorlib\2.0.0.0__b77a5c561934e089\mscorlib.dll) Fields: MT Field Offset Type VT Attr Value Name 700708ec 40000b5 4 System.String 0 instance 00000000 _className 7006fd60 40000b6 8 ...ection.MethodBase 0 instance 00000000 _exceptionMethod 700708ec 40000b7 c System.String 0 instance 00000000 _exceptionMethodString 700708ec 40000b8 10 System.String 0 instance 01e8e7ac _message 7006a248 40000b9 14 ...tions.IDictionary 0 instance 00000000 _data 70070a80 40000ba 18 System.Exception 0 instance 00000000 _innerException 700708ec 40000bb 1c System.String 0 instance 00000000 _helpURL 70070508 40000bc 20 System.Object 0 instance 00000000 _stackTrace 700708ec 40000bd 24 System.String 0 instance 00000000 _stackTraceString 700708ec 40000be 28 System.String 0 instance 00000000 _remoteStackTraceString 70072b38 40000bf 34 System.Int32 1 instance 0 _remoteStackIndex 70070508 40000c0 2c System.Object 0 instance 00000000 _dynamicMethods 70072b38 40000c1 38 System.Int32 1 instance -2147352558 _HResult 700708ec 40000c2 30 System.String 0 instance 00000000 _source 700731b4 40000c3 3c System.IntPtr 1 instance 0 _xptrs 70072b38 40000c4 40 System.Int32 1 instance -532459699 _xcode
確かに System.DivideByZeroException 型のオブジェクトです。 例外オブジェクトの中身のダンプは次のように簡単に出来ます。
0:000> !sos.pe eax Exception object: 01ec13cc Exception type: System.DivideByZeroException Message: Attempted to divide by zero. InnerException: <none> StackTrace (generated): <none> StackTraceString: <none> HResult: 80020012 0:000>
これで例外オブジェクトの Message も確認できました。 しかしこのタイミングではスタックトレース等の情報はまだセットされていないこともわかります。
CLR 上の例外スロー時の確認は簡単
さて、次は Test2 ボタンの方です。こちらは例外オブジェクトを new してスローしています。
SEH 例外がトリガーになるのではなく、CLR 上のコードで例外オブジェクトを作って、それをスローするという順番になりますから、 上記の0除算例外とは流れが異なります。
しかし、幸いなことにこちらは簡単です。
CLR 上の例外オブジェクトを生成した後、それを e0434f4d というきまったコードで RaiseException を呼び出します。 この時のファーストチャンス例外でブレークするためには、sxe clr コマンドを実行します。
0:004> sxe clr
この後、プログラムを走らせて Test2 をクリックします。
0:004> g
次の箇所でブレークします。
(f64.1478): CLR exception - code e0434f4d (first chance)
First chance exceptions are reported before any exception handling.
This exception may be expected and handled.
eax=001fea60 ebx=e0434f4d ecx=00000001 edx=00000000 esi=001feae8 edi=004e8de8
eip=75f142eb esp=001fea60 ebp=001feab0 iopl=0 nv up ei pl nz ac pe nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000216
KERNEL32!RaiseException+0x58:
75f142eb c9 leave
マネージドスタックは次のようになります。
0:000> !sos.clrstack OS Thread Id: 0x1478 (0) ESP EIP 001feb38 75f142eb [HelperMethodFrame: 001feb38] 001febdc 00a503ac ExceptionTest1.Form1.button2_Click(System.Object, System.EventArgs) 001fec0c 64404170 System.Windows.Forms.Control.OnClick(System.EventArgs) 001fec24 643ff55a System.Windows.Forms.Button.OnClick(System.EventArgs) 001fec34 64996da4 System.Windows.Forms.Button.OnMouseUp(System.Windows.Forms.MouseEventArgs) 001fec50 649675d3 System.Windows.Forms.Control.WmMouseUp(System.Windows.Forms.Message ByRef, System.Windows.Forms.MouseButtons, Int32) 001fecdc 64c99b66 System.Windows.Forms.Control.WndProc(System.Windows.Forms.Message ByRef) 001fece0 64c98325 [InlinedCallFrame: 001fece0] 001fed78 64432550 System.Windows.Forms.Button.WndProc(System.Windows.Forms.Message ByRef) 001fed84 64438640 System.Windows.Forms.Control+ControlNativeWindow.OnMessage(System. Windows.Forms.Message ByRef) 001fed8c 644385c1 System.Windows.Forms.Control+ControlNativeWindow.WndProc(System. Windows.Forms.Message ByRef) 001feda0 6443849a System.Windows.Forms.NativeWindow.Callback(IntPtr, Int32, IntPtr, IntPtr) 001fef48 002609dc [NDirectMethodFrameStandalone: 001fef48] System.Windows.Forms. UnsafeNativeMethods.DispatchMessageW(MSG ByRef) 001fef58 64448cce System.Windows.Forms.Application+ComponentManager.System.Windows. Forms.UnsafeNativeMethods.IMsoComponentManager.FPushMessageLoop(Int32, Int32, Int32) 001feff4 64448937 System.Windows.Forms.Application+ThreadContext.RunMessageLoopInner( Int32, System.Windows.Forms.ApplicationContext) 001ff048 64448781 System.Windows.Forms.Application+ThreadContext.RunMessageLoop( Int32, System.Windows.Forms.ApplicationContext) 001ff078 64405911 System.Windows.Forms.Application.Run(System.Windows.Forms.Form) 001ff08c 00a5009a ExceptionTest1.Program.Main() 001ff2b4 71401b4c [GCFrame: 001ff2b4]
最初にオブジェクトを作ってからスローしてますから、例外オブジェクトは既に存在しているはずです。 !sos.dumpstackobjects でオブジェクトを探して、!sos.pe で中身をダンプします。
0:000> !sos.dumpstackobjects OS Thread Id: 0x1478 (0) ESP/REG Object Name 001feacc 01d70050 System.OutOfMemoryException 001feb18 01d70050 System.OutOfMemoryException 001feb28 01d37c88 System.Windows.Forms.Button 001feb2c 01d38d48 System.EventHandler ... 001ff068 01d34498 System.Windows.Forms.Application+ThreadContext 001ff074 01d39c8c System.Windows.Forms.ApplicationContext 001ff07c 01d33a5c ExceptionTest1.Form1 0:000> !sos.pe 01d70050 Exception object: 01d70050 Exception type: System.OutOfMemoryException Message: Hello, ExceptionTest1.exe!! InnerException: <none> StackTrace (generated): <none> StackTraceString: <none> HResult: 8007000e
以上のように確かに例外オブジェクトの中身を確認することが出来ました。