HowToLoggingCsharpException

Exceptionのログ方法について

結論から言うと、アプリケーションとライブラリでは同じExceptionオブジェクトでも（少なくとも後からの調査用のログという観点からは）見るべきプロパティを変えるべきだ。

Exceptionオブジェクトの見え方をチェックする。

以下のテストプログラムを用意した。

Fooメソッドは呼び出し先メソッド（当然ライブラリを想定する）を信用していない。したがって、このメソッドが採取すべきログは呼び出し先の振る舞いを調べるための資料となるものだ。

Bazメソッドは呼び出し元メソッド（当然アプリケーションを想定する）を信用していない。したがって、このメソッドが採取すべきログは呼び出し元の呼び出し条件を調べるための資料となるものだ。

テストコード(Exp.cs)

using System;
using System.Text.RegularExpressions;
public class Exp
{
    public enum ThrowType
    {
        Implicit,
        Explicit,
        Inner,
    }
    static readonly Regex KEY = new Regex("^(\\d\\d):.+$");
    ThrowType tType;
    public Exp(ThrowType t)
    {
        tType = t;
    }
    public void Foo()
    {
        try
        {
            Bar();
        }
        catch (Exception e)
        {
            Console.WriteLine("in Foo:");
            PrintException(e);
        }
    }
    void Bar()
    {
        Console.WriteLine(string.Format("key={0}", Baz(null)));
    }
    public int Baz(string s)
    {
        try
        {
            var m = KEY.Match(s);
            if (m.Success)
            {
                return int.Parse(m.Groups[1].Value);
            }
            else
            {
                return -1;
            }
        }
        catch (Exception e)
        {
            Console.WriteLine("in Baz:");
            PrintException(e);
            switch (tType)
            {
            case ThrowType.Implicit:
                throw;
            case ThrowType.Explicit:
                throw e;
            case ThrowType.Inner:
                throw new ArgumentException(string.Format("arg value={0}", s), e);
            default:
                throw new Exception("F# is better, at least discriminated union is better than enum");
            }
        }
    }
    void PrintException(Exception e)
    {
        Console.WriteLine("ToString: " + e.ToString());
        foreach (var p in e.GetType().GetProperties())
        {
            Console.WriteLine(string.Format("{0}: {1}", p.Name, p.GetValue(e, null)));
        }
    }
    public static void Main()
    {
        var e = new Exp(ThrowType.Implicit);
        e.Foo();
        Console.WriteLine("---------------------------------");
        e = new Exp(ThrowType.Explicit);
        e.Foo();
        Console.WriteLine("---------------------------------");
        e = new Exp(ThrowType.Inner);
        e.Foo();
    }
}

コードについて

Mainでは3回ExpクラスのFooメソッドを呼び出している。

それぞれの違いは、ライブラリが例外をスローする場合に、暗黙の再スローか明示した再スローかネストした例外を利用するかだ。

出力結果

出力は以下となる。サーバーサイドではないのでPDBはデプロイ対象としていない状態を想定する。

c:\Users\arton\Documents\test>Exp
in Baz:
ToString: System.ArgumentNullException: 値を Null にすることはできません。
パラメーター名: input
   場所 System.Text.RegularExpressions.Regex.Match(String input)
   場所 Exp.Baz(String s)
Message: 値を Null にすることはできません。
パラメーター名: input
ParamName: input
Data: System.Collections.ListDictionaryInternal
InnerException:
TargetSite: System.Text.RegularExpressions.Match Match(System.String)
StackTrace:    場所 System.Text.RegularExpressions.Regex.Match(String input)
   場所 Exp.Baz(String s)
HelpLink:
Source: System
in Foo:
ToString: System.ArgumentNullException: 値を Null にすることはできません。
パラメーター名: input
   場所 System.Text.RegularExpressions.Regex.Match(String input)
   場所 Exp.Baz(String s)
   場所 Exp.Bar()
   場所 Exp.Foo()
Message: 値を Null にすることはできません。
パラメーター名: input
ParamName: input
Data: System.Collections.ListDictionaryInternal
InnerException:
TargetSite: System.Text.RegularExpressions.Match Match(System.String)
StackTrace:    場所 System.Text.RegularExpressions.Regex.Match(String input)
   場所 Exp.Baz(String s)
   場所 Exp.Bar()
   場所 Exp.Foo()
HelpLink:
Source: System
---------------------------------
in Baz:
ToString: System.ArgumentNullException: 値を Null にすることはできません。
パラメーター名: input
   場所 System.Text.RegularExpressions.Regex.Match(String input)
   場所 Exp.Baz(String s)
