Pixel Pedals of Tomakomai

北海道苫小牧市出身の初老の日常

StackTraceを少し便利に(2)

結論から言えば、ベストな解は見つかってませんので、あくまでアイデアのメモとして。

以前、P::M::StackTrace について以下のような話を書きました。

plackup を -E development で起動するとついてくるPlack::Middleware::StackTraceは大変便利ですが、このMiddlewareは最後に発生したdieを追跡するため、フレームワーク内で try ... catch ... die をしていると、原因となった部分ではなく rethrow させた部分のトレースが表示されてしまいます。

レガシーオレオレフレームワークをPSGI化した記録

ここで言っているrethrowとは、例えば以下のようなコードです。"some reason"が例外として上がってきた場合、普通なら表示したいスタックトレースは直接の原因となった(1)の呼び出し時のものでしょうが、実際にP::M::StackTrace で得られるトレースは(2)が呼び出された時のものです。

sub invalid_operation() {
    # 例外の発生源
    die "some reason"; # (1)
}

my $value = eval { invalid_operation };
if ($@ =~ /should be catch/) {
    # 適切な処理
} elsif ($@) {
    # 例外をrethrow
    die $@; # (2)
}

先のエントリで紹介した解決方法は、例外を投げる側で「こいつはTraceしないで」と明示する方法でした。しかし、呼び元がトレースの要不要を指示するってのも本来おかしな話です。

そもそもなぜこのような問題が起こるのかと言えば、たいていの場合Perlの例外は単なる文字列であり、例外中にスタックトレースの情報を含まないためです。例外がスタックトレースを持っていれば、外からdieのタイミングを見張る必要はなく、rethrowされた場合も最終的に上がってきた例外が持っているスタックトレースを表示すれば万事解決します。

ということで、この観点から2つの方法が考えられます。ただし、どちらの方法でもP::M::StackTrace ではなく、自前のミドルウェアを実装する必要があります*1

方法1: 必ずスタックトレースを含むような例外を投げる

例えば、Exception::Classスタックトレースの情報を含んだ例外オブジェクトなので、これを利用するようにします。ただし、P::M::StackTrace のException::Class 対応は日の目を見ずにrejectされている*2ため、トレースを意図したように表示するためには自前のStackTraceミドルウェアを実装する必要があります。

また、この方法では相変わらず文字列を例外として投げる部分は正しくトレースできないため、既存のコードや出来合いのコードについては効果がないという欠点もあります。

方法2: Inside-out Object的にトレースを保存する

例外の中にスタックトレースを保存できないのなら、Inside-out Objectのように外側で状態を保持してやるという手があります。例外が生まれたときにスタックトレースを取得して保存し、rethrowの時は何もしないという方法です。それが以下のパッチ。

現在、社内の開発環境ではこの方法を使っています*3。例外のユニークIDとしてオブジェクトの場合はrefaddr、それ以外の場合は文字列をそのまま使っていますが、この方法はdieの「末尾に改行を含む場合は行番号などをつけない」という仕様から"ほぼ"うまく機能します。die "hoge" などと例外を発生させるとメッセージの末尾に行番号やファイル名(と改行コード)がつきますが、その後のdie $@ とrethrowした場合は、すでに改行コードがついているために文字列は変更されずそのまま保持され、キーは改変されずに保たれます。また、仮にdie "hoge" と書かれている箇所が何カ所もあったとしても、改行文字で終わっていないメッセージには行番号とファイル名がつきますので、それぞれ違う例外として認識されます。

なお、propagate についてはこの方法だとpropagate 後のトレースを表示しますが、propagate は例外をラップして新たな例外を投げるという意図がある(と思う)ので、この挙動には問題ないでしょう。必要であれば、元の例外をPROPAGATEメソッドにてラップしたオブジェクトが、エラーやスタックトレースの表示を求められた時になんとかすべきです。

ただ、この方法には根本的にまずい部分があります*4。簡単に言えば、「例外のユニークID」が真の意味でユニークにはなっておらず、被ってしまうことがあるということです。先ほど"ほぼ"と言ったのはそのためです。IDが被ると、意図しない箇所のトレースを表示してしまいます。

例えば die "hoge\n" のように改行文字を含むエラーメセージの場合には行番号やファイル名がつけられないため、このような記述の箇所が複数あると同じ例外として見られてしまいます。また、この方法だと文字列の例外はシングルトンとして振る舞うため、同じdie が複数回呼ばれるようなシチュエーションでも問題となります。例えば、以下のコードでは最初のdieのスタックトレースを表示してしまい、another_operation経由での呼び出しであることがわかりません。

sub invalid_operation() {
    die "NG";
}

sub another_operation() {
    invalid_operation;
}

eval { invalid_operation }; # ←この例外は無視したい
another_operation;

上記のようなシチュエーションを無視してかまわないのであればこの方法はうまく機能しますが、一般的に使うことを考えるとこの動作は無視できない振る舞いでしょう。

*1:2011-01-25時点での話

*2:"discuss more to merge more appropriate fix"とコメントされているように、まだ対応を模索中な段階と言えます。

*3:厳密には他の修正も施しているため、このパッチは使ってませんが。

*4:よって、本家にはパッチを送ってません。