@kyanny's blog

My thoughts, my life. Views/opinions are my own.

DBIx::Class の DBIC_TRACE が綺麗なデバッグ SQL を出力している仕組みを少し調べてみた

DBIx::Class にはあまり詳しくないけど、 DBIC_TRACE は DBI の TRACE に比べて綺麗で見やすくていいなぁと思っていて、さっきふと「そういやなんで DBIC_TRACE だけ綺麗なんだろう」と不思議に思ったので少しソースを追ってみた。

google codesearch とかでちらっと DBIC_TRACE とかで検索してみたら、あんまりたいしたことがわからなかったので諦めて tarball を CPAN からおとしてきて、解凍した。

手元にソース一式があれば検索するのは M-x moccur-grep-find で楽々。 DBIC_TRACE で調べると DBIx::Class::Storage あたりで $storage->debug(1) をセットしている箇所があった。しかし実際に SQL をデバッグ出力してる様子はない。

こんどは debug でソースを全部検索してみる、と多すぎた・・・。でも、 t/91debug.t とかそんなテストがあって、ここを読むと debug がらみで少しは詳しいことがわかった。

途中、 SQL::Translator::Utils に寄り道したり(実はこのクラスのメソッドが DBI の TRACE を要約してるんじゃないか、とか。そんなことはなかった)して、 debugobj と debugfh と callback あたりについてうすぼんやりと把握した。

debugfh ってのが IO::Handle 互換のクラスのインスタンスになってて print() メソッドがあれば良くて、デフォルトだと STDERR に対する print() になって warn してるのと一緒、という感じか。

そしてもう少しさかのぼって query_start ってメソッドまでたどり着いた。これが定義されてる DBIx::Class::Storage::Statistics がデフォルトでの debugobj になってて、 query_start の中で $self->print を呼んでいてこいつが STDERR とか指定したファイルとかにデバッグメッセージを出力している、と。

query_start と _query_start ってのもあってややこしい。 _do_query ってメソッドの中から呼ばれているので、どうやらここが大元らしいぞと思ってそこと query_start などをあわせて読んでみると、もっと DBIC のコア部分の、ここより前段階にあたるどこかで SQL を綺麗に整形し終わっていてそれを単に引き回してきてクエリ実行しつつデバッグ出力に渡してるだけ、ということがわかった。

結論として、 DBIx::Class 以外の O/R マッパを使ってる場合に DBIC_TRACE 相当の綺麗なデバッグメッセージを得ることはできない。自力で相当頑張ればできないってことはないだろうけど、頑張るくらいなら我慢して DBI->trace を見たほうがいいか。。

しかしなんか納得いかないので DBI の perldoc をみていたら http://search.cpan.org/~timb/DBI-1.607/DBI.pm#TRACING の項に TraceFlags なんてのがあった。でも not yet implemented とか書いてある。しかしその下には $h-->{TraceLevel} = '3|SQL|foo' とも書いてある。 foo ってなんぞや。しかしこれで SQL だけ(プレースホルダでバインドされる値も含む)のデバッグメッセージを出せるなら嬉しいな。