Message: 値を Null にすることはできません。
パラメーター名: input
ParamName: input
Data: System.Collections.ListDictionaryInternal
InnerException:
TargetSite: System.Text.RegularExpressions.Match Match(System.String)
StackTrace:    場所 System.Text.RegularExpressions.Regex.Match(String input)
   場所 Exp.Baz(String s)
HelpLink:
Source: System
in Foo:
ToString: System.ArgumentNullException: 値を Null にすることはできません。
パラメーター名: input
   場所 Exp.Baz(String s)
   場所 Exp.Bar()
   場所 Exp.Foo()
Message: 値を Null にすることはできません。
パラメーター名: input
ParamName: input
Data: System.Collections.ListDictionaryInternal
InnerException:
TargetSite: System.Text.RegularExpressions.Match Match(System.String)
StackTrace:    場所 Exp.Baz(String s)
   場所 Exp.Bar()
   場所 Exp.Foo()
HelpLink:
Source: System
---------------------------------
in Baz:
ToString: System.ArgumentNullException: 値を Null にすることはできません。
パラメーター名: input
   場所 System.Text.RegularExpressions.Regex.Match(String input)
   場所 Exp.Baz(String s)
Message: 値を Null にすることはできません。
パラメーター名: input
ParamName: input
Data: System.Collections.ListDictionaryInternal
InnerException:
TargetSite: System.Text.RegularExpressions.Match Match(System.String)
StackTrace:    場所 System.Text.RegularExpressions.Regex.Match(String input)
   場所 Exp.Baz(String s)
HelpLink:
Source: System
in Foo:
ToString: System.ArgumentException: arg value= ---> System.ArgumentNullException: 値を Null にすることはできません。
パラメーター名: input
   場所 System.Text.RegularExpressions.Regex.Match(String input)
   場所 Exp.Baz(String s)
   --- 内部例外スタック トレースの終わり ---
   場所 Exp.Baz(String s)
   場所 Exp.Bar()
   場所 Exp.Foo()
Message: arg value=
ParamName:
Data: System.Collections.ListDictionaryInternal
InnerException: System.ArgumentNullException: 値を Null にすることはできません。
パラメーター名: input
   場所 System.Text.RegularExpressions.Regex.Match(String input)
   場所 Exp.Baz(String s)
TargetSite: Int32 Baz(System.String)
StackTrace:    場所 Exp.Baz(String s)
   場所 Exp.Bar()
   場所 Exp.Foo()
HelpLink:
Source: Exp

考察

以上からわかることは、catchしたExceptionオブジェクトから得られるスタックトレースは、StackTraceプロパティのものであろうがToStringメソッドのものであろうが、併設したtryブロックから先だけだということだ。

これはアプリケーション（ライブラリを信用していない）にとっては十分な情報量だ。しかも最低限必要と考えられる情報（Messageプロパティの値とStackTraceプロパティの値）はすべて単一のToStringメソッド呼び出しで得られる。しかもToStringメソッドは内部例外の情報についてもトレースを含めて対象になす。

つまり、アプリケーションが例外をログするのであれば、ToStringの結果をログすれば良い。

それに対して、アプリケーションを信用しないライブラリにとっては話が異なる。

信用していないのだから、アプリケーションプログラマに対して、このメソッドの呼び出し（またはそのメソッドを呼び出したメソッド……）はおかしい（引数がおかしいのか、状態がおかしいのか、いずれにしろ事前条件相当のものは例外とは別にログする必要はある）と指摘できなければならない。そのためには、別途スタックトレースを入手する必要がある（Diagnostics.StackTraceあるいはEnvironment.StackTrace）。

ライブラリからの例外のスロー方法

また、ライブラリが例外をキャッチした後に、アプリケーションに例外をスローする場合には次のいずれかを利用すべきということも言える。

1. 独自にArgumentException（事前条件のうち引数違反）やInvalidOperationException（事前条件のうち状態違反）を作成し、InnerExceptionにキャッチしたExceptionオブジェクトを設定する。アプリケーションがキャッチしたExceptionオブジェクトをここで示したようにToStringメソッドでログすることを前提とするのであれば、独自に状態をメッセージに追加できることから、この方法がベターである。
2. 暗黙の再スロー（無引数throw）。この方法を利用すると元の例外の原因（上の例ではRegexが検出した引数null）がスタックトレース上に含まれるため、仮にライブラリ側のログが失われても原因を追跡しやすい。

上記に対して、キャッチしたオブジェクトを指定した再スローでは真の原因（上の例ではRegexが検出した引数null）の通知元がTargetSiteプロパティにしか残らない。すると、上で示したようにアプリケーションはToStringの結果だけをログするとした場合に、真の原因が不明となりライブラリ側の調査が難しくなる可能性がある。したがって避けるべきだ。

yfakariyaさんとmatarilloさんに、間違いをいろいろ指摘していただきました。どうもありがとうございます。