Web/DB プログラミング徹底解説

ホーム > 雑記帳 > .NET Framework デバッグ ~ 例外オブジェクトの捕まえ方

.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

以上のように確かに例外オブジェクトの中身を確認することが出来ました。

スポンサーリンク