日々の破片

_ NET FrameworkのException.StackTrace

追記：間違ってるところを修正。yfakariyaさんのコメントも参照

昨日、同僚と例外を出しまくるテストをしていて恐ろしいことに気付いた。

次のようなメソッドをクラスライブラリで用意したのだった。

public int Foo(string s) 
{
   // たとえば
   try 
   {
       var m = KEYWORDS.match(s);
       if (m.Success) 
       {
           return int.Parse(m.Group[1]);
       }
   }
   catch (Exception e)
   {
       var b = new StringBuilder("argment is ok ?\r\n");
       b.Append("value=").Append(s);
       Logger.Write(e, b.ToString());  // LoggerはeのStackTraceプロパティをログする。
       throw new ArgumentException(b.ToString(), e);
   }
}
....
public void Write(Exception e, string s)
{
    ...
    logWriter.WriteLine(e.StackTrace);
    ...
}

おれの作ったクラスライブラリは、Java流儀というか、引数のnullチェックみたいなくだらないことはしない。そういうものは下位のクラスライブラリに任せる。したがってnullが与えられるとRegex.MatchがスローするArugmentNullExceptionを取る。(さすがにこれは例が単純過ぎるが、本来はいろいろな例外が引数によって発生する可能性がある)

しかし、ライブラリのユーザがまじめに例外を処理することはあまり期待しない。すればOKだがしなくてもそれはその時だ。そこで、後で原因がわかるようにこちらで例外を受けたらログをするわけだ。

で、そうやってnullを与えたりその他の（上の例だとちょっと他の例は考えにくいが）エラーになるパターンを与えたりしてログにさんざん書き込んだ。

で、ログを見てびっくり。

スタックトレースのボトムが、Foo(String s)になっているからだ。

このトレースみたら、悪いのはFooメソッド以外に存在しないことになってしまう。

そこでいろいろ試すと、どうも、アセンブリ境界(.NET Frameworkのアセンブリの直前のアセンブリの最初のメソッド)でスタックトレースが切られてしまうようだと気付いた。

いや、これはクラスライブラリを提供する側にとっては致命的だよ。誰が呼び出したかを調べるためにトレースを残そうとしているのに、それが残らないわけだから。

で、気づいて良かった良かったということで、ロガークラスのほうで

var st = new System.Diagnostics.StackTrace(1); // 0にするとロガーのこのメソッドになってしまう
logFile.WriteLine(st.ToString());

と書き出すようにして決着。

が、今、追試してみて、確かにアセンブリ境界で切れるようだと確信したが、どうしてこんな愚かな仕組みになっているんだ？（追記：メソッドの位置の問題で、アセンブリの境界ではなく、スロー元からキャッチしたメソッドまでを取り出すようになっているため、そのように見えていたということで、誤り） と疑問は拭えない。おれの設定とかがおかしいんんじゃないかという気がするわけだ。

追記：さらにいろいろ試すと、System.Diagnostics.StackTraceはフレームの位置を決められるというメリットはあるけれど、行番号をまったく残してくれないことに気付く。とすると、Environment.StackTraceのほうが行番号が付くから良いかも（しかし先頭2つがEnvironmentになってしまうのがいやな感じだ。というか、PDBファイルを置かなければいずれにしても行番号は無いはずだから、Diagnosticsのやつでも同じかなぁ。